builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s-pgo slave: talos-linux64-ix-005 starttime: 1512248733.52 results: success (0) revision: 44fad51c239833e710307b286b2b40953771fb96 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.524441) ========= master: http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.524941) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.525342) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.604328) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.604964) ========= 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=7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-12-02 13:05:33-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.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% 41.4M=0s 2017-12-02 13:05:33 (41.4 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.077567 ========= master_lag: 0.03 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.710407) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.710742) ========= 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=7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.019672 ========= master_lag: 0.05 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:33.779367) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-12-02 13:05:33.779739) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 44fad51c239833e710307b286b2b40953771fb96 --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 44fad51c239833e710307b286b2b40953771fb96 --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=7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-12-02 13:05:33,844 truncating revision to first 12 chars 2017-12-02 13:05:33,844 Setting DEBUG logging. 2017-12-02 13:05:33,844 attempt 1/10 2017-12-02 13:05:33,844 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/44fad51c2398?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-12-02 13:05:35,106 unpacking tar archive at: mozilla-central-44fad51c2398/testing/mozharness/ program finished with exit code 0 elapsedTime=1.905565 ========= master_lag: 0.03 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-12-02 13:05:35.719061) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:35.719405) ========= script_repo_revision: 44fad51c239833e710307b286b2b40953771fb96 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:35.719917) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:35.720218) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-12-02 13:05:35.735637) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 0 secs) (at 2017-12-02 13:05:35.735988) ========= /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=7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 13:05:35 INFO - MultiFileLogger online at 20171202 13:05:35 in /builds/slave/test 13:05:35 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:05:35 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 13:05:35 INFO - {'append_to_log': False, 13:05:35 INFO - 'base_work_dir': '/builds/slave/test', 13:05:35 INFO - 'blob_upload_branch': 'Firefox', 13:05:35 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 13:05:35 INFO - 'branch': 'Firefox', 13:05:35 INFO - 'buildbot_json_path': 'buildprops.json', 13:05:35 INFO - 'code_coverage': False, 13:05:35 INFO - 'config_files': ('talos/linux_config.py',), 13:05:35 INFO - 'default_actions': ('clobber', 13:05:35 INFO - 'read-buildbot-config', 13:05:35 INFO - 'download-and-extract', 13:05:35 INFO - 'populate-webroot', 13:05:35 INFO - 'create-virtualenv', 13:05:35 INFO - 'install', 13:05:35 INFO - 'setup-mitmproxy', 13:05:35 INFO - 'run-tests'), 13:05:35 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 13:05:35 INFO - 'disable_ccov_upload': False, 13:05:35 INFO - 'disable_stylo': False, 13:05:35 INFO - 'download_minidump_stackwalk': True, 13:05:35 INFO - 'download_symbols': 'ondemand', 13:05:35 INFO - 'e10s': False, 13:05:35 INFO - 'enable_stylo': False, 13:05:35 INFO - 'enable_webrender': False, 13:05:35 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 13:05:35 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 13:05:35 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 13:05:35 INFO - 'gecko_profile': False, 13:05:35 INFO - 'gecko_profile_interval': 0, 13:05:35 INFO - 'installer_path': 'installer.exe', 13:05:35 INFO - 'jsd_code_coverage': False, 13:05:35 INFO - 'log_level': 'info', 13:05:35 INFO - 'log_name': 'talos', 13:05:35 INFO - 'log_to_console': True, 13:05:35 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 13:05:35 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 13:05:35 INFO - 'opt_config_files': (), 13:05:35 INFO - 'pip_index': False, 13:05:35 INFO - 'suite': 'g4-stylo-disabled-e10s', 13:05:35 INFO - 'system_bits': '32', 13:05:35 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 13:05:35 INFO - 'title': 'talos-linux64-ix-005', 13:05:35 INFO - 'tooltool_cache': '/builds/tooltool_cache', 13:05:35 INFO - 'use_talos_json': True, 13:05:35 INFO - 'verify': 'False', 13:05:35 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 13:05:35 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 13:05:35 INFO - 'work_dir': 'build'} 13:05:35 INFO - [mozharness: 2017-12-02 21:05:35.922388Z] Running clobber step. 13:05:35 INFO - Running pre-action listener: _resource_record_pre_action 13:05:35 INFO - Running main action method: clobber 13:05:35 INFO - rmtree: /builds/slave/test/build 13:05:35 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 13:05:36 INFO - Running post-action listener: _resource_record_post_action 13:05:37 INFO - [mozharness: 2017-12-02 21:05:37.000042Z] Finished clobber step (success) 13:05:37 INFO - [mozharness: 2017-12-02 21:05:37.000138Z] Running read-buildbot-config step. 13:05:37 INFO - Running pre-action listener: _resource_record_pre_action 13:05:37 INFO - Running main action method: read_buildbot_config 13:05:37 INFO - Using buildbot properties: 13:05:37 INFO - { 13:05:37 INFO - "project": "", 13:05:37 INFO - "product": "firefox", 13:05:37 INFO - "who": "ffxbld@noreply.mozilla.org", 13:05:37 INFO - "installer_path": "public/build/target.tar.bz2", 13:05:37 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s", 13:05:37 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 13:05:37 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-stylo-disabled-e10s", 13:05:37 INFO - "stage_platform": "linux64-pgo", 13:05:37 INFO - "basedir": "/builds/slave/test", 13:05:37 INFO - "buildnumber": 113, 13:05:37 INFO - "platform": "ubuntu64_hw", 13:05:37 INFO - "master": "http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/", 13:05:37 INFO - "slavebuilddir": "test", 13:05:37 INFO - "taskId": "PpQmb26fQDSBU3uXCcwRjQ", 13:05:37 INFO - "branch": "mozilla-central", 13:05:37 INFO - "script_repo_revision": "production", 13:05:37 INFO - "revision": "44fad51c239833e710307b286b2b40953771fb96", 13:05:37 INFO - "slavename": "talos-linux64-ix-005", 13:05:37 INFO - "repo_path": "mozilla-central" 13:05:37 INFO - } 13:05:37 INFO - Finding installer, test and symbols from parent task. 13:05:37 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/PpQmb26fQDSBU3uXCcwRjQ'}, attempt #1 13:05:37 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/PpQmb26fQDSBU3uXCcwRjQ'}, attempt #1 13:05:37 INFO - Task dependencies: ZkkQmAVxSLi0rTbCwmZJgA 13:05:37 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA'}, attempt #1 13:05:38 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2 13:05:38 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.test_packages.json 13:05:38 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.crashreporter-symbols.zip 13:05:38 INFO - Running post-action listener: _resource_record_post_action 13:05:38 INFO - [mozharness: 2017-12-02 21:05:38.344607Z] Finished read-buildbot-config step (success) 13:05:38 INFO - [mozharness: 2017-12-02 21:05:38.344823Z] Running download-and-extract step. 13:05:38 INFO - Running pre-action listener: _resource_record_pre_action 13:05:38 INFO - Running main action method: download_and_extract 13:05:38 INFO - mkdir: /builds/slave/test/build/tests 13:05: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:05:38 INFO - trying https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.test_packages.json 13:05:38 INFO - Downloading https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 13:05:38 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 13:05:38 INFO - Downloaded 989 bytes. 13:05:38 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 13:05:38 INFO - Using the following test package requirements: 13:05:38 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 13:05:38 INFO - u'common': [u'target.common.tests.zip'], 13:05:38 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 13:05:38 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 13:05:38 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 13:05:38 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 13:05:38 INFO - u'mozbase': [u'target.common.tests.zip'], 13:05:38 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 13:05:38 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 13:05:38 INFO - u'web-platform': [u'target.common.tests.zip', 13:05:38 INFO - u'target.web-platform.tests.tar.gz'], 13:05:38 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 13:05:38 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 13:05:38 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.common.tests.zip 13:05:38 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.common.tests.zip'}, attempt #1 13:05:38 INFO - Fetch https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.common.tests.zip into memory 13:05:41 INFO - Content-Length response header: 60056186 13:05:41 INFO - Bytes received: 60056186 13:05:52 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.talos.tests.zip 13:05:52 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.talos.tests.zip'}, attempt #1 13:05:52 INFO - Fetch https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.talos.tests.zip into memory 13:05:52 INFO - Content-Length response header: 18753193 13:05:52 INFO - Bytes received: 18753193 13:05:53 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:05:53 INFO - trying https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2 13:05:53 INFO - Downloading https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 13:05:53 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 13:05:56 INFO - Downloaded 63514673 bytes. 13:05:56 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2 13:05:56 INFO - mkdir: /builds/slave/test/properties 13:05:56 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 13:05:56 INFO - Writing to file /builds/slave/test/properties/build_url 13:05:56 INFO - Contents: 13:05:56 INFO - build_url:https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2 13:05:56 INFO - Running post-action listener: _resource_record_post_action 13:05:56 INFO - Running post-action listener: find_tests_for_verification 13:05:56 INFO - Running post-action listener: set_extra_try_arguments 13:05:56 INFO - [mozharness: 2017-12-02 21:05:56.423272Z] Finished download-and-extract step (success) 13:05:56 INFO - [mozharness: 2017-12-02 21:05:56.423367Z] Running populate-webroot step. 13:05:56 INFO - Running pre-action listener: _resource_record_pre_action 13:05:56 INFO - Running main action method: populate_webroot 13:05:56 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 13:05:56 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['tresize', 13:05:56 INFO - 'tcanvasmark']}, 13:05:56 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 13:05:56 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['dromaeo_css', 13:05:56 INFO - 'kraken']}, 13:05:56 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:05:56 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:05:56 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'tests': ['damp', 'tps']}, 13:05:56 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['damp', 'tps']}, 13:05:56 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 13:05:56 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['dromaeo_dom']}, 13:05:56 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 13:05:56 INFO - 'glvideo', 13:05:56 INFO - 'displaylist_mutate']}, 13:05:56 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['basic_compositor_video', 13:05:56 INFO - 'glvideo']}, 13:05:56 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 13:05:56 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['ts_paint_webext', 13:05:56 INFO - 'tp5o_webext']}, 13:05:56 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 13:05:56 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:05:56 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:05:56 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:05:56 INFO - 'talos_options': ['--mitmproxy', 13:05:56 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:05:56 INFO - '--firstNonBlankPaint'], 13:05:56 INFO - 'tests': ['tp6_google_heavy', 13:05:56 INFO - 'tp6_youtube_heavy', 13:05:56 INFO - 'tp6_amazon_heavy', 13:05:56 INFO - 'tp6_facebook_heavy']}, 13:05:56 INFO - 'other-e10s': {'tests': ['a11yr', 13:05:56 INFO - 'ts_paint', 13:05:56 INFO - 'tpaint', 13:05:56 INFO - 'sessionrestore', 13:05:56 INFO - 'sessionrestore_many_windows', 13:05:56 INFO - 'sessionrestore_no_auto_restore', 13:05:56 INFO - 'tabpaint', 13:05:56 INFO - 'cpstartup']}, 13:05:56 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['a11yr', 13:05:56 INFO - 'ts_paint', 13:05:56 INFO - 'tpaint', 13:05:56 INFO - 'sessionrestore', 13:05:56 INFO - 'sessionrestore_many_windows', 13:05:56 INFO - 'sessionrestore_no_auto_restore', 13:05:56 INFO - 'tabpaint', 13:05:56 INFO - 'cpstartup']}, 13:05:56 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 13:05:56 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 13:05:56 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['perf_reftest_singletons']}, 13:05:56 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['perf_reftest']}, 13:05:56 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 13:05:56 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['speedometer']}, 13:05:56 INFO - 'svgr-e10s': {'tests': ['tsvgx', 13:05:56 INFO - 'tsvgr_opacity', 13:05:56 INFO - 'tart', 13:05:56 INFO - 'tscrollx', 13:05:56 INFO - 'tsvg_static']}, 13:05:56 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['tsvgx', 13:05:56 INFO - 'tsvgr_opacity', 13:05:56 INFO - 'tart', 13:05:56 INFO - 'tscrollx', 13:05:56 INFO - 'tsvg_static']}, 13:05:56 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 13:05:56 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'talos_options': ['--disable-stylo'], 13:05:56 INFO - 'tests': ['tp5o']}, 13:05:56 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:05:56 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:05:56 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:05:56 INFO - 'talos_options': ['--mitmproxy', 13:05:56 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:05:56 INFO - '--firstNonBlankPaint'], 13:05:56 INFO - 'tests': ['tp6_google', 13:05:56 INFO - 'tp6_youtube', 13:05:56 INFO - 'tp6_amazon', 13:05:56 INFO - 'tp6_facebook']}, 13:05:56 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:05:56 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:05:56 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:05:56 INFO - 'talos_options': ['--disable-stylo', 13:05:56 INFO - '--mitmproxy', 13:05:56 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:05:56 INFO - '--firstNonBlankPaint'], 13:05:56 INFO - 'tests': ['tp6_google', 13:05:56 INFO - 'tp6_youtube', 13:05:56 INFO - 'tp6_amazon', 13:05:56 INFO - 'tp6_facebook']}, 13:05:56 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:05:56 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:05:56 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:05:56 INFO - 'talos_options': ['--stylo-threads=1', 13:05:56 INFO - '--mitmproxy', 13:05:56 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:05:56 INFO - '--firstNonBlankPaint'], 13:05:56 INFO - 'tests': ['tp6_google', 13:05:56 INFO - 'tp6_youtube', 13:05:56 INFO - 'tp6_amazon', 13:05:56 INFO - 'tp6_facebook']}, 13:05:56 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'talos_options': ['--xperf_path', 13:05:56 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:05:56 INFO - 'tests': ['tp5n']}, 13:05:56 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:05:56 INFO - 'talos_options': ['--disable-stylo', 13:05:56 INFO - '--xperf_path', 13:05:56 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:05:56 INFO - 'tests': ['tp5n']}}} 13:05:56 INFO - Running post-action listener: _resource_record_post_action 13:05:56 INFO - [mozharness: 2017-12-02 21:05:56.441659Z] Finished populate-webroot step (success) 13:05:56 INFO - [mozharness: 2017-12-02 21:05:56.441752Z] Running create-virtualenv step. 13:05:56 INFO - Running pre-action listener: _resource_record_pre_action 13:05:56 INFO - Running main action method: create_virtualenv 13:05:56 INFO - Creating virtualenv /builds/slave/test/build/venv 13:05:56 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:05:56 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 13:05:56 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 13:05:56 INFO - Using real prefix '/usr' 13:05:56 INFO - New python executable in /builds/slave/test/build/venv/bin/python 13:05:56 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 13:05:58 INFO - Installing setuptools, pip, wheel...done. 13:05:58 INFO - Return code: 0 13:05:58 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 13:05:58 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:05:58 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:05:58 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:05:58 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:05:58 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:05:58 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5'] in /builds/slave/test/build 13:05:58 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org pip>=1.5 13:05:58 INFO - Using env: {'DISPLAY': ':0', 13:05:58 INFO - 'HOME': '/home/cltbld', 13:05:58 INFO - 'LANG': 'en_US.UTF-8', 13:05:58 INFO - 'LANGUAGE': 'en_US:en', 13:05:58 INFO - 'LOGNAME': 'cltbld', 13:05:58 INFO - 'MAIL': '/var/mail/cltbld', 13:05:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:05:58 INFO - 'MOZ_NO_REMOTE': '1', 13:05:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:05:58 INFO - 'NO_EM_RESTART': '1', 13:05:58 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:05:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:05:58 INFO - 'PWD': '/builds/slave/test', 13:05:58 INFO - 'SHELL': '/bin/bash', 13:05:58 INFO - 'SHLVL': '1', 13:05:58 INFO - 'TERM': 'linux', 13:05:58 INFO - 'TMOUT': '86400', 13:05:58 INFO - 'USER': 'cltbld', 13:05:58 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:05:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:05:58 INFO - '_': '/tools/buildbot/bin/python'} 13:05:58 INFO - Ignoring indexes: https://pypi.python.org/simple 13:05:58 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 13:05:58 INFO - Return code: 0 13:05:58 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 13:05:58 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:05:58 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:05:58 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:05:58 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:05:58 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', '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 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:05:58 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'psutil>=3.1.1'] in /builds/slave/test/build 13:05:58 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org psutil>=3.1.1 13:05:58 INFO - Using env: {'DISPLAY': ':0', 13:05:58 INFO - 'HOME': '/home/cltbld', 13:05:58 INFO - 'LANG': 'en_US.UTF-8', 13:05:58 INFO - 'LANGUAGE': 'en_US:en', 13:05:58 INFO - 'LOGNAME': 'cltbld', 13:05:58 INFO - 'MAIL': '/var/mail/cltbld', 13:05:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:05:58 INFO - 'MOZ_NO_REMOTE': '1', 13:05:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:05:58 INFO - 'NO_EM_RESTART': '1', 13:05:58 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:05:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:05:58 INFO - 'PWD': '/builds/slave/test', 13:05:58 INFO - 'SHELL': '/bin/bash', 13:05:58 INFO - 'SHLVL': '1', 13:05:58 INFO - 'TERM': 'linux', 13:05:58 INFO - 'TMOUT': '86400', 13:05:58 INFO - 'USER': 'cltbld', 13:05:58 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:05:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:05:58 INFO - '_': '/tools/buildbot/bin/python'} 13:05:59 INFO - Ignoring indexes: https://pypi.python.org/simple 13:05:59 INFO - Collecting psutil>=3.1.1 13:06:00 INFO - Installing collected packages: psutil 13:06:00 INFO - Successfully installed psutil-3.1.1 13:06:00 INFO - Return code: 0 13:06:00 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 13:06: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:06:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06: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:06:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06: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', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06: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', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 13:06: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 mozsystemmonitor==0.3 13:06:00 INFO - Using env: {'DISPLAY': ':0', 13:06:00 INFO - 'HOME': '/home/cltbld', 13:06:00 INFO - 'LANG': 'en_US.UTF-8', 13:06:00 INFO - 'LANGUAGE': 'en_US:en', 13:06:00 INFO - 'LOGNAME': 'cltbld', 13:06:00 INFO - 'MAIL': '/var/mail/cltbld', 13:06:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:00 INFO - 'MOZ_NO_REMOTE': '1', 13:06:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:00 INFO - 'NO_EM_RESTART': '1', 13:06:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:00 INFO - 'PWD': '/builds/slave/test', 13:06:00 INFO - 'SHELL': '/bin/bash', 13:06:00 INFO - 'SHLVL': '1', 13:06:00 INFO - 'TERM': 'linux', 13:06:00 INFO - 'TMOUT': '86400', 13:06:00 INFO - 'USER': 'cltbld', 13:06:00 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:00 INFO - '_': '/tools/buildbot/bin/python'} 13:06:01 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:01 INFO - Collecting mozsystemmonitor==0.3 13:06:02 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 13:06:02 INFO - Installing collected packages: mozsystemmonitor 13:06:02 INFO - Successfully installed mozsystemmonitor-0.3 13:06:02 INFO - Return code: 0 13:06:02 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 13:06:02 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:06:02 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06:02 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:06:02 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06:02 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', '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 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06:02 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1'] in /builds/slave/test/build 13:06:02 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema==2.5.1 13:06:02 INFO - Using env: {'DISPLAY': ':0', 13:06:02 INFO - 'HOME': '/home/cltbld', 13:06:02 INFO - 'LANG': 'en_US.UTF-8', 13:06:02 INFO - 'LANGUAGE': 'en_US:en', 13:06:02 INFO - 'LOGNAME': 'cltbld', 13:06:02 INFO - 'MAIL': '/var/mail/cltbld', 13:06:02 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:02 INFO - 'MOZ_NO_REMOTE': '1', 13:06:02 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:02 INFO - 'NO_EM_RESTART': '1', 13:06:02 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:02 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:02 INFO - 'PWD': '/builds/slave/test', 13:06:02 INFO - 'SHELL': '/bin/bash', 13:06:02 INFO - 'SHLVL': '1', 13:06:02 INFO - 'TERM': 'linux', 13:06:02 INFO - 'TMOUT': '86400', 13:06:02 INFO - 'USER': 'cltbld', 13:06:02 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:02 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:02 INFO - '_': '/tools/buildbot/bin/python'} 13:06:02 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:02 INFO - Collecting jsonschema==2.5.1 13:06:03 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 13:06:03 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 13:06:04 INFO - Installing collected packages: functools32, jsonschema 13:06:04 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 13:06:04 INFO - Return code: 0 13:06:04 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 13:06:04 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:06:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06:04 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:06:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06:04 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 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06:04 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:06:04 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:06:04 INFO - Using env: {'DISPLAY': ':0', 13:06:04 INFO - 'HOME': '/home/cltbld', 13:06:04 INFO - 'LANG': 'en_US.UTF-8', 13:06:04 INFO - 'LANGUAGE': 'en_US:en', 13:06:04 INFO - 'LOGNAME': 'cltbld', 13:06:04 INFO - 'MAIL': '/var/mail/cltbld', 13:06:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:04 INFO - 'MOZ_NO_REMOTE': '1', 13:06:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:04 INFO - 'NO_EM_RESTART': '1', 13:06:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:04 INFO - 'PWD': '/builds/slave/test', 13:06:04 INFO - 'SHELL': '/bin/bash', 13:06:04 INFO - 'SHLVL': '1', 13:06:04 INFO - 'TERM': 'linux', 13:06:04 INFO - 'TMOUT': '86400', 13:06:04 INFO - 'USER': 'cltbld', 13:06:04 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:04 INFO - '_': '/tools/buildbot/bin/python'} 13:06:05 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:05 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 13:06:05 INFO - Return code: 0 13:06:05 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 13:06:05 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:06:05 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06:05 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:06:05 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06:05 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 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06:05 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:06:05 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:06:05 INFO - Using env: {'DISPLAY': ':0', 13:06:05 INFO - 'HOME': '/home/cltbld', 13:06:05 INFO - 'LANG': 'en_US.UTF-8', 13:06:05 INFO - 'LANGUAGE': 'en_US:en', 13:06:05 INFO - 'LOGNAME': 'cltbld', 13:06:05 INFO - 'MAIL': '/var/mail/cltbld', 13:06:05 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:05 INFO - 'MOZ_NO_REMOTE': '1', 13:06:05 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:05 INFO - 'NO_EM_RESTART': '1', 13:06:05 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:05 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:05 INFO - 'PWD': '/builds/slave/test', 13:06:05 INFO - 'SHELL': '/bin/bash', 13:06:05 INFO - 'SHLVL': '1', 13:06:05 INFO - 'TERM': 'linux', 13:06:05 INFO - 'TMOUT': '86400', 13:06:05 INFO - 'USER': 'cltbld', 13:06:05 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:05 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:05 INFO - '_': '/tools/buildbot/bin/python'} 13:06:05 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:05 INFO - Collecting blobuploader==1.2.4 13:06:06 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 13:06:07 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 13:06:08 INFO - Installing collected packages: requests, docopt, blobuploader 13:06:09 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 13:06:09 INFO - Return code: 0 13:06:09 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:06:09 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:06:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06:09 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:06:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06:09 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 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06:09 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:06:09 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:06:09 INFO - Using env: {'DISPLAY': ':0', 13:06:09 INFO - 'HOME': '/home/cltbld', 13:06:09 INFO - 'LANG': 'en_US.UTF-8', 13:06:09 INFO - 'LANGUAGE': 'en_US:en', 13:06:09 INFO - 'LOGNAME': 'cltbld', 13:06:09 INFO - 'MAIL': '/var/mail/cltbld', 13:06:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:09 INFO - 'MOZ_NO_REMOTE': '1', 13:06:09 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:09 INFO - 'NO_EM_RESTART': '1', 13:06:09 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:09 INFO - 'PWD': '/builds/slave/test', 13:06:09 INFO - 'SHELL': '/bin/bash', 13:06:09 INFO - 'SHLVL': '1', 13:06:09 INFO - 'TERM': 'linux', 13:06:09 INFO - 'TMOUT': '86400', 13:06:09 INFO - 'USER': 'cltbld', 13:06:09 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:09 INFO - '_': '/tools/buildbot/bin/python'} 13:06:09 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:09 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:06:09 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:06:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:06:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:06:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:06:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:06:10 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:06:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:06:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:06:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:06:11 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:06:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:06:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:06:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:06:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:06:12 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:06:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:06:12 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 13:06:12 INFO - Running setup.py install for manifestparser: started 13:06:13 INFO - Running setup.py install for manifestparser: finished with status 'done' 13:06:13 INFO - Running setup.py install for mozcrash: started 13:06:13 INFO - Running setup.py install for mozcrash: finished with status 'done' 13:06:13 INFO - Running setup.py install for mozdebug: started 13:06:13 INFO - Running setup.py install for mozdebug: finished with status 'done' 13:06:13 INFO - Running setup.py install for mozdevice: started 13:06:13 INFO - Running setup.py install for mozdevice: finished with status 'done' 13:06:13 INFO - Running setup.py install for mozfile: started 13:06:13 INFO - Running setup.py install for mozfile: finished with status 'done' 13:06:13 INFO - Running setup.py install for mozhttpd: started 13:06:14 INFO - Running setup.py install for mozhttpd: finished with status 'done' 13:06:14 INFO - Running setup.py install for mozinfo: started 13:06:14 INFO - Running setup.py install for mozinfo: finished with status 'done' 13:06:14 INFO - Running setup.py install for mozInstall: started 13:06:14 INFO - Running setup.py install for mozInstall: finished with status 'done' 13:06:14 INFO - Running setup.py install for mozleak: started 13:06:14 INFO - Running setup.py install for mozleak: finished with status 'done' 13:06:14 INFO - Running setup.py install for mozlog: started 13:06:15 INFO - Running setup.py install for mozlog: finished with status 'done' 13:06:15 INFO - Running setup.py install for moznetwork: started 13:06:15 INFO - Running setup.py install for moznetwork: finished with status 'done' 13:06:15 INFO - Running setup.py install for mozprocess: started 13:06:15 INFO - Running setup.py install for mozprocess: finished with status 'done' 13:06:15 INFO - Running setup.py install for mozprofile: started 13:06:15 INFO - Running setup.py install for mozprofile: finished with status 'done' 13:06:15 INFO - Running setup.py install for mozrunner: started 13:06:15 INFO - Running setup.py install for mozrunner: finished with status 'done' 13:06:15 INFO - Running setup.py install for mozscreenshot: started 13:06:16 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 13:06:16 INFO - Running setup.py install for moztest: started 13:06:16 INFO - Running setup.py install for moztest: finished with status 'done' 13:06:16 INFO - Running setup.py install for mozversion: started 13:06:16 INFO - Running setup.py install for mozversion: finished with status 'done' 13:06:16 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.14 mozscreenshot-0.1 moztest-0.8 mozversion-1.4 13:06:16 INFO - Return code: 0 13:06:16 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:06:16 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:06:16 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06:16 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:06:16 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06:16 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 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06:16 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:06:16 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:06:16 INFO - Using env: {'DISPLAY': ':0', 13:06:16 INFO - 'HOME': '/home/cltbld', 13:06:16 INFO - 'LANG': 'en_US.UTF-8', 13:06:16 INFO - 'LANGUAGE': 'en_US:en', 13:06:16 INFO - 'LOGNAME': 'cltbld', 13:06:16 INFO - 'MAIL': '/var/mail/cltbld', 13:06:16 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:16 INFO - 'MOZ_NO_REMOTE': '1', 13:06:16 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:16 INFO - 'NO_EM_RESTART': '1', 13:06:16 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:16 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:16 INFO - 'PWD': '/builds/slave/test', 13:06:16 INFO - 'SHELL': '/bin/bash', 13:06:16 INFO - 'SHLVL': '1', 13:06:16 INFO - 'TERM': 'linux', 13:06:16 INFO - 'TMOUT': '86400', 13:06:16 INFO - 'USER': 'cltbld', 13:06:16 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:16 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:16 INFO - '_': '/tools/buildbot/bin/python'} 13:06:17 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:17 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:06:17 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:06:17 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:06:17 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:06:17 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:06:18 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:06:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:06:18 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:06:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:06:18 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:06:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:06:18 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:06:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:06:18 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:06:18 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:06:19 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:06:19 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:06:19 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:06:19 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:06:19 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:06:19 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:06:19 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:06:19 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:06:19 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:06:19 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:06:20 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:06:20 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:06:20 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.14 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:06:20 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:06:20 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:06:20 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:06:20 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:06:20 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:06:20 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:06:20 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 13:06:21 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl 13:06:21 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:06:21 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:06:21 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:06:21 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:06:21 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:06:21 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:06:21 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 13:06:22 INFO - Installing collected packages: six, blessings 13:06:23 INFO - Successfully installed blessings-1.6 six-1.10.0 13:06:23 INFO - Return code: 0 13:06:23 INFO - Done creating virtualenv /builds/slave/test/build/venv. 13:06:23 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:06:23 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:06:23 INFO - Reading from file tmpfile_stdout 13:06:23 INFO - Reading from file tmpfile_stderr 13:06:23 INFO - Current package versions: 13:06:23 INFO - blessings == 1.6 13:06:23 INFO - blobuploader == 1.2.4 13:06:23 INFO - docopt == 0.6.1 13:06:23 INFO - functools32 == 3.2.3.post2 13:06:23 INFO - jsonschema == 2.5.1 13:06:23 INFO - manifestparser == 1.2 13:06:23 INFO - mozInstall == 1.14 13:06:23 INFO - mozcrash == 1.0 13:06:23 INFO - mozdebug == 0.1 13:06:23 INFO - mozdevice == 0.51 13:06:23 INFO - mozfile == 1.2 13:06:23 INFO - mozhttpd == 0.7 13:06:23 INFO - mozinfo == 0.10 13:06:23 INFO - mozleak == 0.1 13:06:23 INFO - mozlog == 3.5 13:06:23 INFO - moznetwork == 0.27 13:06:23 INFO - mozprocess == 0.25 13:06:23 INFO - mozprofile == 0.29 13:06:23 INFO - mozrunner == 6.14 13:06:23 INFO - mozscreenshot == 0.1 13:06:23 INFO - mozsystemmonitor == 0.3 13:06:23 INFO - moztest == 0.8 13:06:23 INFO - mozversion == 1.4 13:06:23 INFO - psutil == 3.1.1 13:06:23 INFO - requests == 1.2.3 13:06:23 INFO - six == 1.10.0 13:06:23 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:06:23 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:06:23 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06:23 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:06:23 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06:23 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 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06:23 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:06:23 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:06:23 INFO - Using env: {'DISPLAY': ':0', 13:06:23 INFO - 'HOME': '/home/cltbld', 13:06:23 INFO - 'LANG': 'en_US.UTF-8', 13:06:23 INFO - 'LANGUAGE': 'en_US:en', 13:06:23 INFO - 'LOGNAME': 'cltbld', 13:06:23 INFO - 'MAIL': '/var/mail/cltbld', 13:06:23 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:23 INFO - 'MOZ_NO_REMOTE': '1', 13:06:23 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:23 INFO - 'NO_EM_RESTART': '1', 13:06:23 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:23 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:23 INFO - 'PWD': '/builds/slave/test', 13:06:23 INFO - 'SHELL': '/bin/bash', 13:06:23 INFO - 'SHLVL': '1', 13:06:23 INFO - 'TERM': 'linux', 13:06:23 INFO - 'TMOUT': '86400', 13:06:23 INFO - 'USER': 'cltbld', 13:06:23 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:23 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:23 INFO - '_': '/tools/buildbot/bin/python'} 13:06:24 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:24 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:06:24 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:06:24 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:06:24 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:06:24 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:06:24 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:06:24 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:06:24 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:06:24 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:06:24 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 13:06:25 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:06:26 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/requests-2.18.3-py2.py3-none-any.whl (88kB) 13:06:26 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:06:26 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:06:26 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:06:26 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:06:27 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/chardet-3.0.4-py2.py3-none-any.whl (133kB) 13:06:27 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:06:28 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/urllib3-1.22-py2.py3-none-any.whl (132kB) 13:06:28 INFO - Collecting certifi>=2017.4.17 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:06:29 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/certifi-2017.7.27.1-py2.py3-none-any.whl (349kB) 13:06:29 INFO - Collecting idna<2.6,>=2.5 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:06:30 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/idna-2.5-py2.py3-none-any.whl (55kB) 13:06:30 INFO - Installing collected packages: simplejson, chardet, urllib3, certifi, idna, requests 13:06:31 INFO - Found existing installation: requests 1.2.3 13:06:31 INFO - Uninstalling requests-1.2.3: 13:06:31 INFO - Successfully uninstalled requests-1.2.3 13:06:31 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:06:31 INFO - Return code: 0 13:06:31 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 13:06:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:06:31 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:06:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:06:31 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:06:31 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2819e30>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x287c990>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29a23b0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, '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': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', '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:06:31 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema'] in /builds/slave/test/build 13:06:31 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema 13:06:31 INFO - Using env: {'DISPLAY': ':0', 13:06:31 INFO - 'HOME': '/home/cltbld', 13:06:31 INFO - 'LANG': 'en_US.UTF-8', 13:06:31 INFO - 'LANGUAGE': 'en_US:en', 13:06:31 INFO - 'LOGNAME': 'cltbld', 13:06:31 INFO - 'MAIL': '/var/mail/cltbld', 13:06:31 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:31 INFO - 'MOZ_NO_REMOTE': '1', 13:06:31 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:31 INFO - 'NO_EM_RESTART': '1', 13:06:31 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:31 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:31 INFO - 'PWD': '/builds/slave/test', 13:06:31 INFO - 'SHELL': '/bin/bash', 13:06:31 INFO - 'SHLVL': '1', 13:06:31 INFO - 'TERM': 'linux', 13:06:31 INFO - 'TMOUT': '86400', 13:06:31 INFO - 'USER': 'cltbld', 13:06:31 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:31 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:31 INFO - '_': '/tools/buildbot/bin/python'} 13:06:31 INFO - Ignoring indexes: https://pypi.python.org/simple 13:06:31 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 13:06:31 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 13:06:31 INFO - Return code: 0 13:06:31 INFO - Running post-action listener: _resource_record_post_action 13:06:31 INFO - Running post-action listener: _start_resource_monitoring 13:06:32 INFO - Starting resource monitoring. 13:06:32 INFO - [mozharness: 2017-12-02 21:06:32.003574Z] Finished create-virtualenv step (success) 13:06:32 INFO - [mozharness: 2017-12-02 21:06:32.004042Z] Running install step. 13:06:32 INFO - Running pre-action listener: _resource_record_pre_action 13:06:32 INFO - Running main action method: install 13:06:32 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:06:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:06:32 INFO - Reading from file tmpfile_stdout 13:06:32 INFO - Reading from file tmpfile_stderr 13:06:32 INFO - Detecting whether we're running mozinstall >=1.0... 13:06:32 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 13:06:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 13:06:32 INFO - Reading from file tmpfile_stdout 13:06:32 INFO - Output received: 13:06:32 INFO - Usage: mozinstall [options] installer 13:06:32 INFO - Options: 13:06:32 INFO - -h, --help show this help message and exit 13:06:32 INFO - -d DEST, --destination=DEST 13:06:32 INFO - Directory to install application into. [default: 13:06:32 INFO - "/builds/slave/test"] 13:06:32 INFO - --app=APP Application being installed. [default: firefox] 13:06:32 INFO - mkdir: /builds/slave/test/build/application 13:06:32 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:06:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 13:06:50 INFO - Reading from file tmpfile_stdout 13:06:50 INFO - Output received: 13:06:50 INFO - /builds/slave/test/build/application/firefox/firefox 13:06:50 INFO - Running post-action listener: _resource_record_post_action 13:06:50 INFO - [mozharness: 2017-12-02 21:06:50.899116Z] Finished install step (success) 13:06:50 INFO - [mozharness: 2017-12-02 21:06:50.899446Z] Running setup-mitmproxy step. 13:06:50 INFO - Running pre-action listener: _resource_record_pre_action 13:06:50 INFO - Running main action method: setup_mitmproxy 13:06:50 INFO - Skipping: mitmproxy is not required 13:06:50 INFO - Running post-action listener: _resource_record_post_action 13:06:50 INFO - [mozharness: 2017-12-02 21:06:50.901048Z] Finished setup-mitmproxy step (success) 13:06:50 INFO - [mozharness: 2017-12-02 21:06:50.901354Z] Running run-tests step. 13:06:50 INFO - Running pre-action listener: _resource_record_pre_action 13:06:50 INFO - Running pre-action listener: _set_gcov_prefix 13:06:50 INFO - Running main action method: run_tests 13:06:50 WARNING - Try message not found. 13:06:50 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 13:06:50 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 13:06:50 INFO - Python 2.7.3 13:06:50 INFO - Return code: 0 13:06:50 INFO - grabbing minidump binary from tooltool 13:06:50 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:06:50 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 0x29a5a00>, '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 0x29a66f0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29a08e0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 13:06:50 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:06:50 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:06:50 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:06:50 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 13:06:51 INFO - Return code: 0 13:06:51 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 13:06:51 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 13:06:51 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 13:06:51 INFO - ENV: RUST_BACKTRACE is now full 13:06:51 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 13:06:51 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 13:06:51 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/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-005', '--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:06:51 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/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-005 --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:06:51 INFO - Using env: {'DISPLAY': ':0', 13:06:51 INFO - 'HOME': '/home/cltbld', 13:06:51 INFO - 'LANG': 'en_US.UTF-8', 13:06:51 INFO - 'LANGUAGE': 'en_US:en', 13:06:51 INFO - 'LOGNAME': 'cltbld', 13:06:51 INFO - 'MAIL': '/var/mail/cltbld', 13:06:51 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:06:51 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:06:51 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:51 INFO - 'MOZ_NO_REMOTE': '1', 13:06:51 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:06:51 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:51 INFO - 'NO_EM_RESTART': '1', 13:06:51 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:51 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:51 INFO - 'PWD': '/builds/slave/test', 13:06:51 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:06:51 INFO - 'RUST_BACKTRACE': 'full', 13:06:51 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:06:51 INFO - 'SHELL': '/bin/bash', 13:06:51 INFO - 'SHLVL': '1', 13:06:51 INFO - 'TERM': 'linux', 13:06:51 INFO - 'TMOUT': '86400', 13:06:51 INFO - 'USER': 'cltbld', 13:06:51 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:51 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:51 INFO - '_': '/tools/buildbot/bin/python'} 13:06:51 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/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-005', '--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:06:51 INFO - mozversion application_buildid: 20171202194511 13:06:51 INFO - mozversion application_changeset: 44fad51c239833e710307b286b2b40953771fb96 13:06:51 INFO - mozversion application_display_name: Nightly 13:06:51 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 13:06:51 INFO - mozversion application_name: Firefox 13:06:51 INFO - mozversion application_remotingname: firefox 13:06:51 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 13:06:51 INFO - mozversion application_vendor: Mozilla 13:06:51 INFO - mozversion application_version: 59.0a1 13:06:51 INFO - mozversion platform_buildid: 20171202194511 13:06:51 INFO - mozversion platform_changeset: 44fad51c239833e710307b286b2b40953771fb96 13:06:51 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 13:06:51 INFO - mozversion platform_version: 59.0a1 13:06:51 INFO - using testdate: 1512248811 13:06:51 INFO - actual date: 1512248811 13:06:51 INFO - starting webserver on 'localhost:56081' 13:06:51 INFO - SUITE-START | Running 2 tests 13:06:51 INFO - TEST-START | basic_compositor_video 13:06:51 INFO - Initialising browser for basic_compositor_video test... 13:06:51 INFO - Cloning profile located at /builds/slave/test/build/tests/talos/talos/base_profile 13:06:51 INFO - Installing Add-ons 13:06:51 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:56081/getInfo.html -profile /tmp/tmpxZz_v8/profile 13:06:51 INFO - TEST-INFO | started process 8778 (/builds/slave/test/build/application/firefox/firefox http://localhost:56081/getInfo.html) 13:06:57 INFO - TEST-INFO | 8778: exit 0 13:06:57 INFO - Browser initialized. 13:06:57 INFO - Running cycle 1/1 for basic_compositor_video test... 13:06:57 INFO - Using env: {'DISPLAY': ':0', 13:06:57 INFO - 'HOME': '/home/cltbld', 13:06:57 INFO - 'JSGC_DISABLE_POISONING': '1', 13:06:57 INFO - 'LANG': 'en_US.UTF-8', 13:06:57 INFO - 'LANGUAGE': 'en_US:en', 13:06:57 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:06:57 INFO - 'LOGNAME': 'cltbld', 13:06:57 INFO - 'MAIL': '/var/mail/cltbld', 13:06:57 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:06:57 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:06:57 INFO - 'MOZ_CRASHREPORTER': '1', 13:06:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:06:57 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:06:57 INFO - 'MOZ_NO_REMOTE': '1', 13:06:57 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:06:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:06:57 INFO - 'NO_EM_RESTART': '1', 13:06:57 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:06:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:06:57 INFO - 'PWD': '/builds/slave/test', 13:06:57 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:06:57 INFO - 'RUST_BACKTRACE': 'full', 13:06:57 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:06:57 INFO - 'SHELL': '/bin/bash', 13:06:57 INFO - 'SHLVL': '1', 13:06:57 INFO - 'STYLO_FORCE_DISABLED': '1', 13:06:57 INFO - 'TERM': 'linux', 13:06:57 INFO - 'TMOUT': '86400', 13:06:57 INFO - 'USER': 'cltbld', 13:06:57 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:06:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:06:57 INFO - '_': '/tools/buildbot/bin/python'} 13:06:57 INFO - TEST-INFO | started process 9066 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpxZz_v8/profile) 13:06:58 INFO - PID 9066 | 13:06:58 INFO - PID 9066 | (/builds/slave/test/build/application/firefox/firefox:9117): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:06:58 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6898367117117117 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6712656641604007 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.708016505406944 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.692385786802031 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.033077956989246 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.134493801652895 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.468549132947977 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.431337907375639 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.7370172084130076 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.57204735376044 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 9.934668874172175 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.052562814070365 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.911727272727267 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.642047872340434 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.451514522821586 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.125909090909099 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.409467680608346 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.934344262295085 ms/frame 13:07:44 INFO - PID 9066 | 13:07:44 INFO - PID 9066 | Cycle 1(1): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:08:30 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.680963585434174 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.666954166666667 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7362500000000003 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7396913043478257 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.138600000000001 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.0325201612903205 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.4287828571428585 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3283693843593984 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.71486666666666 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.184028497409336 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 10.383148788927334 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.153832487309646 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.11283333333332 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.582698412698438 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.298401639344252 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.052379518072287 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.40712927756653 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.993214285714282 ms/frame 13:08:30 INFO - PID 9066 | 13:08:30 INFO - PID 9066 | Cycle 1(2): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:09:16 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6884214969048958 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6701168614357265 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7848483045806067 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7157847341337904 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.081959183673469 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.115946502057614 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.5548578199052145 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4908464223385707 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.662226415094339 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.650903954802255 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 9.901303630363028 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.001900000000004 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.200186567164184 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.871548913043467 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.295963114754084 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.7690588235294 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.541557692307693 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.115972222222222 ms/frame 13:09:16 INFO - PID 9066 | 13:09:16 INFO - PID 9066 | Cycle 1(3): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:10:02 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6896002252252251 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6672750000000003 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.750886814469078 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7365798611111112 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.093669849931787 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.041393939393939 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.4566589861751162 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4083816013628576 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.727242366412215 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.481616438356167 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 10.23935153583617 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.10507575757576 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.91036363636363 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.696336898395742 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.553828451882836 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.271472392638037 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.365416666666643 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.933797814207662 ms/frame 13:10:02 INFO - PID 9066 | 13:10:02 INFO - PID 9066 | Cycle 1(4): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:10:48 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6798936170212766 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6683277731442872 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.75682962529274 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7346877710320896 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.077201086956522 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.00161 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.4286571428571437 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.351566164154101 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.683986742424243 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.377956989247318 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 9.902541254125405 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 9.39063380281691 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.155910780669153 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.528078947368417 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.449543568464716 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.837278106508876 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.408384030418274 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.815189189189176 ms/frame 13:10:48 INFO - PID 9066 | 13:10:48 INFO - PID 9066 | Cycle 1(5): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:11:35 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6761452513966482 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6702253756260437 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.734557803468208 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7261302847282147 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.087772479564031 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.116430041152265 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.4249828767123307 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.368577441077437 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.662179245283015 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.589329608938546 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 9.870115131578958 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 9.664323671497582 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.32450943396226 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.52865789473684 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.500625000000007 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.908333333333324 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.674785992217892 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.051712707182324 ms/frame 13:11:35 INFO - PID 9066 | 13:11:35 INFO - PID 9066 | Cycle 1(6): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:12:21 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.678869613878008 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6673916666666666 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.744406976744186 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.716729613733906 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.038196500672947 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.8996393762183224 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.41377701934016 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3458862876254183 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.693434535104362 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.620435393258427 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 10.490349650349655 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.154974619289334 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.072509225092244 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.477251308900556 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.44921161825727 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.977365269461085 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.45324427480916 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.98914835164832 ms/frame 13:12:21 INFO - PID 9066 | 13:12:21 INFO - PID 9066 | Cycle 1(7): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:13:07 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.677409167132476 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6670541666666667 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7267261219792867 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7377367506516066 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.132451790633609 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.058275862068968 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.606472355769232 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5098333333333325 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.618735955056184 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.619620786516851 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 10.641950354609937 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.41877604166666 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.99285714285714 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.699304812834246 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.71209745762712 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.767941176470563 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.539365384615387 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.052099447513815 ms/frame 13:13:07 INFO - PID 9066 | 13:13:07 INFO - PID 9066 | Cycle 1(8): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:13:53 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6801735722284434 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.667391666666667 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7392405797101447 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6935224386113465 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.115761316872427 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.8928112840466937 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.428925714285716 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.385059221658206 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.661301886792456 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.556888888888888 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 9.616298076923089 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 9.305232558139535 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.113203703703713 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.528184210526295 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.246183673469368 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.565028901734104 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.3664015151515 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.696631016042803 ms/frame 13:13:53 INFO - PID 9066 | 13:13:53 INFO - PID 9066 | Cycle 1(9): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:14:39 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6809915966386555 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6659825145711904 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7341531791907514 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7039991482112435 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0493319838056685 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.8394433781190025 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.4816241299303923 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.442667814113601 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.546109057301293 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.61924157303371 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 10.453832752613241 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.00175000000001 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.411901140684403 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.753521505376337 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.347572016460902 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.977754491017985 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.23719101123596 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.989203296703275 ms/frame 13:14:39 INFO - PID 9066 | 13:14:39 INFO - PID 9066 | Cycle 1(10): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:15:25 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6798600223964166 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.669974958263773 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7691450471698116 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7183591065292096 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.167951388888888 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.176565762004177 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.5591755634638176 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4618598615916985 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.703906844106459 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.450231607629429 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 10.71614285714286 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.641595744680846 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.952609489051106 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.639893617021253 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.609432773109237 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.906339285714282 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.541884615384614 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.051740331491741 ms/frame 13:15:25 INFO - PID 9066 | 13:15:25 INFO - PID 9066 | Cycle 1(11): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:16:11 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_startup = 1.677305757406372 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6658701082431309 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7178362907842017 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.686618887015177 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_startup = 4.190886871508379 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9380511811023635 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_startup = 3.4333066361556073 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3568120805369124 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.736854684512428 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.495604395604389 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_startup = 10.205493197278914 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.480p.60fps.webm_scale_2_inclip = 10.002649999999994 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.031158088235289 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.698850267379706 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.66021097046414 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.976497005988007 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.408365019011413 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.11447222222224 ms/frame 13:16:11 INFO - PID 9066 | 13:16:11 INFO - PID 9066 | Cycle 1(12): loaded http://localhost:56081/tests/video/video_playback.html (next: http://localhost:56081/tests/video/video_playback.html) 13:16:12 INFO - PID 9066 | __start_tp_report 13:16:12 INFO - PID 9066 | _x_x_mozilla_page_load 13:16:12 INFO - PID 9066 | _x_x_mozilla_page_load_details 13:16:12 INFO - PID 9066 | |i|pagename|runs| 13:16:12 INFO - PID 9066 | |0;240p.120fps.mp4_scale_1_startup;1.6898367117117117;1.680963585434174;1.6884214969048958;1.6896002252252251;1.6798936170212766;1.6761452513966482;1.678869613878008;1.677409167132476;1.6801735722284434;1.6809915966386555;1.6798600223964166;1.677305757406372 13:16:12 INFO - PID 9066 | |1;240p.120fps.mp4_scale_1_inclip;1.6712656641604007;1.666954166666667;1.6701168614357265;1.6672750000000003;1.6683277731442872;1.6702253756260437;1.6673916666666666;1.6670541666666667;1.667391666666667;1.6659825145711904;1.669974958263773;1.6658701082431309 13:16:12 INFO - PID 9066 | |2;240p.120fps.mp4_scale_1.1_startup;1.708016505406944;1.7362500000000003;1.7848483045806067;1.750886814469078;1.75682962529274;1.734557803468208;1.744406976744186;1.7267261219792867;1.7392405797101447;1.7341531791907514;1.7691450471698116;1.7178362907842017 13:16:12 INFO - PID 9066 | |3;240p.120fps.mp4_scale_1.1_inclip;1.692385786802031;1.7396913043478257;1.7157847341337904;1.7365798611111112;1.7346877710320896;1.7261302847282147;1.716729613733906;1.7377367506516066;1.6935224386113465;1.7039991482112435;1.7183591065292096;1.686618887015177 13:16:12 INFO - PID 9066 | |4;240p.120fps.mp4_scale_2_startup;4.033077956989246;4.138600000000001;4.081959183673469;4.093669849931787;4.077201086956522;4.087772479564031;4.038196500672947;4.132451790633609;4.115761316872427;4.0493319838056685;4.167951388888888;4.190886871508379 13:16:12 INFO - PID 9066 | |5;240p.120fps.mp4_scale_2_inclip;4.134493801652895;4.0325201612903205;4.115946502057614;4.041393939393939;4.00161;4.116430041152265;3.8996393762183224;4.058275862068968;3.8928112840466937;3.8394433781190025;4.176565762004177;3.9380511811023635 13:16:12 INFO - PID 9066 | |6;480p.60fps.webm_scale_1_startup;3.468549132947977;3.4287828571428585;3.5548578199052145;3.4566589861751162;3.4286571428571437;3.4249828767123307;3.41377701934016;3.606472355769232;3.428925714285716;3.4816241299303923;3.5591755634638176;3.4333066361556073 13:16:12 INFO - PID 9066 | |7;480p.60fps.webm_scale_1_inclip;3.431337907375639;3.3283693843593984;3.4908464223385707;3.4083816013628576;3.351566164154101;3.368577441077437;3.3458862876254183;3.5098333333333325;3.385059221658206;3.442667814113601;3.4618598615916985;3.3568120805369124 13:16:12 INFO - PID 9066 | |8;480p.60fps.webm_scale_1.1_startup;5.7370172084130076;5.71486666666666;5.662226415094339;5.727242366412215;5.683986742424243;5.662179245283015;5.693434535104362;5.618735955056184;5.661301886792456;5.546109057301293;5.703906844106459;5.736854684512428 13:16:12 INFO - PID 9066 | |9;480p.60fps.webm_scale_1.1_inclip;5.57204735376044;5.184028497409336;5.650903954802255;5.481616438356167;5.377956989247318;5.589329608938546;5.620435393258427;5.619620786516851;5.556888888888888;5.61924157303371;5.450231607629429;5.495604395604389 13:16:12 INFO - PID 9066 | |10;480p.60fps.webm_scale_2_startup;9.934668874172175;10.383148788927334;9.901303630363028;10.23935153583617;9.902541254125405;9.870115131578958;10.490349650349655;10.641950354609937;9.616298076923089;10.453832752613241;10.71614285714286;10.205493197278914 13:16:12 INFO - PID 9066 | |11;480p.60fps.webm_scale_2_inclip;10.052562814070365;10.153832487309646;10.001900000000004;10.10507575757576;9.39063380281691;9.664323671497582;10.154974619289334;10.41877604166666;9.305232558139535;10.00175000000001;10.641595744680846;10.002649999999994 13:16:12 INFO - PID 9066 | |12;1080p.60fps.mp4_scale_1_startup;10.911727272727267;11.11283333333332;11.200186567164184;10.91036363636363;11.155910780669153;11.32450943396226;11.072509225092244;10.99285714285714;11.113203703703713;11.411901140684403;10.952609489051106;11.031158088235289 13:16:12 INFO - PID 9066 | |13;1080p.60fps.mp4_scale_1_inclip;10.642047872340434;10.582698412698438;10.871548913043467;10.696336898395742;10.528078947368417;10.52865789473684;10.477251308900556;10.699304812834246;10.528184210526295;10.753521505376337;10.639893617021253;10.698850267379706 13:16:12 INFO - PID 9066 | |14;1080p.60fps.mp4_scale_1.1_startup;12.451514522821586;12.298401639344252;12.295963114754084;12.553828451882836;12.449543568464716;12.500625000000007;12.44921161825727;12.71209745762712;12.246183673469368;12.347572016460902;12.609432773109237;12.66021097046414 13:16:12 INFO - PID 9066 | |15;1080p.60fps.mp4_scale_1.1_inclip;12.125909090909099;12.052379518072287;11.7690588235294;12.271472392638037;11.837278106508876;11.908333333333324;11.977365269461085;11.767941176470563;11.565028901734104;11.977754491017985;11.906339285714282;11.976497005988007 13:16:12 INFO - PID 9066 | |16;1080p.60fps.mp4_scale_2_startup;11.409467680608346;11.40712927756653;11.541557692307693;11.365416666666643;11.408384030418274;11.674785992217892;11.45324427480916;11.539365384615387;11.3664015151515;11.23719101123596;11.541884615384614;11.408365019011413 13:16:12 INFO - PID 9066 | |17;1080p.60fps.mp4_scale_2_inclip;10.934344262295085;10.993214285714282;11.115972222222222;10.933797814207662;10.815189189189176;11.051712707182324;10.98914835164832;11.052099447513815;10.696631016042803;10.989203296703275;11.051740331491741;11.11447222222224 13:16:12 INFO - PID 9066 | __end_tp_report 13:16:12 INFO - PID 9066 | __start_cc_report 13:16:12 INFO - PID 9066 | _x_x_mozilla_cycle_collect,543 13:16:12 INFO - PID 9066 | __end_cc_report 13:16:12 INFO - PID 9066 | __startTimestamp1512249372179__endTimestamp 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | ------- Summary: start ------- 13:16:12 INFO - PID 9066 | Number of tests: 18 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.00 (0.3%) stddev-sans-first:0.00 13:16:12 INFO - PID 9066 | 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:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#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:16:12 INFO - PID 9066 | 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:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.74 Median:1.74 stddev:0.02 (1.2%) stddev-sans-first:0.02 13:16:12 INFO - PID 9066 | Values: 1.7 1.7 1.8 1.8 1.8 1.7 1.7 1.7 1.7 1.7 1.8 1.7 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.72 Median:1.72 stddev:0.02 (1.1%) stddev-sans-first:0.02 13:16:12 INFO - PID 9066 | 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:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.10 Median:4.10 stddev:0.05 (1.2%) stddev-sans-first:0.05 13:16:12 INFO - PID 9066 | Values: 4.0 4.1 4.1 4.1 4.1 4.1 4.0 4.1 4.1 4.0 4.2 4.2 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.02 Median:4.05 stddev:0.11 (2.7%) stddev-sans-first:0.11 13:16:12 INFO - PID 9066 | Values: 4.1 4.0 4.1 4.0 4.0 4.1 3.9 4.1 3.9 3.8 4.2 3.9 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.47 Median:3.46 stddev:0.06 (1.9%) stddev-sans-first:0.07 13:16:12 INFO - PID 9066 | Values: 3.5 3.4 3.6 3.5 3.4 3.4 3.4 3.6 3.4 3.5 3.6 3.4 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.41 Median:3.42 stddev:0.06 (1.8%) stddev-sans-first:0.06 13:16:12 INFO - PID 9066 | Values: 3.4 3.3 3.5 3.4 3.4 3.4 3.3 3.5 3.4 3.4 3.5 3.4 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.68 Median:5.70 stddev:0.06 (1.0%) stddev-sans-first:0.05 13:16:12 INFO - PID 9066 | Values: 5.7 5.7 5.7 5.7 5.7 5.7 5.7 5.6 5.7 5.5 5.7 5.7 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.52 Median:5.58 stddev:0.13 (2.4%) stddev-sans-first:0.14 13:16:12 INFO - PID 9066 | Values: 5.6 5.2 5.7 5.5 5.4 5.6 5.6 5.6 5.6 5.6 5.5 5.5 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.20 Median:10.17 stddev:0.35 (3.4%) stddev-sans-first:0.36 13:16:12 INFO - PID 9066 | Values: 9.9 10.4 9.9 10.2 9.9 9.9 10.5 10.6 9.6 10.5 10.7 10.2 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.99 Median:10.29 stddev:0.38 (3.7%) stddev-sans-first:0.40 13:16:12 INFO - PID 9066 | Values: 10.1 10.2 10.0 10.1 9.4 9.7 10.2 10.4 9.3 10.0 10.6 10.0 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.10 Median:11.11 stddev:0.16 (1.4%) stddev-sans-first:0.15 13:16:12 INFO - PID 9066 | Values: 10.9 11.1 11.2 10.9 11.2 11.3 11.1 11.0 11.1 11.4 11.0 11.0 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.64 Median:10.67 stddev:0.11 (1.1%) stddev-sans-first:0.12 13:16:12 INFO - PID 9066 | Values: 10.6 10.6 10.9 10.7 10.5 10.5 10.5 10.7 10.5 10.8 10.6 10.7 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.46 Median:12.48 stddev:0.15 (1.2%) stddev-sans-first:0.16 13:16:12 INFO - PID 9066 | Values: 12.5 12.3 12.3 12.6 12.4 12.5 12.4 12.7 12.2 12.3 12.6 12.7 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.93 Median:11.98 stddev:0.18 (1.5%) stddev-sans-first:0.18 13:16:12 INFO - PID 9066 | Values: 12.1 12.1 11.8 12.3 11.8 11.9 12.0 11.8 11.6 12.0 11.9 12.0 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.45 Median:11.43 stddev:0.11 (1.0%) stddev-sans-first:0.12 13:16:12 INFO - PID 9066 | Values: 11.4 11.4 11.5 11.4 11.4 11.7 11.5 11.5 11.4 11.2 11.5 11.4 13:16:12 INFO - PID 9066 | 13:16:12 INFO - PID 9066 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.98 Median:11.02 stddev:0.12 (1.1%) stddev-sans-first:0.13 13:16:12 INFO - PID 9066 | Values: 10.9 11.0 11.1 10.9 10.8 11.1 11.0 11.1 10.7 11.0 11.1 11.1 13:16:12 INFO - PID 9066 | -------- Summary: end -------- 13:16:12 INFO - PID 9066 | 13:16:12 INFO - TEST-INFO | 9066: exit 0 13:16:12 INFO - TEST-OK | basic_compositor_video | took 561391ms 13:16:12 INFO - TEST-START | glvideo 13:16:12 INFO - Initialising browser for glvideo test... 13:16:12 INFO - Cloning profile located at /builds/slave/test/build/tests/talos/talos/base_profile 13:16:12 INFO - Installing Add-ons 13:16:12 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:56081/getInfo.html -profile /tmp/tmpGdbwVQ/profile 13:16:12 INFO - TEST-INFO | started process 10292 (/builds/slave/test/build/application/firefox/firefox http://localhost:56081/getInfo.html) 13:16:18 INFO - TEST-INFO | 10292: exit 0 13:16:18 INFO - Browser initialized. 13:16:18 INFO - Running cycle 1/1 for glvideo test... 13:16:18 INFO - Using env: {'DISPLAY': ':0', 13:16:18 INFO - 'HOME': '/home/cltbld', 13:16:18 INFO - 'JSGC_DISABLE_POISONING': '1', 13:16:18 INFO - 'LANG': 'en_US.UTF-8', 13:16:18 INFO - 'LANGUAGE': 'en_US:en', 13:16:18 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:16:18 INFO - 'LOGNAME': 'cltbld', 13:16:18 INFO - 'MAIL': '/var/mail/cltbld', 13:16:18 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:16:18 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:16:18 INFO - 'MOZ_CRASHREPORTER': '1', 13:16:18 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:16:18 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:16:18 INFO - 'MOZ_NO_REMOTE': '1', 13:16:18 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:16:18 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:16:18 INFO - 'NO_EM_RESTART': '1', 13:16:18 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:16:18 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:16:18 INFO - 'PWD': '/builds/slave/test', 13:16:18 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:16:18 INFO - 'RUST_BACKTRACE': 'full', 13:16:18 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:16:18 INFO - 'SHELL': '/bin/bash', 13:16:18 INFO - 'SHLVL': '1', 13:16:18 INFO - 'STYLO_FORCE_DISABLED': '1', 13:16:18 INFO - 'TERM': 'linux', 13:16:18 INFO - 'TMOUT': '86400', 13:16:18 INFO - 'USER': 'cltbld', 13:16:18 INFO - 'XDG_SESSION_COOKIE': '7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297', 13:16:18 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:16:18 INFO - '_': '/tools/buildbot/bin/python'} 13:16:18 INFO - TEST-INFO | started process 10626 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpGdbwVQ/profile) 13:16:19 INFO - PID 10626 | 13:16:19 INFO - PID 10626 | (/builds/slave/test/build/application/firefox/firefox:10677): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:16:19 INFO - PID 10626 | 13:16:21 INFO - PID 10626 | [talos glvideo result] Mean tick time across 100 ticks: 6.90205 ms 13:16:21 INFO - PID 10626 | Cycle 1(1): loaded http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html) 13:16:22 INFO - PID 10626 | [talos glvideo result] Mean tick time across 100 ticks: 6.4949 ms 13:16:22 INFO - PID 10626 | Cycle 1(2): loaded http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html) 13:16:23 INFO - PID 10626 | [talos glvideo result] Mean tick time across 100 ticks: 6.6049 ms 13:16:23 INFO - PID 10626 | Cycle 1(3): loaded http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html) 13:16:25 INFO - PID 10626 | [talos glvideo result] Mean tick time across 100 ticks: 6.7648 ms 13:16:25 INFO - PID 10626 | Cycle 1(4): loaded http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html) 13:16:26 INFO - PID 10626 | [talos glvideo result] Mean tick time across 100 ticks: 6.53345 ms 13:16:26 INFO - PID 10626 | Cycle 1(5): loaded http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56081/tests/webgl/benchmarks/video/video_upload.html) 13:16:26 INFO - PID 10626 | __start_tp_report 13:16:26 INFO - PID 10626 | _x_x_mozilla_page_load 13:16:26 INFO - PID 10626 | _x_x_mozilla_page_load_details 13:16:26 INFO - PID 10626 | |i|pagename|runs| 13:16:26 INFO - PID 10626 | |0;Mean tick time across 100 ticks: ;6.90205;6.4949;6.6049;6.7648;6.53345 13:16:26 INFO - PID 10626 | __end_tp_report 13:16:26 INFO - PID 10626 | __start_cc_report 13:16:26 INFO - PID 10626 | _x_x_mozilla_cycle_collect,282 13:16:26 INFO - PID 10626 | __end_cc_report 13:16:26 INFO - PID 10626 | __startTimestamp1512249386714__endTimestamp 13:16:26 INFO - PID 10626 | 13:16:26 INFO - PID 10626 | ------- Summary: start ------- 13:16:26 INFO - PID 10626 | Number of tests: 1 13:16:26 INFO - PID 10626 | 13:16:26 INFO - PID 10626 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.66 Median:6.60 stddev:0.17 (2.6%) stddev-sans-first:0.12 13:16:26 INFO - PID 10626 | Values: 6.9 6.5 6.6 6.8 6.5 13:16:26 INFO - PID 10626 | -------- Summary: end -------- 13:16:26 INFO - PID 10626 | 13:16:27 INFO - PID 10626 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 13:16:27 INFO - TEST-INFO | 10626: exit 0 13:16:27 INFO - TEST-OK | glvideo | took 14589ms 13:16:27 INFO - SUITE-END | took 575s 13:16:27 INFO - Completed test suite (00:09:36) 13:16:27 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.572420498198453, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6898367117117117, 1.680963585434174, 1.6884214969048958, 1.6896002252252251, 1.6798936170212766, 1.6761452513966482, 1.678869613878008, 1.677409167132476, 1.6801735722284434, 1.6809915966386555, 1.6798600223964166, 1.677305757406372], "value": 1.6798936170212766, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6712656641604007, 1.666954166666667, 1.6701168614357265, 1.6672750000000003, 1.6683277731442872, 1.6702253756260437, 1.6673916666666666, 1.6670541666666667, 1.667391666666667, 1.6659825145711904, 1.669974958263773, 1.6658701082431309], "value": 1.6673916666666666, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.708016505406944, 1.7362500000000003, 1.7848483045806067, 1.750886814469078, 1.75682962529274, 1.734557803468208, 1.744406976744186, 1.7267261219792867, 1.7392405797101447, 1.7341531791907514, 1.7691450471698116, 1.7178362907842017], "value": 1.7392405797101447, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.692385786802031, 1.7396913043478257, 1.7157847341337904, 1.7365798611111112, 1.7346877710320896, 1.7261302847282147, 1.716729613733906, 1.7377367506516066, 1.6935224386113465, 1.7039991482112435, 1.7183591065292096, 1.686618887015177], "value": 1.7183591065292096, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.033077956989246, 4.138600000000001, 4.081959183673469, 4.093669849931787, 4.077201086956522, 4.087772479564031, 4.038196500672947, 4.132451790633609, 4.115761316872427, 4.0493319838056685, 4.167951388888888, 4.190886871508379], "value": 4.093669849931787, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.134493801652895, 4.0325201612903205, 4.115946502057614, 4.041393939393939, 4.00161, 4.116430041152265, 3.8996393762183224, 4.058275862068968, 3.8928112840466937, 3.8394433781190025, 4.176565762004177, 3.9380511811023635], "value": 4.0325201612903205, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.468549132947977, 3.4287828571428585, 3.5548578199052145, 3.4566589861751162, 3.4286571428571437, 3.4249828767123307, 3.41377701934016, 3.606472355769232, 3.428925714285716, 3.4816241299303923, 3.5591755634638176, 3.4333066361556073], "value": 3.4333066361556073, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.431337907375639, 3.3283693843593984, 3.4908464223385707, 3.4083816013628576, 3.351566164154101, 3.368577441077437, 3.3458862876254183, 3.5098333333333325, 3.385059221658206, 3.442667814113601, 3.4618598615916985, 3.3568120805369124], "value": 3.385059221658206, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.7370172084130076, 5.71486666666666, 5.662226415094339, 5.727242366412215, 5.683986742424243, 5.662179245283015, 5.693434535104362, 5.618735955056184, 5.661301886792456, 5.546109057301293, 5.703906844106459, 5.736854684512428], "value": 5.683986742424243, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.57204735376044, 5.184028497409336, 5.650903954802255, 5.481616438356167, 5.377956989247318, 5.589329608938546, 5.620435393258427, 5.619620786516851, 5.556888888888888, 5.61924157303371, 5.450231607629429, 5.495604395604389], "value": 5.556888888888888, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.934668874172175, 10.383148788927334, 9.901303630363028, 10.23935153583617, 9.902541254125405, 9.870115131578958, 10.490349650349655, 10.641950354609937, 9.616298076923089, 10.453832752613241, 10.71614285714286, 10.205493197278914], "value": 10.23935153583617, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.052562814070365, 10.153832487309646, 10.001900000000004, 10.10507575757576, 9.39063380281691, 9.664323671497582, 10.154974619289334, 10.41877604166666, 9.305232558139535, 10.00175000000001, 10.641595744680846, 10.002649999999994], "value": 10.002649999999994, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.911727272727267, 11.11283333333332, 11.200186567164184, 10.91036363636363, 11.155910780669153, 11.32450943396226, 11.072509225092244, 10.99285714285714, 11.113203703703713, 11.411901140684403, 10.952609489051106, 11.031158088235289], "value": 11.11283333333332, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.642047872340434, 10.582698412698438, 10.871548913043467, 10.696336898395742, 10.528078947368417, 10.52865789473684, 10.477251308900556, 10.699304812834246, 10.528184210526295, 10.753521505376337, 10.639893617021253, 10.698850267379706], "value": 10.639893617021253, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.451514522821586, 12.298401639344252, 12.295963114754084, 12.553828451882836, 12.449543568464716, 12.500625000000007, 12.44921161825727, 12.71209745762712, 12.246183673469368, 12.347572016460902, 12.609432773109237, 12.66021097046414], "value": 12.449543568464716, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.125909090909099, 12.052379518072287, 11.7690588235294, 12.271472392638037, 11.837278106508876, 11.908333333333324, 11.977365269461085, 11.767941176470563, 11.565028901734104, 11.977754491017985, 11.906339285714282, 11.976497005988007], "value": 11.908333333333324, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.409467680608346, 11.40712927756653, 11.541557692307693, 11.365416666666643, 11.408384030418274, 11.674785992217892, 11.45324427480916, 11.539365384615387, 11.3664015151515, 11.23719101123596, 11.541884615384614, 11.408365019011413], "value": 11.408384030418274, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.934344262295085, 10.993214285714282, 11.115972222222222, 10.933797814207662, 10.815189189189176, 11.051712707182324, 10.98914835164832, 11.052099447513815, 10.696631016042803, 10.989203296703275, 11.051740331491741, 11.11447222222224], "value": 10.993214285714282, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.90205, 6.4949, 6.6049, 6.7648, 6.53345], "value": 6.5691749999999995, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]} 13:16:27 INFO - Return code: 0 13:16:27 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 13:16:27 INFO - # TBPL SUCCESS # 13:16:27 INFO - Running post-action listener: _package_coverage_data 13:16:27 INFO - Running post-action listener: _resource_record_post_action 13:16:27 INFO - [mozharness: 2017-12-02 21:16:27.893701Z] Finished run-tests step (success) 13:16:27 INFO - Running post-run listener: _resource_record_post_run 13:16:27 INFO - Total resource usage - Wall time: 596s; CPU: 38.0%; Read bytes: 6111232; Write bytes: 316973056; Read time: 968; Write time: 258440 13:16:27 INFO - TinderboxPrint: CPU usage
38.4% 13:16:27 INFO - TinderboxPrint: I/O read bytes / time
6,111,232 / 968 13:16:27 INFO - TinderboxPrint: I/O write bytes / time
316,973,056 / 258,440 13:16:27 INFO - TinderboxPrint: CPU idle
2,881.3 (61.6%) 13:16:27 INFO - TinderboxPrint: CPU system
304.8 (6.5%) 13:16:27 INFO - TinderboxPrint: CPU user
1,474.4 (31.5%) 13:16:27 INFO - TinderboxPrint: Swap in / out
0 / 0 13:16:27 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 5242880; Read time: 0; Write time: 1464 13:16:27 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 13:16:27 INFO - run-tests - Wall time: 577s; CPU: 39.0%; Read bytes: 6111232; Write bytes: 311181312; Read time: 968; Write time: 256940 13:16:28 INFO - Running post-run listener: _upload_blobber_files 13:16:28 INFO - Blob upload gear active. 13:16:28 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 13:16:28 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:16:28 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:16:28 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:16:28 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:16:28 INFO - SNIMissingWarning 13:16:28 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:16:28 INFO - InsecurePlatformWarning 13:16:28 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:16:28 INFO - SubjectAltNameWarning 13:16:28 INFO - (blobuploader) - INFO - Open directory for files ... 13:16:28 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log ... 13:16:28 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:16:28 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:16:28 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:16:28 INFO - InsecurePlatformWarning 13:16:28 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:16:28 INFO - SubjectAltNameWarning 13:16:29 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:16:29 INFO - InsecurePlatformWarning 13:16:29 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_errorsummary.log: uploaded 13:16:29 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:16:29 INFO - (blobuploader) - INFO - Done attempting. 13:16:29 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 13:16:29 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:16:29 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:16:29 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:16:29 INFO - InsecurePlatformWarning 13:16:29 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:16:29 INFO - SubjectAltNameWarning 13:16:34 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:16:34 INFO - InsecurePlatformWarning 13:16:34 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 13:16:34 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:16:34 INFO - (blobuploader) - INFO - Done attempting. 13:16:34 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 13:16:34 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:16:34 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:16:34 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:16:34 INFO - InsecurePlatformWarning 13:16:34 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:16:34 INFO - SubjectAltNameWarning 13:16:35 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:16:35 INFO - InsecurePlatformWarning 13:16:35 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 13:16:35 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:16:35 INFO - (blobuploader) - INFO - Done attempting. 13:16:35 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log ... 13:16:35 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:16:35 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:16:35 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:16:35 INFO - InsecurePlatformWarning 13:16:35 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:16:35 INFO - SubjectAltNameWarning 13:16:36 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:16:36 INFO - InsecurePlatformWarning 13:16:36 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_raw.log: uploaded 13:16:36 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:16:36 INFO - (blobuploader) - INFO - Done attempting. 13:16:36 INFO - (blobuploader) - INFO - Iteration through files over. 13:16:36 INFO - Return code: 0 13:16:36 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 13:16:36 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 13:16:36 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/e46f99f83f19fe18eaaad3501ddf6a6a8efa4a5eb65f4f6f8e317a5f7deb5010c9e4c118f9ac59804b384fd9d402e41424f8859eb830d3149d8203de39a8454a", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/50959b6554774c4bc64a5dbaa4f4f0a41e47cf10b5559272fb400d46f65e1e9f4ef4b7a76453102a61a3f2d5bc18498c1a7dd4d2db3b838ffe9fa6bab4c142ca", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3bfa137107136d37da462f74763eb9ff188730d0bda9db7b2b5792908d14a95b7f0d07a6ead6ff1b0cf48ff03e89a884428825712c5f629e648b2bfa42f2b0e6", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7627c83f53095a686e71cc298c88fe197d5cd191c0c8bcfa73eade5ab51cc687164dce90bcac3515915059b15729e2ea687f75b22bc54af63096427b8d4efbf7"} 13:16:36 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 13:16:36 INFO - Writing to file /builds/slave/test/properties/blobber_files 13:16:36 INFO - Contents: 13:16:36 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/e46f99f83f19fe18eaaad3501ddf6a6a8efa4a5eb65f4f6f8e317a5f7deb5010c9e4c118f9ac59804b384fd9d402e41424f8859eb830d3149d8203de39a8454a", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/50959b6554774c4bc64a5dbaa4f4f0a41e47cf10b5559272fb400d46f65e1e9f4ef4b7a76453102a61a3f2d5bc18498c1a7dd4d2db3b838ffe9fa6bab4c142ca", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3bfa137107136d37da462f74763eb9ff188730d0bda9db7b2b5792908d14a95b7f0d07a6ead6ff1b0cf48ff03e89a884428825712c5f629e648b2bfa42f2b0e6", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7627c83f53095a686e71cc298c88fe197d5cd191c0c8bcfa73eade5ab51cc687164dce90bcac3515915059b15729e2ea687f75b22bc54af63096427b8d4efbf7"} 13:16:36 INFO - Running post-run listener: copy_logs_to_upload_dir 13:16:36 INFO - Copying logs to upload dir... 13:16:36 INFO - mkdir: /builds/slave/test/build/upload/logs 13:16:36 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=660.666889 ========= master_lag: 0.04 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 0 secs) (at 2017-12-02 13:16:36.439953) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-12-02 13:16:36.443940) ========= 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=7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297 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/e46f99f83f19fe18eaaad3501ddf6a6a8efa4a5eb65f4f6f8e317a5f7deb5010c9e4c118f9ac59804b384fd9d402e41424f8859eb830d3149d8203de39a8454a", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/50959b6554774c4bc64a5dbaa4f4f0a41e47cf10b5559272fb400d46f65e1e9f4ef4b7a76453102a61a3f2d5bc18498c1a7dd4d2db3b838ffe9fa6bab4c142ca", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3bfa137107136d37da462f74763eb9ff188730d0bda9db7b2b5792908d14a95b7f0d07a6ead6ff1b0cf48ff03e89a884428825712c5f629e648b2bfa42f2b0e6", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7627c83f53095a686e71cc298c88fe197d5cd191c0c8bcfa73eade5ab51cc687164dce90bcac3515915059b15729e2ea687f75b22bc54af63096427b8d4efbf7"} build_url:https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011415 build_url: 'https://queue.taskcluster.net/v1/task/ZkkQmAVxSLi0rTbCwmZJgA/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/e46f99f83f19fe18eaaad3501ddf6a6a8efa4a5eb65f4f6f8e317a5f7deb5010c9e4c118f9ac59804b384fd9d402e41424f8859eb830d3149d8203de39a8454a", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/50959b6554774c4bc64a5dbaa4f4f0a41e47cf10b5559272fb400d46f65e1e9f4ef4b7a76453102a61a3f2d5bc18498c1a7dd4d2db3b838ffe9fa6bab4c142ca", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3bfa137107136d37da462f74763eb9ff188730d0bda9db7b2b5792908d14a95b7f0d07a6ead6ff1b0cf48ff03e89a884428825712c5f629e648b2bfa42f2b0e6", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7627c83f53095a686e71cc298c88fe197d5cd191c0c8bcfa73eade5ab51cc687164dce90bcac3515915059b15729e2ea687f75b22bc54af63096427b8d4efbf7"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-12-02 13:16:36.479408) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-12-02 13:16:36.480192) ========= 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=7fc86f70bae03e018da0b1d8000001c4-1512247610.120519-1912929297 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004517 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-12-02 13:16:36.561916) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-12-02 13:16:36.562244) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-12-02 13:16:36.562604) ========= ========= Total master_lag: 0.25 =========