builder: mozilla-central_ubuntu64_hw_test-g4-e10s-pgo slave: talos-linux64-ix-035 starttime: 1507473285.14 results: success (0) revision: 5e030a486ad8535969c4f6c1955c253a12ee8c51 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.142976) ========= master: http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.143409) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.143679) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.248380) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.248646) ========= 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=ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-10-08 07:34:45-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.102, 63.245.215.25 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 224M=0s 2017-10-08 07:34:45 (224 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.209737 ========= master_lag: 0.06 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.522499) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.522791) ========= 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=ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.020105 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.571679) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:45.571967) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 5e030a486ad8535969c4f6c1955c253a12ee8c51 --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 5e030a486ad8535969c4f6c1955c253a12ee8c51 --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=ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-10-08 07:34:45,532 truncating revision to first 12 chars 2017-10-08 07:34:45,532 Setting DEBUG logging. 2017-10-08 07:34:45,533 attempt 1/10 2017-10-08 07:34:45,533 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/5e030a486ad8?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-10-08 07:34:45,937 unpacking tar archive at: mozilla-central-5e030a486ad8/testing/mozharness/ program finished with exit code 0 elapsedTime=0.773164 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:46.368381) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:46.368679) ========= script_repo_revision: 5e030a486ad8535969c4f6c1955c253a12ee8c51 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:46.369038) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:46.369316) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-08 07:34:46.391295) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 46 secs) (at 2017-10-08 07:34:46.391562) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 07:34:46 INFO - MultiFileLogger online at 20171008 07:34:46 in /builds/slave/test 07:34:46 INFO - Run as scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 07:34:46 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 07:34:46 INFO - {'append_to_log': False, 07:34:46 INFO - 'base_work_dir': '/builds/slave/test', 07:34:46 INFO - 'blob_upload_branch': 'Firefox', 07:34:46 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 07:34:46 INFO - 'branch': 'Firefox', 07:34:46 INFO - 'buildbot_json_path': 'buildprops.json', 07:34:46 INFO - 'code_coverage': False, 07:34:46 INFO - 'config_files': ('talos/linux_config.py',), 07:34:46 INFO - 'default_actions': ('clobber', 07:34:46 INFO - 'read-buildbot-config', 07:34:46 INFO - 'download-and-extract', 07:34:46 INFO - 'populate-webroot', 07:34:46 INFO - 'create-virtualenv', 07:34:46 INFO - 'install', 07:34:46 INFO - 'setup-mitmproxy', 07:34:46 INFO - 'run-tests'), 07:34:46 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 07:34:46 INFO - 'disable_ccov_upload': False, 07:34:46 INFO - 'disable_stylo': False, 07:34:46 INFO - 'download_minidump_stackwalk': True, 07:34:46 INFO - 'download_symbols': 'ondemand', 07:34:46 INFO - 'enable_stylo': False, 07:34:46 INFO - 'enable_webrender': False, 07:34:46 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 07:34:46 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 07:34:46 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 07:34:46 INFO - 'gecko_profile': False, 07:34:46 INFO - 'gecko_profile_interval': 0, 07:34:46 INFO - 'installer_path': 'installer.exe', 07:34:46 INFO - 'log_level': 'info', 07:34:46 INFO - 'log_name': 'talos', 07:34:46 INFO - 'log_to_console': True, 07:34:46 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 07:34:46 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 07:34:46 INFO - 'opt_config_files': (), 07:34:46 INFO - 'pip_index': False, 07:34:46 INFO - 'suite': 'g4-e10s', 07:34:46 INFO - 'system_bits': '32', 07:34:46 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 07:34:46 INFO - 'title': 'talos-linux64-ix-035', 07:34:46 INFO - 'tooltool_cache': '/builds/tooltool_cache', 07:34:46 INFO - 'use_talos_json': True, 07:34:46 INFO - 'verify': 'False', 07:34:46 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 07:34:46 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 07:34:46 INFO - 'work_dir': 'build'} 07:34:46 INFO - [mozharness: 2017-10-08 14:34:46.578461Z] Running clobber step. 07:34:46 INFO - Running pre-action listener: _resource_record_pre_action 07:34:46 INFO - Running main action method: clobber 07:34:46 INFO - rmtree: /builds/slave/test/build 07:34:46 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 07:34:47 INFO - Running post-action listener: _resource_record_post_action 07:34:47 INFO - [mozharness: 2017-10-08 14:34:47.522745Z] Finished clobber step (success) 07:34:47 INFO - [mozharness: 2017-10-08 14:34:47.522841Z] Running read-buildbot-config step. 07:34:47 INFO - Running pre-action listener: _resource_record_pre_action 07:34:47 INFO - Running main action method: read_buildbot_config 07:34:47 INFO - Using buildbot properties: 07:34:47 INFO - { 07:34:47 INFO - "project": "", 07:34:47 INFO - "product": "firefox", 07:34:47 INFO - "who": "archaeopteryx@coole-files.de", 07:34:47 INFO - "installer_path": "public/build/target.tar.bz2", 07:34:47 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-e10s", 07:34:47 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 07:34:47 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-e10s", 07:34:47 INFO - "stage_platform": "linux64-pgo", 07:34:47 INFO - "basedir": "/builds/slave/test", 07:34:47 INFO - "buildnumber": 225, 07:34:47 INFO - "platform": "ubuntu64_hw", 07:34:47 INFO - "master": "http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/", 07:34:47 INFO - "slavebuilddir": "test", 07:34:47 INFO - "taskId": "GYQOOkz9RRStKY-Z7DvovQ", 07:34:47 INFO - "branch": "mozilla-central", 07:34:47 INFO - "script_repo_revision": "production", 07:34:47 INFO - "revision": "5e030a486ad8535969c4f6c1955c253a12ee8c51", 07:34:47 INFO - "slavename": "talos-linux64-ix-035", 07:34:47 INFO - "repo_path": "mozilla-central" 07:34:47 INFO - } 07:34:47 INFO - Finding installer, test and symbols from parent task. 07:34:47 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/GYQOOkz9RRStKY-Z7DvovQ'}, attempt #1 07:34:47 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/GYQOOkz9RRStKY-Z7DvovQ'}, attempt #1 07:34:48 INFO - Task dependencies: U4d1o1h6RfSYXdRazbM7jg 07:34:48 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg'}, attempt #1 07:34:48 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2 07:34:48 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.test_packages.json 07:34:48 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.crashreporter-symbols.zip 07:34:48 INFO - Running post-action listener: _resource_record_post_action 07:34:48 INFO - [mozharness: 2017-10-08 14:34:48.954847Z] Finished read-buildbot-config step (success) 07:34:48 INFO - [mozharness: 2017-10-08 14:34:48.955065Z] Running download-and-extract step. 07:34:48 INFO - Running pre-action listener: _resource_record_pre_action 07:34:48 INFO - Running main action method: download_and_extract 07:34:48 INFO - mkdir: /builds/slave/test/build/tests 07:34:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:34:48 INFO - trying https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.test_packages.json 07:34:48 INFO - Downloading https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 07:34:48 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 07:34:49 INFO - Downloaded 989 bytes. 07:34:49 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 07:34:49 INFO - Using the following test package requirements: 07:34:49 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 07:34:49 INFO - u'common': [u'target.common.tests.zip'], 07:34:49 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 07:34:49 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 07:34:49 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 07:34:49 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 07:34:49 INFO - u'mozbase': [u'target.common.tests.zip'], 07:34:49 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 07:34:49 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 07:34:49 INFO - u'web-platform': [u'target.common.tests.zip', 07:34:49 INFO - u'target.web-platform.tests.tar.gz'], 07:34:49 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 07:34:49 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 07:34:49 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.common.tests.zip 07:34:49 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.common.tests.zip'}, attempt #1 07:34:49 INFO - Fetch https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.common.tests.zip into memory 07:34:51 INFO - Content-Length response header: 55885528 07:34:51 INFO - Bytes received: 55885528 07:35:02 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.talos.tests.zip 07:35:02 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.talos.tests.zip'}, attempt #1 07:35:02 INFO - Fetch https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.talos.tests.zip into memory 07:35:03 INFO - Content-Length response header: 14431952 07:35:03 INFO - Bytes received: 14431952 07:35:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:03 INFO - trying https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2 07:35:03 INFO - Downloading https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 07:35:03 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 07:35:06 INFO - Downloaded 62640895 bytes. 07:35:06 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2 07:35:06 INFO - mkdir: /builds/slave/test/properties 07:35:06 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 07:35:06 INFO - Writing to file /builds/slave/test/properties/build_url 07:35:06 INFO - Contents: 07:35:06 INFO - build_url:https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2 07:35:06 INFO - Running post-action listener: _resource_record_post_action 07:35:06 INFO - Running post-action listener: find_tests_for_verification 07:35:06 INFO - Running post-action listener: set_extra_try_arguments 07:35:06 INFO - [mozharness: 2017-10-08 14:35:06.773223Z] Finished download-and-extract step (success) 07:35:06 INFO - [mozharness: 2017-10-08 14:35:06.773492Z] Running populate-webroot step. 07:35:06 INFO - Running pre-action listener: _resource_record_pre_action 07:35:06 INFO - Running main action method: populate_webroot 07:35:06 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 07:35:06 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['tresize', 07:35:06 INFO - 'tcanvasmark']}, 07:35:06 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 07:35:06 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['dromaeo_css', 07:35:06 INFO - 'kraken']}, 07:35:06 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 07:35:06 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 07:35:06 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'tests': ['damp', 'tps']}, 07:35:06 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['damp', 'tps']}, 07:35:06 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 07:35:06 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['dromaeo_dom']}, 07:35:06 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 07:35:06 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['basic_compositor_video', 07:35:06 INFO - 'glvideo']}, 07:35:06 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 07:35:06 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['ts_paint_webext', 07:35:06 INFO - 'tp5o_webext']}, 07:35:06 INFO - 'other-e10s': {'tests': ['a11yr', 07:35:06 INFO - 'ts_paint', 07:35:06 INFO - 'tpaint', 07:35:06 INFO - 'sessionrestore', 07:35:06 INFO - 'sessionrestore_many_windows', 07:35:06 INFO - 'sessionrestore_no_auto_restore', 07:35:06 INFO - 'tabpaint', 07:35:06 INFO - 'cpstartup']}, 07:35:06 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['a11yr', 07:35:06 INFO - 'ts_paint', 07:35:06 INFO - 'tpaint', 07:35:06 INFO - 'sessionrestore', 07:35:06 INFO - 'sessionrestore_many_windows', 07:35:06 INFO - 'sessionrestore_no_auto_restore', 07:35:06 INFO - 'tabpaint', 07:35:06 INFO - 'cpstartup']}, 07:35:06 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 07:35:06 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 07:35:06 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['perf_reftest_singletons']}, 07:35:06 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['perf_reftest']}, 07:35:06 INFO - 'svgr-e10s': {'tests': ['tsvgx', 07:35:06 INFO - 'tsvgr_opacity', 07:35:06 INFO - 'tart', 07:35:06 INFO - 'tscrollx', 07:35:06 INFO - 'tsvg_static']}, 07:35:06 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['tsvgx', 07:35:06 INFO - 'tsvgr_opacity', 07:35:06 INFO - 'tart', 07:35:06 INFO - 'tscrollx', 07:35:06 INFO - 'tsvg_static']}, 07:35:06 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 07:35:06 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'talos_options': ['--disable-stylo'], 07:35:06 INFO - 'tests': ['tp5o']}, 07:35:06 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 07:35:06 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 07:35:06 INFO - 'talos_options': ['--mitmproxy', 07:35:06 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 07:35:06 INFO - '--firstNonBlankPaint'], 07:35:06 INFO - 'tests': ['tp6_google', 07:35:06 INFO - 'tp6_youtube', 07:35:06 INFO - 'tp6_amazon', 07:35:06 INFO - 'tp6_facebook']}, 07:35:06 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 07:35:06 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 07:35:06 INFO - 'talos_options': ['--disable-stylo', 07:35:06 INFO - '--mitmproxy', 07:35:06 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 07:35:06 INFO - '--firstNonBlankPaint'], 07:35:06 INFO - 'tests': ['tp6_google', 07:35:06 INFO - 'tp6_youtube', 07:35:06 INFO - 'tp6_amazon', 07:35:06 INFO - 'tp6_facebook']}, 07:35:06 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 07:35:06 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 07:35:06 INFO - 'talos_options': ['--stylo-threads=1', 07:35:06 INFO - '--mitmproxy', 07:35:06 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 07:35:06 INFO - '--firstNonBlankPaint'], 07:35:06 INFO - 'tests': ['tp6_google', 07:35:06 INFO - 'tp6_youtube', 07:35:06 INFO - 'tp6_amazon', 07:35:06 INFO - 'tp6_facebook']}, 07:35:06 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'talos_options': ['--xperf_path', 07:35:06 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 07:35:06 INFO - 'tests': ['tp5n']}, 07:35:06 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:35:06 INFO - 'talos_options': ['--disable-stylo', 07:35:06 INFO - '--xperf_path', 07:35:06 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 07:35:06 INFO - 'tests': ['tp5n']}}} 07:35:06 INFO - Running post-action listener: _resource_record_post_action 07:35:06 INFO - [mozharness: 2017-10-08 14:35:06.799186Z] Finished populate-webroot step (success) 07:35:06 INFO - [mozharness: 2017-10-08 14:35:06.799280Z] Running create-virtualenv step. 07:35:06 INFO - Running pre-action listener: _resource_record_pre_action 07:35:06 INFO - Running main action method: create_virtualenv 07:35:06 INFO - Creating virtualenv /builds/slave/test/build/venv 07:35:06 INFO - Running command: ['virtualenv', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 07:35:06 INFO - Copy/paste: virtualenv --no-site-packages --distribute /builds/slave/test/build/venv 07:35:06 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 07:35:07 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 07:35:07 INFO - New python executable in /builds/slave/test/build/venv/bin/python 07:35:07 INFO - Installing distribute.............................................................................................................................................................................................done. 07:35:08 INFO - Installing pip...............done. 07:35:08 INFO - Return code: 0 07:35:08 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 07:35:08 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 07:35:08 INFO - Reading from file tmpfile_stdout 07:35:08 INFO - Output received: 07:35:08 INFO - pip 1.1 from /builds/slave/test/build/venv/lib/python2.7/site-packages/pip-1.1-py2.7.egg (python 2.7) 07:35:08 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 07:35:08 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:08 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:08 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:08 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:08 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', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:08 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', 'pip>=1.5'] in /builds/slave/test/build 07:35:08 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 pip>=1.5 07:35:08 INFO - Using env: {'DISPLAY': ':0', 07:35:08 INFO - 'HOME': '/home/cltbld', 07:35:08 INFO - 'LANG': 'en_US.UTF-8', 07:35:08 INFO - 'LANGUAGE': 'en_US:en', 07:35:08 INFO - 'LOGNAME': 'cltbld', 07:35:08 INFO - 'MAIL': '/var/mail/cltbld', 07:35:08 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:08 INFO - 'MOZ_NO_REMOTE': '1', 07:35:08 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:08 INFO - 'NO_EM_RESTART': '1', 07:35:08 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:08 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:08 INFO - 'PWD': '/builds/slave/test', 07:35:08 INFO - 'SHELL': '/bin/bash', 07:35:08 INFO - 'SHLVL': '1', 07:35:08 INFO - 'TERM': 'linux', 07:35:08 INFO - 'TMOUT': '86400', 07:35:08 INFO - 'USER': 'cltbld', 07:35:08 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:08 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:08 INFO - '_': '/tools/buildbot/bin/python'} 07:35:09 INFO - Ignoring indexes: http://pypi.python.org/simple/ 07:35:09 INFO - Downloading/unpacking pip>=1.5 07:35:09 INFO - Running setup.py egg_info for package pip 07:35:09 INFO - warning: no files found matching 'pip/cacert.pem' 07:35:09 INFO - warning: no files found matching '*.html' under directory 'docs' 07:35:09 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 07:35:09 INFO - no previously-included directories found matching 'docs/_build/_sources' 07:35:09 INFO - Installing collected packages: pip 07:35:09 INFO - Found existing installation: pip 1.1 07:35:09 INFO - Uninstalling pip: 07:35:09 INFO - Successfully uninstalled pip 07:35:09 INFO - Running setup.py install for pip 07:35:09 INFO - warning: no files found matching 'pip/cacert.pem' 07:35:09 INFO - warning: no files found matching '*.html' under directory 'docs' 07:35:09 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 07:35:09 INFO - no previously-included directories found matching 'docs/_build/_sources' 07:35:09 INFO - Installing pip script to /builds/slave/test/build/venv/bin 07:35:09 INFO - Installing pip2.7 script to /builds/slave/test/build/venv/bin 07:35:09 INFO - Installing pip2 script to /builds/slave/test/build/venv/bin 07:35:09 INFO - Successfully installed pip 07:35:09 INFO - Cleaning up... 07:35:09 INFO - Return code: 0 07:35:09 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 07:35: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')]} 07:35:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35: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')]} 07:35:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:09 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', '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 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:09 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', 'psutil>=3.1.1'] in /builds/slave/test/build 07:35:09 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 psutil>=3.1.1 07:35:09 INFO - Using env: {'DISPLAY': ':0', 07:35:09 INFO - 'HOME': '/home/cltbld', 07:35:09 INFO - 'LANG': 'en_US.UTF-8', 07:35:09 INFO - 'LANGUAGE': 'en_US:en', 07:35:09 INFO - 'LOGNAME': 'cltbld', 07:35:09 INFO - 'MAIL': '/var/mail/cltbld', 07:35:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:09 INFO - 'MOZ_NO_REMOTE': '1', 07:35:09 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:09 INFO - 'NO_EM_RESTART': '1', 07:35:09 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:09 INFO - 'PWD': '/builds/slave/test', 07:35:09 INFO - 'SHELL': '/bin/bash', 07:35:09 INFO - 'SHLVL': '1', 07:35:09 INFO - 'TERM': 'linux', 07:35:09 INFO - 'TMOUT': '86400', 07:35:09 INFO - 'USER': 'cltbld', 07:35:09 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:09 INFO - '_': '/tools/buildbot/bin/python'} 07:35:09 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:09 INFO - Downloading/unpacking psutil>=3.1.1 07:35:09 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:09 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:09 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:09 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:10 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 07:35:11 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 07:35:11 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 07:35:11 INFO - Installing collected packages: psutil 07:35:11 INFO - Running setup.py install for psutil 07:35:11 INFO - building 'psutil._psutil_linux' extension 07:35:11 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o 07:35:13 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so 07:35:13 INFO - building 'psutil._psutil_posix' extension 07:35:13 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o 07:35:13 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so 07:35:13 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 07:35:13 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 07:35:13 INFO - Successfully installed psutil 07:35:13 INFO - Cleaning up... 07:35:13 INFO - Return code: 0 07:35:13 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 07:35:13 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')]} 07:35:13 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:13 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')]} 07:35:13 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:13 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', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:13 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', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 07:35:13 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 mozsystemmonitor==0.3 07:35:13 INFO - Using env: {'DISPLAY': ':0', 07:35:13 INFO - 'HOME': '/home/cltbld', 07:35:13 INFO - 'LANG': 'en_US.UTF-8', 07:35:13 INFO - 'LANGUAGE': 'en_US:en', 07:35:13 INFO - 'LOGNAME': 'cltbld', 07:35:13 INFO - 'MAIL': '/var/mail/cltbld', 07:35:13 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:13 INFO - 'MOZ_NO_REMOTE': '1', 07:35:13 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:13 INFO - 'NO_EM_RESTART': '1', 07:35:13 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:13 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:13 INFO - 'PWD': '/builds/slave/test', 07:35:13 INFO - 'SHELL': '/bin/bash', 07:35:13 INFO - 'SHLVL': '1', 07:35:13 INFO - 'TERM': 'linux', 07:35:13 INFO - 'TMOUT': '86400', 07:35:13 INFO - 'USER': 'cltbld', 07:35:13 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:13 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:13 INFO - '_': '/tools/buildbot/bin/python'} 07:35:14 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:14 INFO - Downloading/unpacking mozsystemmonitor==0.3 07:35:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:15 INFO - Downloading mozsystemmonitor-0.3.tar.gz 07:35:15 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 07:35:15 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 07:35:15 INFO - Installing collected packages: mozsystemmonitor 07:35:15 INFO - Running setup.py install for mozsystemmonitor 07:35:15 INFO - Successfully installed mozsystemmonitor 07:35:15 INFO - Cleaning up... 07:35:15 INFO - Return code: 0 07:35:15 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 07:35:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:15 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:15 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:15 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', '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 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:15 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', 'jsonschema==2.5.1'] in /builds/slave/test/build 07:35:15 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 jsonschema==2.5.1 07:35:15 INFO - Using env: {'DISPLAY': ':0', 07:35:15 INFO - 'HOME': '/home/cltbld', 07:35:15 INFO - 'LANG': 'en_US.UTF-8', 07:35:15 INFO - 'LANGUAGE': 'en_US:en', 07:35:15 INFO - 'LOGNAME': 'cltbld', 07:35:15 INFO - 'MAIL': '/var/mail/cltbld', 07:35:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:15 INFO - 'MOZ_NO_REMOTE': '1', 07:35:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:15 INFO - 'NO_EM_RESTART': '1', 07:35:15 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:15 INFO - 'PWD': '/builds/slave/test', 07:35:15 INFO - 'SHELL': '/bin/bash', 07:35:15 INFO - 'SHLVL': '1', 07:35:15 INFO - 'TERM': 'linux', 07:35:15 INFO - 'TMOUT': '86400', 07:35:15 INFO - 'USER': 'cltbld', 07:35:15 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:15 INFO - '_': '/tools/buildbot/bin/python'} 07:35:15 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:15 INFO - Downloading/unpacking jsonschema==2.5.1 07:35:15 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:15 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:15 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:15 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:16 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 07:35:16 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 07:35:16 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:16 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:16 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:16 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:16 INFO - Downloading functools32-3.2.3-2.tar.gz 07:35:16 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 07:35:16 INFO - warning: no files found matching '*.txt' 07:35:16 INFO - no previously-included directories found matching 'build' 07:35:16 INFO - no previously-included directories found matching 'dist' 07:35:16 INFO - no previously-included directories found matching '.git*' 07:35:16 INFO - Installing collected packages: jsonschema, functools32 07:35:16 INFO - Running setup.py install for functools32 07:35:17 INFO - warning: no files found matching '*.txt' 07:35:17 INFO - no previously-included directories found matching 'build' 07:35:17 INFO - no previously-included directories found matching 'dist' 07:35:17 INFO - no previously-included directories found matching '.git*' 07:35:17 INFO - Successfully installed jsonschema functools32 07:35:17 INFO - Cleaning up... 07:35:17 INFO - Return code: 0 07:35:17 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 07:35:17 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')]} 07:35:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:17 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')]} 07:35:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:17 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', '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 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:17 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', 'functools32==3.2.3-2'] in /builds/slave/test/build 07:35:17 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 functools32==3.2.3-2 07:35:17 INFO - Using env: {'DISPLAY': ':0', 07:35:17 INFO - 'HOME': '/home/cltbld', 07:35:17 INFO - 'LANG': 'en_US.UTF-8', 07:35:17 INFO - 'LANGUAGE': 'en_US:en', 07:35:17 INFO - 'LOGNAME': 'cltbld', 07:35:17 INFO - 'MAIL': '/var/mail/cltbld', 07:35:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:17 INFO - 'MOZ_NO_REMOTE': '1', 07:35:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:17 INFO - 'NO_EM_RESTART': '1', 07:35:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:17 INFO - 'PWD': '/builds/slave/test', 07:35:17 INFO - 'SHELL': '/bin/bash', 07:35:17 INFO - 'SHLVL': '1', 07:35:17 INFO - 'TERM': 'linux', 07:35:17 INFO - 'TMOUT': '86400', 07:35:17 INFO - 'USER': 'cltbld', 07:35:17 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:17 INFO - '_': '/tools/buildbot/bin/python'} 07:35:17 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:17 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 07:35:17 INFO - Cleaning up... 07:35:17 INFO - Return code: 0 07:35:17 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 07:35:17 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')]} 07:35:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:17 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')]} 07:35:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:17 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', '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 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:17 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', 'blobuploader==1.2.4'] in /builds/slave/test/build 07:35:17 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 blobuploader==1.2.4 07:35:17 INFO - Using env: {'DISPLAY': ':0', 07:35:17 INFO - 'HOME': '/home/cltbld', 07:35:17 INFO - 'LANG': 'en_US.UTF-8', 07:35:17 INFO - 'LANGUAGE': 'en_US:en', 07:35:17 INFO - 'LOGNAME': 'cltbld', 07:35:17 INFO - 'MAIL': '/var/mail/cltbld', 07:35:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:17 INFO - 'MOZ_NO_REMOTE': '1', 07:35:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:17 INFO - 'NO_EM_RESTART': '1', 07:35:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:17 INFO - 'PWD': '/builds/slave/test', 07:35:17 INFO - 'SHELL': '/bin/bash', 07:35:17 INFO - 'SHLVL': '1', 07:35:17 INFO - 'TERM': 'linux', 07:35:17 INFO - 'TMOUT': '86400', 07:35:17 INFO - 'USER': 'cltbld', 07:35:17 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:17 INFO - '_': '/tools/buildbot/bin/python'} 07:35:17 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:17 INFO - Downloading/unpacking blobuploader==1.2.4 07:35:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:18 INFO - Downloading blobuploader-1.2.4.tar.gz 07:35:18 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 07:35:18 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 07:35:18 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:18 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:18 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:18 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:18 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 07:35:19 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 07:35:19 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:19 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:19 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:19 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:19 INFO - Downloading docopt-0.6.1.tar.gz 07:35:19 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 07:35:19 INFO - Installing collected packages: blobuploader, requests, docopt 07:35:19 INFO - Running setup.py install for blobuploader 07:35:19 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 07:35:19 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 07:35:19 INFO - Running setup.py install for requests 07:35:19 INFO - Running setup.py install for docopt 07:35:19 INFO - Successfully installed blobuploader requests docopt 07:35:19 INFO - Cleaning up... 07:35:19 INFO - Return code: 0 07:35:19 INFO - Installing None into virtualenv /builds/slave/test/build/venv 07:35:19 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')]} 07:35:19 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:19 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')]} 07:35:19 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:19 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']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:19 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'] in /builds/slave/test/build/tests/config 07:35:19 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 07:35:19 INFO - Using env: {'DISPLAY': ':0', 07:35:19 INFO - 'HOME': '/home/cltbld', 07:35:19 INFO - 'LANG': 'en_US.UTF-8', 07:35:19 INFO - 'LANGUAGE': 'en_US:en', 07:35:19 INFO - 'LOGNAME': 'cltbld', 07:35:19 INFO - 'MAIL': '/var/mail/cltbld', 07:35:19 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:19 INFO - 'MOZ_NO_REMOTE': '1', 07:35:19 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:19 INFO - 'NO_EM_RESTART': '1', 07:35:19 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:19 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:19 INFO - 'PWD': '/builds/slave/test', 07:35:19 INFO - 'SHELL': '/bin/bash', 07:35:19 INFO - 'SHLVL': '1', 07:35:19 INFO - 'TERM': 'linux', 07:35:19 INFO - 'TMOUT': '86400', 07:35:19 INFO - 'USER': 'cltbld', 07:35:19 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:19 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:19 INFO - '_': '/tools/buildbot/bin/python'} 07:35:20 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 07:35:20 INFO - Running setup.py (path:/tmp/pip-FOY3tH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 07:35:20 INFO - Running setup.py (path:/tmp/pip-M5tHBp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 07:35:20 INFO - Running setup.py (path:/tmp/pip-eW3JzK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 07:35:20 INFO - Running setup.py (path:/tmp/pip-epZs5G-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 07:35:20 INFO - Running setup.py (path:/tmp/pip-cpb2E5-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 07:35:20 INFO - Running setup.py (path:/tmp/pip-wWXzoY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 07:35:20 INFO - Running setup.py (path:/tmp/pip-vxtOGW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 07:35:20 INFO - Running setup.py (path:/tmp/pip-zIpRnM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 07:35:20 INFO - Running setup.py (path:/tmp/pip-NhPcQi-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 07:35:20 INFO - Running setup.py (path:/tmp/pip-Vi4rRd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 07:35:20 INFO - Running setup.py (path:/tmp/pip-TMiGEC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 07:35:20 INFO - Running setup.py (path:/tmp/pip-KYknlo-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 07:35:20 INFO - Running setup.py (path:/tmp/pip-l6muBx-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 07:35:20 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 07:35:20 INFO - Running setup.py (path:/tmp/pip-XXOjgz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 07:35:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 07:35:21 INFO - Running setup.py (path:/tmp/pip-QmftVR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 07:35:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 07:35:21 INFO - Running setup.py (path:/tmp/pip-WKgq6q-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 07:35:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 07:35:21 INFO - Running setup.py (path:/tmp/pip-c_5Mjs-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 07:35:21 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 07:35:21 INFO - Running setup.py install for manifestparser 07:35:21 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 07:35:21 INFO - Running setup.py install for mozcrash 07:35:21 INFO - Running setup.py install for mozdebug 07:35:21 INFO - Running setup.py install for mozdevice 07:35:21 INFO - Installing dm script to /builds/slave/test/build/venv/bin 07:35:21 INFO - Running setup.py install for mozfile 07:35:21 INFO - Running setup.py install for mozhttpd 07:35:21 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 07:35:21 INFO - Running setup.py install for mozinfo 07:35:21 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 07:35:21 INFO - Running setup.py install for mozInstall 07:35:22 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Running setup.py install for mozleak 07:35:22 INFO - Running setup.py install for mozlog 07:35:22 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Running setup.py install for moznetwork 07:35:22 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Running setup.py install for mozprocess 07:35:22 INFO - Running setup.py install for mozprofile 07:35:22 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Running setup.py install for mozrunner 07:35:22 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Running setup.py install for mozscreenshot 07:35:22 INFO - Running setup.py install for moztest 07:35:22 INFO - Running setup.py install for mozversion 07:35:22 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 07:35:22 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 07:35:22 INFO - Cleaning up... 07:35:23 INFO - Return code: 0 07:35:23 INFO - Installing None into virtualenv /builds/slave/test/build/venv 07:35: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')]} 07:35:23 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35: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')]} 07:35:23 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:23 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']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:23 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'] in /builds/slave/test/build/tests/config 07:35:23 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 07:35:23 INFO - Using env: {'DISPLAY': ':0', 07:35:23 INFO - 'HOME': '/home/cltbld', 07:35:23 INFO - 'LANG': 'en_US.UTF-8', 07:35:23 INFO - 'LANGUAGE': 'en_US:en', 07:35:23 INFO - 'LOGNAME': 'cltbld', 07:35:23 INFO - 'MAIL': '/var/mail/cltbld', 07:35:23 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:23 INFO - 'MOZ_NO_REMOTE': '1', 07:35:23 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:23 INFO - 'NO_EM_RESTART': '1', 07:35:23 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:23 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:23 INFO - 'PWD': '/builds/slave/test', 07:35:23 INFO - 'SHELL': '/bin/bash', 07:35:23 INFO - 'SHLVL': '1', 07:35:23 INFO - 'TERM': 'linux', 07:35:23 INFO - 'TMOUT': '86400', 07:35:23 INFO - 'USER': 'cltbld', 07:35:23 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:23 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:23 INFO - '_': '/tools/buildbot/bin/python'} 07:35:23 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 07:35:23 INFO - Running setup.py (path:/tmp/pip-mRgBrn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 07:35:23 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 07:35:23 INFO - Running setup.py (path:/tmp/pip-TOylkd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 07:35:23 INFO - Running setup.py (path:/tmp/pip-q2FMHv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 07:35:23 INFO - Running setup.py (path:/tmp/pip-dUXS6w-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 07:35:23 INFO - Running setup.py (path:/tmp/pip-kVkMyW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 07:35:23 INFO - Running setup.py (path:/tmp/pip-mAzQTn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 07:35:23 INFO - Running setup.py (path:/tmp/pip-L8yTqa-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 07:35:23 INFO - Running setup.py (path:/tmp/pip-eh4GYc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 07:35:23 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.13 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 07:35:23 INFO - Running setup.py (path:/tmp/pip-kmoW6h-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 07:35:23 INFO - Running setup.py (path:/tmp/pip-60Whre-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 07:35:23 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)) 07:35:23 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 07:35:23 INFO - Running setup.py (path:/tmp/pip-mi0HRR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 07:35:24 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)) 07:35:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 07:35:24 INFO - Running setup.py (path:/tmp/pip-qgBQfH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 07:35:24 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)) 07:35:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 07:35:24 INFO - Running setup.py (path:/tmp/pip-Zvj6h3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 07:35:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.28 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 07:35:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 07:35:24 INFO - Running setup.py (path:/tmp/pip-bgk8w5-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 07:35:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.13 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 07:35:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 07:35:24 INFO - Running setup.py (path:/tmp/pip-nufLfX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 07:35:24 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)) 07:35:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 07:35:24 INFO - Running setup.py (path:/tmp/pip-kDB_D1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 07:35:24 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)) 07:35:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 07:35:24 INFO - Running setup.py (path:/tmp/pip-6xKcv5-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 07:35:24 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)) 07:35:24 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)) 07:35:24 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)) 07:35:24 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)) 07:35:24 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)) 07:35:24 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)) 07:35:24 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.13->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 07:35:24 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 07:35:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:24 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:24 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:25 INFO - Downloading blessings-1.6.tar.gz 07:35:25 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 07:35:25 INFO - Installing collected packages: blessings 07:35:25 INFO - Running setup.py install for blessings 07:35:25 INFO - Successfully installed blessings 07:35:25 INFO - Cleaning up... 07:35:25 INFO - Return code: 0 07:35:25 INFO - Done creating virtualenv /builds/slave/test/build/venv. 07:35:25 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 07:35:25 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 07:35:26 INFO - Reading from file tmpfile_stdout 07:35:26 INFO - Current package versions: 07:35:26 INFO - argparse == 1.2.1 07:35:26 INFO - blessings == 1.6 07:35:26 INFO - blobuploader == 1.2.4 07:35:26 INFO - docopt == 0.6.1 07:35:26 INFO - functools32 == 3.2.3-2 07:35:26 INFO - jsonschema == 2.5.1 07:35:26 INFO - manifestparser == 1.1 07:35:26 INFO - mozInstall == 1.13 07:35:26 INFO - mozcrash == 1.0 07:35:26 INFO - mozdebug == 0.1 07:35:26 INFO - mozdevice == 0.51 07:35:26 INFO - mozfile == 1.2 07:35:26 INFO - mozhttpd == 0.7 07:35:26 INFO - mozinfo == 0.10 07:35:26 INFO - mozleak == 0.1 07:35:26 INFO - mozlog == 3.5 07:35:26 INFO - moznetwork == 0.27 07:35:26 INFO - mozprocess == 0.25 07:35:26 INFO - mozprofile == 0.28 07:35:26 INFO - mozrunner == 6.13 07:35:26 INFO - mozscreenshot == 0.1 07:35:26 INFO - mozsystemmonitor == 0.3 07:35:26 INFO - moztest == 0.8 07:35:26 INFO - mozversion == 1.4 07:35:26 INFO - psutil == 3.1.1 07:35:26 INFO - requests == 1.2.3 07:35:26 INFO - wsgiref == 0.1.2 07:35:26 INFO - Installing None into virtualenv /builds/slave/test/build/venv 07:35:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:26 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:26 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:26 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']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:26 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'] in /builds/slave/test/build/tests/talos 07:35:26 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 07:35:26 INFO - Using env: {'DISPLAY': ':0', 07:35:26 INFO - 'HOME': '/home/cltbld', 07:35:26 INFO - 'LANG': 'en_US.UTF-8', 07:35:26 INFO - 'LANGUAGE': 'en_US:en', 07:35:26 INFO - 'LOGNAME': 'cltbld', 07:35:26 INFO - 'MAIL': '/var/mail/cltbld', 07:35:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:26 INFO - 'MOZ_NO_REMOTE': '1', 07:35:26 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:26 INFO - 'NO_EM_RESTART': '1', 07:35:26 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:26 INFO - 'PWD': '/builds/slave/test', 07:35:26 INFO - 'SHELL': '/bin/bash', 07:35:26 INFO - 'SHLVL': '1', 07:35:26 INFO - 'TERM': 'linux', 07:35:26 INFO - 'TMOUT': '86400', 07:35:26 INFO - 'USER': 'cltbld', 07:35:26 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:26 INFO - '_': '/tools/buildbot/bin/python'} 07:35:26 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:26 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)) 07:35:26 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)) 07:35:26 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)) 07:35:26 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)) 07:35:26 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)) 07:35:26 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)) 07:35:26 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)) 07:35:26 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)) 07:35:26 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)) 07:35:26 INFO - Downloading/unpacking simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 07:35:26 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:26 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:26 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:26 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:27 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/simplejson/setup.py) egg_info for package simplejson 07:35:27 INFO - Downloading/unpacking requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 07:35:27 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:27 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:27 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:35:27 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:35:27 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 07:35:27 INFO - warning: no files found matching 'test_requests.py' 07:35:27 INFO - warning: no files found matching 'requirements.txt' 07:35:27 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)) 07:35:27 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)) 07:35:27 INFO - Installing collected packages: simplejson, requests 07:35:27 INFO - Running setup.py install for simplejson 07:35:27 INFO - building 'simplejson._speedups' extension 07:35:27 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c simplejson/_speedups.c -o build/temp.linux-x86_64-2.7/simplejson/_speedups.o 07:35:28 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/simplejson/_speedups.o -o build/lib.linux-x86_64-2.7/simplejson/_speedups.so 07:35:28 INFO - Found existing installation: requests 1.2.3 07:35:28 INFO - Uninstalling requests: 07:35:28 INFO - Successfully uninstalled requests 07:35:28 INFO - Running setup.py install for requests 07:35:28 INFO - warning: no files found matching 'test_requests.py' 07:35:28 INFO - warning: no files found matching 'requirements.txt' 07:35:29 INFO - Successfully installed simplejson requests 07:35:29 INFO - Cleaning up... 07:35:29 INFO - Return code: 0 07:35:29 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 07:35:29 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:29 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:35:29 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:35:29 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:35:29 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x10471f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x120fb70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x13b49c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, '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': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', '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 07:35:29 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema'] in /builds/slave/test/build 07:35:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema 07:35:29 INFO - Using env: {'DISPLAY': ':0', 07:35:29 INFO - 'HOME': '/home/cltbld', 07:35:29 INFO - 'LANG': 'en_US.UTF-8', 07:35:29 INFO - 'LANGUAGE': 'en_US:en', 07:35:29 INFO - 'LOGNAME': 'cltbld', 07:35:29 INFO - 'MAIL': '/var/mail/cltbld', 07:35:29 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:29 INFO - 'MOZ_NO_REMOTE': '1', 07:35:29 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:29 INFO - 'NO_EM_RESTART': '1', 07:35:29 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:29 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:29 INFO - 'PWD': '/builds/slave/test', 07:35:29 INFO - 'SHELL': '/bin/bash', 07:35:29 INFO - 'SHLVL': '1', 07:35:29 INFO - 'TERM': 'linux', 07:35:29 INFO - 'TMOUT': '86400', 07:35:29 INFO - 'USER': 'cltbld', 07:35:29 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:29 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:29 INFO - '_': '/tools/buildbot/bin/python'} 07:35:29 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:35:29 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 07:35:29 INFO - Cleaning up... 07:35:29 INFO - Return code: 0 07:35:29 INFO - Running post-action listener: _resource_record_post_action 07:35:29 INFO - Running post-action listener: _start_resource_monitoring 07:35:29 INFO - Starting resource monitoring. 07:35:29 INFO - [mozharness: 2017-10-08 14:35:29.579494Z] Finished create-virtualenv step (success) 07:35:29 INFO - [mozharness: 2017-10-08 14:35:29.580511Z] Running install step. 07:35:29 INFO - Running pre-action listener: _resource_record_pre_action 07:35:29 INFO - Running main action method: install 07:35:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 07:35:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 07:35:29 INFO - Reading from file tmpfile_stdout 07:35:29 INFO - Detecting whether we're running mozinstall >=1.0... 07:35:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 07:35:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 07:35:29 INFO - Reading from file tmpfile_stdout 07:35:29 INFO - Output received: 07:35:29 INFO - Usage: mozinstall [options] installer 07:35:29 INFO - Options: 07:35:29 INFO - -h, --help show this help message and exit 07:35:29 INFO - -d DEST, --destination=DEST 07:35:29 INFO - Directory to install application into. [default: 07:35:29 INFO - "/builds/slave/test"] 07:35:29 INFO - --app=APP Application being installed. [default: firefox] 07:35:29 INFO - mkdir: /builds/slave/test/build/application 07:35:29 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'] 07:35:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 07:35:47 INFO - Reading from file tmpfile_stdout 07:35:47 INFO - Output received: 07:35:47 INFO - /builds/slave/test/build/application/firefox/firefox 07:35:47 INFO - Running post-action listener: _resource_record_post_action 07:35:47 INFO - [mozharness: 2017-10-08 14:35:47.620432Z] Finished install step (success) 07:35:47 INFO - [mozharness: 2017-10-08 14:35:47.620683Z] Running setup-mitmproxy step. 07:35:47 INFO - Running pre-action listener: _resource_record_pre_action 07:35:47 INFO - Running main action method: setup_mitmproxy 07:35:47 INFO - Skipping: mitmproxy is not required 07:35:47 INFO - Running post-action listener: _resource_record_post_action 07:35:47 INFO - [mozharness: 2017-10-08 14:35:47.621943Z] Finished setup-mitmproxy step (success) 07:35:47 INFO - [mozharness: 2017-10-08 14:35:47.622163Z] Running run-tests step. 07:35:47 INFO - Running pre-action listener: _resource_record_pre_action 07:35:47 INFO - Running pre-action listener: _set_gcov_prefix 07:35:47 INFO - Running main action method: run_tests 07:35:47 WARNING - Try message not found. 07:35:47 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 07:35:47 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 07:35:47 INFO - Python 2.7.3 07:35:47 INFO - Return code: 0 07:35:47 INFO - grabbing minidump binary from tooltool 07:35:47 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')]} 07:35:47 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 0x13b1d60>, '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 0x13b2a60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x13b2ef0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 07:35:47 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 07:35:47 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 07:35:47 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 07:35:47 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 07:35:47 INFO - Return code: 0 07:35:47 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 07:35:47 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 07:35:47 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 07:35:47 INFO - ENV: RUST_BACKTRACE is now full 07:35:47 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 07:35:47 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 07:35:47 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-035', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] in /builds/slave/test/build 07:35:47 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite g4-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-035 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log 07:35:47 INFO - Using env: {'DISPLAY': ':0', 07:35:47 INFO - 'HOME': '/home/cltbld', 07:35:47 INFO - 'LANG': 'en_US.UTF-8', 07:35:47 INFO - 'LANGUAGE': 'en_US:en', 07:35:47 INFO - 'LOGNAME': 'cltbld', 07:35:47 INFO - 'MAIL': '/var/mail/cltbld', 07:35:47 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 07:35:47 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 07:35:47 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:47 INFO - 'MOZ_NO_REMOTE': '1', 07:35:47 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 07:35:47 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:47 INFO - 'NO_EM_RESTART': '1', 07:35:47 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:47 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:47 INFO - 'PWD': '/builds/slave/test', 07:35:47 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 07:35:47 INFO - 'RUST_BACKTRACE': 'full', 07:35:47 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 07:35:47 INFO - 'SHELL': '/bin/bash', 07:35:47 INFO - 'SHLVL': '1', 07:35:47 INFO - 'TERM': 'linux', 07:35:47 INFO - 'TMOUT': '86400', 07:35:47 INFO - 'USER': 'cltbld', 07:35:47 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:47 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:47 INFO - '_': '/tools/buildbot/bin/python'} 07:35:47 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-035', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] with output_timeout 3600 07:35:48 INFO - mozversion application_buildid: 20171008094304 07:35:48 INFO - mozversion application_changeset: 5e030a486ad8535969c4f6c1955c253a12ee8c51 07:35:48 INFO - mozversion application_display_name: Nightly 07:35:48 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 07:35:48 INFO - mozversion application_name: Firefox 07:35:48 INFO - mozversion application_remotingname: firefox 07:35:48 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 07:35:48 INFO - mozversion application_vendor: Mozilla 07:35:48 INFO - mozversion application_version: 58.0a1 07:35:48 INFO - mozversion platform_buildid: 20171008094304 07:35:48 INFO - mozversion platform_changeset: 5e030a486ad8535969c4f6c1955c253a12ee8c51 07:35:48 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 07:35:48 INFO - mozversion platform_version: 58.0a1 07:35:48 INFO - using testdate: 1507473348 07:35:48 INFO - actual date: 1507473348 07:35:48 INFO - starting webserver on 'localhost:56002' 07:35:48 INFO - SUITE-START | Running 2 tests 07:35:48 INFO - TEST-START | basic_compositor_video 07:35:48 INFO - Initialising browser for basic_compositor_video test... 07:35:48 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:56002/getInfo.html -profile /tmp/tmpW3kUbm/profile 07:35:48 INFO - TEST-INFO | started process 3791 (/builds/slave/test/build/application/firefox/firefox http://localhost:56002/getInfo.html) 07:35:55 INFO - TEST-INFO | 3791: exit 0 07:35:55 INFO - Browser initialized. 07:35:55 INFO - Running cycle 1/1 for basic_compositor_video test... 07:35:55 INFO - Using env: {'DISPLAY': ':0', 07:35:55 INFO - 'HOME': '/home/cltbld', 07:35:55 INFO - 'JSGC_DISABLE_POISONING': '1', 07:35:55 INFO - 'LANG': 'en_US.UTF-8', 07:35:55 INFO - 'LANGUAGE': 'en_US:en', 07:35:55 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 07:35:55 INFO - 'LOGNAME': 'cltbld', 07:35:55 INFO - 'MAIL': '/var/mail/cltbld', 07:35:55 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 07:35:55 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 07:35:55 INFO - 'MOZ_CRASHREPORTER': '1', 07:35:55 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:35:55 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 07:35:55 INFO - 'MOZ_NO_REMOTE': '1', 07:35:55 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 07:35:55 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:35:55 INFO - 'NO_EM_RESTART': '1', 07:35:55 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:35:55 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:35:55 INFO - 'PWD': '/builds/slave/test', 07:35:55 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 07:35:55 INFO - 'RUST_BACKTRACE': 'full', 07:35:55 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 07:35:55 INFO - 'SHELL': '/bin/bash', 07:35:55 INFO - 'SHLVL': '1', 07:35:55 INFO - 'TERM': 'linux', 07:35:55 INFO - 'TMOUT': '86400', 07:35:55 INFO - 'USER': 'cltbld', 07:35:55 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:35:55 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:35:55 INFO - '_': '/tools/buildbot/bin/python'} 07:35:55 INFO - TEST-INFO | started process 4065 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpW3kUbm/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 07:35:56 INFO - PID 4065 | 07:35:56 INFO - PID 4065 | (/builds/slave/test/build/application/firefox/firefox:4114): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 07:35:56 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6820375560538117 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.667083333333333 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7465221187427244 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7115098374679205 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9478486842105283 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.059148073022312 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.4375257731958753 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3736593591905595 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.672627599243856 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.573969359331477 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.035267558528435 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 9.391455399061021 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.114185185185192 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.58232804232803 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.554748953974892 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.766764705882345 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.540980769230766 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.931284153005441 ms/frame 07:36:42 INFO - PID 4065 | 07:36:42 INFO - PID 4065 | Cycle 1(1): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:37:28 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6874381327334085 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6677416666666667 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7653352941176468 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7304974048442905 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.048765182186235 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.024859154929577 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.484523809523811 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3850930626057534 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.629671669793624 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.572771587743732 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.001850000000001 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 10.102323232323224 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.197798507462666 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.700294117647069 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.450829875518679 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.049186746987957 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.36729166666668 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.754623655913942 ms/frame 07:37:28 INFO - PID 4065 | 07:37:28 INFO - PID 4065 | Cycle 1(2): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:38:14 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.680170772676372 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6657285595337215 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7693189858490568 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7659399823477497 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.066199186991872 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.168052083333332 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.4292057142857146 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3502596314907866 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.738250478011471 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.6190168539325915 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.136435810810818 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 10.156142131979687 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.032444852941167 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.583783068783102 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.503375000000021 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.196310975609755 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.630581395348846 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.30262711864404 ms/frame 07:38:14 INFO - PID 4065 | 07:38:14 INFO - PID 4065 | Cycle 1(3): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:39:01 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.68121568627451 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6671916666666668 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7452879581151837 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7027999999999999 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.115651577503429 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.159334719334722 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.5759773539928474 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.515123022847106 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.650517890772127 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5564027777777785 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.348603448275853 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 9.665797101449291 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.113166666666668 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.643936170212754 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.349567901234566 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.76902941176471 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.674474708171193 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.23983146067417 ms/frame 07:39:01 INFO - PID 4065 | 07:39:01 INFO - PID 4065 | Cycle 1(4): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:39:47 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6793816452154449 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6675624999999998 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7979298981426004 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7123330479452055 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.179171309192201 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.184257322175734 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.414146757679181 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3737858347386154 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.68386363636364 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.618764044943817 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.0025 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 10.003549999999995 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.194141791044771 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.47657068062828 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.396570247933889 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.696842105263178 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.811889763779533 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.17673184357543 ms/frame 07:39:47 INFO - PID 4065 | 07:39:47 INFO - PID 4065 | Cycle 1(5): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:40:33 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6801147816349387 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6626184538653368 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7282171658986178 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.701071428571428 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9484605263157895 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.042313131313131 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.5974460431654682 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.502819614711034 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.66104716981132 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.292552910052907 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.678113879003556 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 10.365880829015534 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.989853479853478 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.475183246073309 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.452323651452291 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.127212121212109 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.676828793774318 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.930683060109303 ms/frame 07:40:33 INFO - PID 4065 | 07:40:33 INFO - PID 4065 | Cycle 1(6): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:41:19 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6782046979865772 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6662447960033304 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7830421865715986 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7638315696649034 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.195818181818182 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.090664621676893 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.5050584112149554 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.384898477157358 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.65161958568738 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5430886426592805 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.38153979238754 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 9.855098522167482 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.032702205882355 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.64231382978722 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.71404661016949 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.196920731707307 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.585366795366797 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.994670329670324 ms/frame 07:41:19 INFO - PID 4065 | 07:41:19 INFO - PID 4065 | Cycle 1(7): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:42:05 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6793844432008953 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6701085141903176 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7872453841572364 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7725907883082375 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.155671745152353 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.167520833333337 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.441502293577979 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.385947546531305 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.547107208872459 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.511294765840226 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.10425925925926 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 10.257205128205122 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.030091911764698 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585079365079375 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.502250000000004 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.702339181286542 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.585444015444033 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.054723756906071 ms/frame 07:42:05 INFO - PID 4065 | 07:42:05 INFO - PID 4065 | Cycle 1(8): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:42:51 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6784451901565998 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.665333055786844 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7608802816901408 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7703053097345138 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.054628378378379 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.140973084886129 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.4212314709236034 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.339657762938227 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.715238095238095 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.603711484593842 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.206258503401358 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 10.104570707070716 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.199067164179112 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.642579787234045 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.298176229508186 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.049156626506 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.451545801526718 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.871304347826085 ms/frame 07:42:51 INFO - PID 4065 | 07:42:51 INFO - PID 4065 | Cycle 1(9): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:43:37 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6800559910414337 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6687364470391994 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7144485714285713 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6986247877758909 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.048771929824561 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.025985915492956 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.425136986301372 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.362126050420162 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.682566287878789 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.437622282608701 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.56595070422535 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 10.10479797979798 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.994688644688654 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.472303664921462 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.501500000000002 ms/frame 07:43:37 INFO - PID 4065 | 07:43:37 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.054518072289174 ms/frame 07:43:37 INFO - PID 4065 | 07:43:38 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.54288461538462 ms/frame 07:43:38 INFO - PID 4065 | 07:43:38 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.11308333333331 ms/frame 07:43:38 INFO - PID 4065 | 07:43:38 INFO - PID 4065 | Cycle 1(10): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:44:24 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.681889013452915 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6702295492487478 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7135208452312964 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.697018659881255 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.071329715061058 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.098504098360658 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.526304347826087 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3854568527918785 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.661943396226419 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.436834239130428 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.137500000000003 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 9.615480769230771 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.076180811808133 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.697219251336884 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.501437500000005 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.054548192771087 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.410627376425838 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.753118279569902 ms/frame 07:44:24 INFO - PID 4065 | 07:44:24 INFO - PID 4065 | Cycle 1(11): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:45:10 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_startup = 1.677897091722595 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6713533834586467 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7647235294117645 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.705507246376812 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_startup = 4.055499999999999 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.969196428571429 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_startup = 3.546211583924351 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4264212328767103 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.535405904059038 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.572604456824519 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_startup = 10.41880208333334 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.480p.60fps.webm_scale_2_inclip = 9.664685990338148 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.070719557195575 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.204974489795896 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.503250000000026 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.698859649122792 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.62800387596897 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.238988764044949 ms/frame 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | Cycle 1(12): loaded http://localhost:56002/tests/video/video_playback.html (next: http://localhost:56002/tests/video/video_playback.html) 07:45:10 INFO - PID 4065 | __start_tp_report 07:45:10 INFO - PID 4065 | _x_x_mozilla_page_load 07:45:10 INFO - PID 4065 | _x_x_mozilla_page_load_details 07:45:10 INFO - PID 4065 | |i|pagename|runs| 07:45:10 INFO - PID 4065 | |0;240p.120fps.mp4_scale_1_startup;1.6820375560538117;1.6874381327334085;1.680170772676372;1.68121568627451;1.6793816452154449;1.6801147816349387;1.6782046979865772;1.6793844432008953;1.6784451901565998;1.6800559910414337;1.681889013452915;1.677897091722595 07:45:10 INFO - PID 4065 | |1;240p.120fps.mp4_scale_1_inclip;1.667083333333333;1.6677416666666667;1.6657285595337215;1.6671916666666668;1.6675624999999998;1.6626184538653368;1.6662447960033304;1.6701085141903176;1.665333055786844;1.6687364470391994;1.6702295492487478;1.6713533834586467 07:45:10 INFO - PID 4065 | |2;240p.120fps.mp4_scale_1.1_startup;1.7465221187427244;1.7653352941176468;1.7693189858490568;1.7452879581151837;1.7979298981426004;1.7282171658986178;1.7830421865715986;1.7872453841572364;1.7608802816901408;1.7144485714285713;1.7135208452312964;1.7647235294117645 07:45:10 INFO - PID 4065 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7115098374679205;1.7304974048442905;1.7659399823477497;1.7027999999999999;1.7123330479452055;1.701071428571428;1.7638315696649034;1.7725907883082375;1.7703053097345138;1.6986247877758909;1.697018659881255;1.705507246376812 07:45:10 INFO - PID 4065 | |4;240p.120fps.mp4_scale_2_startup;3.9478486842105283;4.048765182186235;4.066199186991872;4.115651577503429;4.179171309192201;3.9484605263157895;4.195818181818182;4.155671745152353;4.054628378378379;4.048771929824561;4.071329715061058;4.055499999999999 07:45:10 INFO - PID 4065 | |5;240p.120fps.mp4_scale_2_inclip;4.059148073022312;4.024859154929577;4.168052083333332;4.159334719334722;4.184257322175734;4.042313131313131;4.090664621676893;4.167520833333337;4.140973084886129;4.025985915492956;4.098504098360658;3.969196428571429 07:45:10 INFO - PID 4065 | |6;480p.60fps.webm_scale_1_startup;3.4375257731958753;3.484523809523811;3.4292057142857146;3.5759773539928474;3.414146757679181;3.5974460431654682;3.5050584112149554;3.441502293577979;3.4212314709236034;3.425136986301372;3.526304347826087;3.546211583924351 07:45:10 INFO - PID 4065 | |7;480p.60fps.webm_scale_1_inclip;3.3736593591905595;3.3850930626057534;3.3502596314907866;3.515123022847106;3.3737858347386154;3.502819614711034;3.384898477157358;3.385947546531305;3.339657762938227;3.362126050420162;3.3854568527918785;3.4264212328767103 07:45:10 INFO - PID 4065 | |8;480p.60fps.webm_scale_1.1_startup;5.672627599243856;5.629671669793624;5.738250478011471;5.650517890772127;5.68386363636364;5.66104716981132;5.65161958568738;5.547107208872459;5.715238095238095;5.682566287878789;5.661943396226419;5.535405904059038 07:45:10 INFO - PID 4065 | |9;480p.60fps.webm_scale_1.1_inclip;5.573969359331477;5.572771587743732;5.6190168539325915;5.5564027777777785;5.618764044943817;5.292552910052907;5.5430886426592805;5.511294765840226;5.603711484593842;5.437622282608701;5.436834239130428;5.572604456824519 07:45:10 INFO - PID 4065 | |10;480p.60fps.webm_scale_2_startup;10.035267558528435;10.001850000000001;10.136435810810818;10.348603448275853;10.0025;10.678113879003556;10.38153979238754;10.10425925925926;10.206258503401358;10.56595070422535;10.137500000000003;10.41880208333334 07:45:10 INFO - PID 4065 | |11;480p.60fps.webm_scale_2_inclip;9.391455399061021;10.102323232323224;10.156142131979687;9.665797101449291;10.003549999999995;10.365880829015534;9.855098522167482;10.257205128205122;10.104570707070716;10.10479797979798;9.615480769230771;9.664685990338148 07:45:10 INFO - PID 4065 | |12;1080p.60fps.mp4_scale_1_startup;11.114185185185192;11.197798507462666;11.032444852941167;11.113166666666668;11.194141791044771;10.989853479853478;11.032702205882355;11.030091911764698;11.199067164179112;10.994688644688654;11.076180811808133;11.070719557195575 07:45:10 INFO - PID 4065 | |13;1080p.60fps.mp4_scale_1_inclip;10.58232804232803;10.700294117647069;10.583783068783102;10.643936170212754;10.47657068062828;10.475183246073309;10.64231382978722;10.585079365079375;10.642579787234045;10.472303664921462;10.697219251336884;10.204974489795896 07:45:10 INFO - PID 4065 | |14;1080p.60fps.mp4_scale_1.1_startup;12.554748953974892;12.450829875518679;12.503375000000021;12.349567901234566;12.396570247933889;12.452323651452291;12.71404661016949;12.502250000000004;12.298176229508186;12.501500000000002;12.501437500000005;12.503250000000026 07:45:10 INFO - PID 4065 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.766764705882345;12.049186746987957;12.196310975609755;11.76902941176471;11.696842105263178;12.127212121212109;12.196920731707307;11.702339181286542;12.049156626506;12.054518072289174;12.054548192771087;11.698859649122792 07:45:10 INFO - PID 4065 | |16;1080p.60fps.mp4_scale_2_startup;11.540980769230766;11.36729166666668;11.630581395348846;11.674474708171193;11.811889763779533;11.676828793774318;11.585366795366797;11.585444015444033;11.451545801526718;11.54288461538462;11.410627376425838;11.62800387596897 07:45:10 INFO - PID 4065 | |17;1080p.60fps.mp4_scale_2_inclip;10.931284153005441;10.754623655913942;11.30262711864404;11.23983146067417;11.17673184357543;10.930683060109303;10.994670329670324;11.054723756906071;10.871304347826085;11.11308333333331;10.753118279569902;11.238988764044949 07:45:10 INFO - PID 4065 | __end_tp_report 07:45:10 INFO - PID 4065 | __start_cc_report 07:45:10 INFO - PID 4065 | _x_x_mozilla_cycle_collect,553 07:45:10 INFO - PID 4065 | __end_cc_report 07:45:10 INFO - PID 4065 | __startTimestamp1507473910666__endTimestamp 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | ------- Summary: start ------- 07:45:10 INFO - PID 4065 | Number of tests: 18 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.00 (0.2%) stddev-sans-first:0.00 07:45:10 INFO - PID 4065 | 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 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#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 07:45:10 INFO - PID 4065 | 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 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.76 Median:1.77 stddev:0.03 (1.6%) stddev-sans-first:0.03 07:45:10 INFO - PID 4065 | Values: 1.7 1.8 1.8 1.7 1.8 1.7 1.8 1.8 1.8 1.7 1.7 1.8 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.73 Median:1.72 stddev:0.03 (1.8%) stddev-sans-first:0.03 07:45:10 INFO - PID 4065 | Values: 1.7 1.7 1.8 1.7 1.7 1.7 1.8 1.8 1.8 1.7 1.7 1.7 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.07 Median:4.07 stddev:0.08 (1.9%) stddev-sans-first:0.07 07:45:10 INFO - PID 4065 | Values: 3.9 4.0 4.1 4.1 4.2 3.9 4.2 4.2 4.1 4.0 4.1 4.1 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.09 Median:4.12 stddev:0.07 (1.7%) stddev-sans-first:0.07 07:45:10 INFO - PID 4065 | Values: 4.1 4.0 4.2 4.2 4.2 4.0 4.1 4.2 4.1 4.0 4.1 4.0 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.48 Median:3.49 stddev:0.07 (1.9%) stddev-sans-first:0.07 07:45:10 INFO - PID 4065 | Values: 3.4 3.5 3.4 3.6 3.4 3.6 3.5 3.4 3.4 3.4 3.5 3.5 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.40 Median:3.39 stddev:0.06 (1.6%) stddev-sans-first:0.06 07:45:10 INFO - PID 4065 | Values: 3.4 3.4 3.4 3.5 3.4 3.5 3.4 3.4 3.3 3.4 3.4 3.4 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.65 Median:5.67 stddev:0.06 (1.1%) stddev-sans-first:0.06 07:45:10 INFO - PID 4065 | Values: 5.7 5.6 5.7 5.7 5.7 5.7 5.7 5.5 5.7 5.7 5.7 5.5 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.53 Median:5.57 stddev:0.10 (1.7%) stddev-sans-first:0.10 07:45:10 INFO - PID 4065 | Values: 5.6 5.6 5.6 5.6 5.6 5.3 5.5 5.5 5.6 5.4 5.4 5.6 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.25 Median:10.28 stddev:0.22 (2.2%) stddev-sans-first:0.22 07:45:10 INFO - PID 4065 | Values: 10.0 10.0 10.1 10.3 10.0 10.7 10.4 10.1 10.2 10.6 10.1 10.4 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.94 Median:9.88 stddev:0.30 (3.0%) stddev-sans-first:0.25 07:45:10 INFO - PID 4065 | Values: 9.4 10.1 10.2 9.7 10.0 10.4 9.9 10.3 10.1 10.1 9.6 9.7 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.09 Median:11.09 stddev:0.08 (0.7%) stddev-sans-first:0.08 07:45:10 INFO - PID 4065 | Values: 11.1 11.2 11.0 11.1 11.2 11.0 11.0 11.0 11.2 11.0 11.1 11.1 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.56 Median:10.61 stddev:0.14 (1.3%) stddev-sans-first:0.14 07:45:10 INFO - PID 4065 | Values: 10.6 10.7 10.6 10.6 10.5 10.5 10.6 10.6 10.6 10.5 10.7 10.2 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.48 Median:12.50 stddev:0.11 (0.8%) stddev-sans-first:0.11 07:45:10 INFO - PID 4065 | Values: 12.6 12.5 12.5 12.3 12.4 12.5 12.7 12.5 12.3 12.5 12.5 12.5 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.95 Median:12.05 stddev:0.20 (1.7%) stddev-sans-first:0.20 07:45:10 INFO - PID 4065 | Values: 11.8 12.0 12.2 11.8 11.7 12.1 12.2 11.7 12.0 12.1 12.1 11.7 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.58 Median:11.61 stddev:0.12 (1.1%) stddev-sans-first:0.13 07:45:10 INFO - PID 4065 | Values: 11.5 11.4 11.6 11.7 11.8 11.7 11.6 11.6 11.5 11.5 11.4 11.6 07:45:10 INFO - PID 4065 | 07:45:10 INFO - PID 4065 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:11.03 Median:11.08 stddev:0.19 (1.7%) stddev-sans-first:0.19 07:45:10 INFO - PID 4065 | Values: 10.9 10.8 11.3 11.2 11.2 10.9 11.0 11.1 10.9 11.1 10.8 11.2 07:45:10 INFO - PID 4065 | -------- Summary: end -------- 07:45:10 INFO - PID 4065 | 07:45:11 INFO - TEST-INFO | 4065: exit 0 07:45:11 INFO - TEST-OK | basic_compositor_video | took 562784ms 07:45:11 INFO - TEST-START | glvideo 07:45:11 INFO - Initialising browser for glvideo test... 07:45:11 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:56002/getInfo.html -profile /tmp/tmpACBm08/profile 07:45:11 INFO - TEST-INFO | started process 5421 (/builds/slave/test/build/application/firefox/firefox http://localhost:56002/getInfo.html) 07:45:15 INFO - TEST-INFO | 5421: exit 0 07:45:15 INFO - Browser initialized. 07:45:15 INFO - Running cycle 1/1 for glvideo test... 07:45:15 INFO - Using env: {'DISPLAY': ':0', 07:45:15 INFO - 'HOME': '/home/cltbld', 07:45:15 INFO - 'JSGC_DISABLE_POISONING': '1', 07:45:15 INFO - 'LANG': 'en_US.UTF-8', 07:45:15 INFO - 'LANGUAGE': 'en_US:en', 07:45:15 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 07:45:15 INFO - 'LOGNAME': 'cltbld', 07:45:15 INFO - 'MAIL': '/var/mail/cltbld', 07:45:15 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 07:45:15 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 07:45:15 INFO - 'MOZ_CRASHREPORTER': '1', 07:45:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:45:15 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 07:45:15 INFO - 'MOZ_NO_REMOTE': '1', 07:45:15 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 07:45:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:45:15 INFO - 'NO_EM_RESTART': '1', 07:45:15 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:45:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:45:15 INFO - 'PWD': '/builds/slave/test', 07:45:15 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 07:45:15 INFO - 'RUST_BACKTRACE': 'full', 07:45:15 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 07:45:15 INFO - 'SHELL': '/bin/bash', 07:45:15 INFO - 'SHLVL': '1', 07:45:15 INFO - 'TERM': 'linux', 07:45:15 INFO - 'TMOUT': '86400', 07:45:15 INFO - 'USER': 'cltbld', 07:45:15 INFO - 'XDG_SESSION_COOKIE': 'ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184', 07:45:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:45:15 INFO - '_': '/tools/buildbot/bin/python'} 07:45:15 INFO - TEST-INFO | started process 5694 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpACBm08/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 07:45:16 INFO - PID 5694 | 07:45:16 INFO - PID 5694 | (/builds/slave/test/build/application/firefox/firefox:5743): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 07:45:16 INFO - PID 5694 | 07:45:18 INFO - PID 5694 | [talos glvideo result] Mean tick time across 100 ticks: 8.942 ms 07:45:18 INFO - PID 5694 | Cycle 1(1): loaded http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html) 07:45:19 INFO - PID 5694 | [talos glvideo result] Mean tick time across 100 ticks: 6.4864999999999995 ms 07:45:19 INFO - PID 5694 | Cycle 1(2): loaded http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html) 07:45:21 INFO - PID 5694 | [talos glvideo result] Mean tick time across 100 ticks: 6.634399999999999 ms 07:45:21 INFO - PID 5694 | Cycle 1(3): loaded http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html) 07:45:22 INFO - PID 5694 | [talos glvideo result] Mean tick time across 100 ticks: 6.64965 ms 07:45:22 INFO - PID 5694 | Cycle 1(4): loaded http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html) 07:45:23 INFO - PID 5694 | [talos glvideo result] Mean tick time across 100 ticks: 6.637650000000001 ms 07:45:23 INFO - PID 5694 | Cycle 1(5): loaded http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56002/tests/webgl/benchmarks/video/video_upload.html) 07:45:23 INFO - PID 5694 | __start_tp_report 07:45:23 INFO - PID 5694 | _x_x_mozilla_page_load 07:45:23 INFO - PID 5694 | _x_x_mozilla_page_load_details 07:45:23 INFO - PID 5694 | |i|pagename|runs| 07:45:23 INFO - PID 5694 | |0;Mean tick time across 100 ticks: ;8.942;6.4864999999999995;6.634399999999999;6.64965;6.637650000000001 07:45:23 INFO - PID 5694 | __end_tp_report 07:45:23 INFO - PID 5694 | __start_cc_report 07:45:23 INFO - PID 5694 | _x_x_mozilla_cycle_collect,277 07:45:23 INFO - PID 5694 | __end_cc_report 07:45:23 INFO - PID 5694 | __startTimestamp1507473923985__endTimestamp 07:45:23 INFO - PID 5694 | 07:45:23 INFO - PID 5694 | ------- Summary: start ------- 07:45:23 INFO - PID 5694 | Number of tests: 1 07:45:23 INFO - PID 5694 | 07:45:23 INFO - PID 5694 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:7.07 Median:6.64 stddev:1.05 (15.8%) stddev-sans-first:0.08 07:45:23 INFO - PID 5694 | Values: 8.9 6.5 6.6 6.6 6.6 07:45:23 INFO - PID 5694 | -------- Summary: end -------- 07:45:23 INFO - PID 5694 | 07:45:24 INFO - PID 5694 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 07:45:24 INFO - TEST-INFO | 5694: exit 0 07:45:24 INFO - TEST-OK | glvideo | took 13497ms 07:45:24 INFO - SUITE-END | took 576s 07:45:25 INFO - Completed test suite (00:09:36) 07:45:25 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.59239455034884, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6820375560538117, 1.6874381327334085, 1.680170772676372, 1.68121568627451, 1.6793816452154449, 1.6801147816349387, 1.6782046979865772, 1.6793844432008953, 1.6784451901565998, 1.6800559910414337, 1.681889013452915, 1.677897091722595], "value": 1.6800559910414337, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.667083333333333, 1.6677416666666667, 1.6657285595337215, 1.6671916666666668, 1.6675624999999998, 1.6626184538653368, 1.6662447960033304, 1.6701085141903176, 1.665333055786844, 1.6687364470391994, 1.6702295492487478, 1.6713533834586467], "value": 1.6675624999999998, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7465221187427244, 1.7653352941176468, 1.7693189858490568, 1.7452879581151837, 1.7979298981426004, 1.7282171658986178, 1.7830421865715986, 1.7872453841572364, 1.7608802816901408, 1.7144485714285713, 1.7135208452312964, 1.7647235294117645], "value": 1.7647235294117645, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7115098374679205, 1.7304974048442905, 1.7659399823477497, 1.7027999999999999, 1.7123330479452055, 1.701071428571428, 1.7638315696649034, 1.7725907883082375, 1.7703053097345138, 1.6986247877758909, 1.697018659881255, 1.705507246376812], "value": 1.7123330479452055, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.9478486842105283, 4.048765182186235, 4.066199186991872, 4.115651577503429, 4.179171309192201, 3.9484605263157895, 4.195818181818182, 4.155671745152353, 4.054628378378379, 4.048771929824561, 4.071329715061058, 4.055499999999999], "value": 4.066199186991872, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.059148073022312, 4.024859154929577, 4.168052083333332, 4.159334719334722, 4.184257322175734, 4.042313131313131, 4.090664621676893, 4.167520833333337, 4.140973084886129, 4.025985915492956, 4.098504098360658, 3.969196428571429], "value": 4.098504098360658, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.4375257731958753, 3.484523809523811, 3.4292057142857146, 3.5759773539928474, 3.414146757679181, 3.5974460431654682, 3.5050584112149554, 3.441502293577979, 3.4212314709236034, 3.425136986301372, 3.526304347826087, 3.546211583924351], "value": 3.484523809523811, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.3736593591905595, 3.3850930626057534, 3.3502596314907866, 3.515123022847106, 3.3737858347386154, 3.502819614711034, 3.384898477157358, 3.385947546531305, 3.339657762938227, 3.362126050420162, 3.3854568527918785, 3.4264212328767103], "value": 3.3850930626057534, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.672627599243856, 5.629671669793624, 5.738250478011471, 5.650517890772127, 5.68386363636364, 5.66104716981132, 5.65161958568738, 5.547107208872459, 5.715238095238095, 5.682566287878789, 5.661943396226419, 5.535405904059038], "value": 5.66104716981132, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.573969359331477, 5.572771587743732, 5.6190168539325915, 5.5564027777777785, 5.618764044943817, 5.292552910052907, 5.5430886426592805, 5.511294765840226, 5.603711484593842, 5.437622282608701, 5.436834239130428, 5.572604456824519], "value": 5.5564027777777785, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.035267558528435, 10.001850000000001, 10.136435810810818, 10.348603448275853, 10.0025, 10.678113879003556, 10.38153979238754, 10.10425925925926, 10.206258503401358, 10.56595070422535, 10.137500000000003, 10.41880208333334], "value": 10.206258503401358, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.391455399061021, 10.102323232323224, 10.156142131979687, 9.665797101449291, 10.003549999999995, 10.365880829015534, 9.855098522167482, 10.257205128205122, 10.104570707070716, 10.10479797979798, 9.615480769230771, 9.664685990338148], "value": 10.102323232323224, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.114185185185192, 11.197798507462666, 11.032444852941167, 11.113166666666668, 11.194141791044771, 10.989853479853478, 11.032702205882355, 11.030091911764698, 11.199067164179112, 10.994688644688654, 11.076180811808133, 11.070719557195575], "value": 11.070719557195575, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.58232804232803, 10.700294117647069, 10.583783068783102, 10.643936170212754, 10.47657068062828, 10.475183246073309, 10.64231382978722, 10.585079365079375, 10.642579787234045, 10.472303664921462, 10.697219251336884, 10.204974489795896], "value": 10.585079365079375, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.554748953974892, 12.450829875518679, 12.503375000000021, 12.349567901234566, 12.396570247933889, 12.452323651452291, 12.71404661016949, 12.502250000000004, 12.298176229508186, 12.501500000000002, 12.501437500000005, 12.503250000000026], "value": 12.501437500000005, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.766764705882345, 12.049186746987957, 12.196310975609755, 11.76902941176471, 11.696842105263178, 12.127212121212109, 12.196920731707307, 11.702339181286542, 12.049156626506, 12.054518072289174, 12.054548192771087, 11.698859649122792], "value": 12.049186746987957, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.540980769230766, 11.36729166666668, 11.630581395348846, 11.674474708171193, 11.811889763779533, 11.676828793774318, 11.585366795366797, 11.585444015444033, 11.451545801526718, 11.54288461538462, 11.410627376425838, 11.62800387596897], "value": 11.585444015444033, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.931284153005441, 10.754623655913942, 11.30262711864404, 11.23983146067417, 11.17673184357543, 10.930683060109303, 10.994670329670324, 11.054723756906071, 10.871304347826085, 11.11308333333331, 10.753118279569902, 11.238988764044949], "value": 11.054723756906071, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [8.942, 6.4864999999999995, 6.634399999999999, 6.64965, 6.637650000000001], "value": 6.636025, "unit": "ms"}], "extraOptions": ["e10s"], "name": "glvideo", "alertThreshold": 2.0}]} 07:45:25 INFO - Return code: 0 07:45:25 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 07:45:25 INFO - # TBPL SUCCESS # 07:45:25 INFO - Running post-action listener: _package_coverage_data 07:45:25 INFO - Running post-action listener: _resource_record_post_action 07:45:25 INFO - [mozharness: 2017-10-08 14:45:25.121529Z] Finished run-tests step (success) 07:45:25 INFO - Running post-run listener: _resource_record_post_run 07:45:25 INFO - Total resource usage - Wall time: 595s; CPU: 38.0%; Read bytes: 17408000; Write bytes: 318836736; Read time: 3508; Write time: 299836 07:45:25 INFO - TinderboxPrint: CPU usage
38.5% 07:45:25 INFO - TinderboxPrint: I/O read bytes / time
17,408,000 / 3,508 07:45:25 INFO - TinderboxPrint: I/O write bytes / time
318,836,736 / 299,836 07:45:25 INFO - TinderboxPrint: CPU idle
2,874.7 (61.5%) 07:45:25 INFO - TinderboxPrint: CPU system
301.7 (6.5%) 07:45:25 INFO - TinderboxPrint: CPU user
1,482.4 (31.7%) 07:45:25 INFO - TinderboxPrint: Swap in / out
0 / 0 07:45:25 INFO - install - Wall time: 18s; CPU: 13.0%; Read bytes: 0; Write bytes: 44199936; Read time: 0; Write time: 18108 07:45:25 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 07:45:25 INFO - run-tests - Wall time: 577s; CPU: 39.0%; Read bytes: 15040512; Write bytes: 208576512; Read time: 2520; Write time: 184832 07:45:25 INFO - Running post-run listener: _upload_blobber_files 07:45:25 INFO - Blob upload gear active. 07:45:25 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 07:45:25 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 07:45:25 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'] 07:45:25 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 07:45:25 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:334: SNIMissingWarning: An HTTPS request has been made, but the SNI (Subject Name Indication) extension to TLS is not available on this platform. This may cause the server to present an incorrect TLS certificate, which can cause validation failures. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:25 INFO - SNIMissingWarning 07:45:25 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:25 INFO - InsecurePlatformWarning 07:45:25 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 07:45:25 INFO - SubjectAltNameWarning 07:45:25 INFO - (blobuploader) - INFO - Open directory for files ... 07:45:25 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 07:45:25 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:45:25 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:45:25 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:25 INFO - InsecurePlatformWarning 07:45:26 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 07:45:26 INFO - SubjectAltNameWarning 07:45:26 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:26 INFO - InsecurePlatformWarning 07:45:26 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 07:45:26 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:45:26 INFO - (blobuploader) - INFO - Done attempting. 07:45:26 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 07:45:26 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:45:26 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:45:26 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:26 INFO - InsecurePlatformWarning 07:45:26 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 07:45:26 INFO - SubjectAltNameWarning 07:45:30 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:30 INFO - InsecurePlatformWarning 07:45:31 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 07:45:31 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:45:31 INFO - (blobuploader) - INFO - Done attempting. 07:45:31 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 07:45:31 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:45:31 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:45:31 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:31 INFO - InsecurePlatformWarning 07:45:31 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 07:45:31 INFO - SubjectAltNameWarning 07:45:31 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:31 INFO - InsecurePlatformWarning 07:45:32 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 07:45:32 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:45:32 INFO - (blobuploader) - INFO - Done attempting. 07:45:32 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 07:45:32 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:45:32 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:45:32 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:32 INFO - InsecurePlatformWarning 07:45:32 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 07:45:32 INFO - SubjectAltNameWarning 07:45:32 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 07:45:32 INFO - InsecurePlatformWarning 07:45:33 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 07:45:33 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:45:33 INFO - (blobuploader) - INFO - Done attempting. 07:45:33 INFO - (blobuploader) - INFO - Iteration through files over. 07:45:33 INFO - Return code: 0 07:45:33 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 07:45:33 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 07:45:33 INFO - Setting buildbot property blobber_files to {"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/b983ffc63dec90a13748847d092e25b35fc1c75075d985e679ddcc08d2e109d95ba8ec8cc161353eab79fae9d15db86c02c64296e602d1cdd3dcacdefcf3e878", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/dc0840dc1132668e0ce694a95d65ea23e14ed9ad796babb3f56f49d5d465734553068fbf750ba60b0fe011cd9e76e766b1b0d8d066fc5295af22f574a95c228e", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/55fcfae66423439fa8f8e3af34587a50a1debb34db1751442632af0980799608977ea715269a0c07caf156596c7b56f3ab4d7d08e7ca93757879e55f7b41cc94", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3a6829f53c8e680d45798bc63c7e53adcbf81cdc6b6e6a7caeb37f1b70469c58bd8d2160708d4f4fa20899d5c7f7277c5efe26745fe133af7c2aa060b89053f7"} 07:45:33 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 07:45:33 INFO - Writing to file /builds/slave/test/properties/blobber_files 07:45:33 INFO - Contents: 07:45:33 INFO - blobber_files:{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/b983ffc63dec90a13748847d092e25b35fc1c75075d985e679ddcc08d2e109d95ba8ec8cc161353eab79fae9d15db86c02c64296e602d1cdd3dcacdefcf3e878", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/dc0840dc1132668e0ce694a95d65ea23e14ed9ad796babb3f56f49d5d465734553068fbf750ba60b0fe011cd9e76e766b1b0d8d066fc5295af22f574a95c228e", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/55fcfae66423439fa8f8e3af34587a50a1debb34db1751442632af0980799608977ea715269a0c07caf156596c7b56f3ab4d7d08e7ca93757879e55f7b41cc94", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3a6829f53c8e680d45798bc63c7e53adcbf81cdc6b6e6a7caeb37f1b70469c58bd8d2160708d4f4fa20899d5c7f7277c5efe26745fe133af7c2aa060b89053f7"} 07:45:33 INFO - Running post-run listener: copy_logs_to_upload_dir 07:45:33 INFO - Copying logs to upload dir... 07:45:33 INFO - mkdir: /builds/slave/test/build/upload/logs 07:45:33 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=646.744353 ========= master_lag: 0.07 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 46 secs) (at 2017-10-08 07:45:33.208325) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-08 07:45:33.212638) ========= 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=ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/b983ffc63dec90a13748847d092e25b35fc1c75075d985e679ddcc08d2e109d95ba8ec8cc161353eab79fae9d15db86c02c64296e602d1cdd3dcacdefcf3e878", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/dc0840dc1132668e0ce694a95d65ea23e14ed9ad796babb3f56f49d5d465734553068fbf750ba60b0fe011cd9e76e766b1b0d8d066fc5295af22f574a95c228e", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/55fcfae66423439fa8f8e3af34587a50a1debb34db1751442632af0980799608977ea715269a0c07caf156596c7b56f3ab4d7d08e7ca93757879e55f7b41cc94", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3a6829f53c8e680d45798bc63c7e53adcbf81cdc6b6e6a7caeb37f1b70469c58bd8d2160708d4f4fa20899d5c7f7277c5efe26745fe133af7c2aa060b89053f7"} build_url:https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011167 build_url: 'https://queue.taskcluster.net/v1/task/U4d1o1h6RfSYXdRazbM7jg/artifacts/public/build/target.tar.bz2' blobber_files: '{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/b983ffc63dec90a13748847d092e25b35fc1c75075d985e679ddcc08d2e109d95ba8ec8cc161353eab79fae9d15db86c02c64296e602d1cdd3dcacdefcf3e878", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/dc0840dc1132668e0ce694a95d65ea23e14ed9ad796babb3f56f49d5d465734553068fbf750ba60b0fe011cd9e76e766b1b0d8d066fc5295af22f574a95c228e", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/55fcfae66423439fa8f8e3af34587a50a1debb34db1751442632af0980799608977ea715269a0c07caf156596c7b56f3ab4d7d08e7ca93757879e55f7b41cc94", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3a6829f53c8e680d45798bc63c7e53adcbf81cdc6b6e6a7caeb37f1b70469c58bd8d2160708d4f4fa20899d5c7f7277c5efe26745fe133af7c2aa060b89053f7"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-08 07:45:33.241398) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:45:33.241738) ========= 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=ed14279e38b05397cf4aa391000001a4-1507471680.62846-1524043184 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004532 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 07:45:33.323160) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-08 07:45:33.326496) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-08 07:45:33.326828) ========= ========= Total master_lag: 0.28 =========