builder: mozilla-central_ubuntu64_hw_test-g4-e10s-pgo slave: talos-linux64-ix-028 starttime: 1507464089.68 results: success (0) revision: 8dba4037f395ce60309ce9e9b1675152f240ff98 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.678378) ========= master: http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.678845) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.679221) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.721840) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.722207) ========= 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=836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-10-08 05:01:29-- 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% 33.7M=0s 2017-10-08 05:01:29 (33.7 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.123888 ========= master_lag: 0.04 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.887660) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.887994) ========= 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=836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.018688 ========= master_lag: 0.08 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.983082) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:29.983394) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 8dba4037f395ce60309ce9e9b1675152f240ff98 --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 8dba4037f395ce60309ce9e9b1675152f240ff98 --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=836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-10-08 05:01:30,044 truncating revision to first 12 chars 2017-10-08 05:01:30,044 Setting DEBUG logging. 2017-10-08 05:01:30,044 attempt 1/10 2017-10-08 05:01:30,044 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/8dba4037f395?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-10-08 05:01:30,418 unpacking tar archive at: mozilla-central-8dba4037f395/testing/mozharness/ program finished with exit code 0 elapsedTime=0.699982 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:30.706968) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:30.707294) ========= script_repo_revision: 8dba4037f395ce60309ce9e9b1675152f240ff98 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:30.707653) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:30.707928) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-08 05:01:30.722508) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 44 secs) (at 2017-10-08 05:01:30.723100) ========= /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=836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 05:01:30 INFO - MultiFileLogger online at 20171008 05:01:30 in /builds/slave/test 05:01:30 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 05:01:30 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 05:01:30 INFO - {'append_to_log': False, 05:01:30 INFO - 'base_work_dir': '/builds/slave/test', 05:01:30 INFO - 'blob_upload_branch': 'Firefox', 05:01:30 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 05:01:30 INFO - 'branch': 'Firefox', 05:01:30 INFO - 'buildbot_json_path': 'buildprops.json', 05:01:30 INFO - 'code_coverage': False, 05:01:30 INFO - 'config_files': ('talos/linux_config.py',), 05:01:30 INFO - 'default_actions': ('clobber', 05:01:30 INFO - 'read-buildbot-config', 05:01:30 INFO - 'download-and-extract', 05:01:30 INFO - 'populate-webroot', 05:01:30 INFO - 'create-virtualenv', 05:01:30 INFO - 'install', 05:01:30 INFO - 'setup-mitmproxy', 05:01:30 INFO - 'run-tests'), 05:01:30 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 05:01:30 INFO - 'disable_ccov_upload': False, 05:01:30 INFO - 'disable_stylo': False, 05:01:30 INFO - 'download_minidump_stackwalk': True, 05:01:30 INFO - 'download_symbols': 'ondemand', 05:01:30 INFO - 'enable_stylo': False, 05:01:30 INFO - 'enable_webrender': False, 05:01:30 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 05:01:30 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 05:01:30 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 05:01:30 INFO - 'gecko_profile': False, 05:01:30 INFO - 'gecko_profile_interval': 0, 05:01:30 INFO - 'installer_path': 'installer.exe', 05:01:30 INFO - 'log_level': 'info', 05:01:30 INFO - 'log_name': 'talos', 05:01:30 INFO - 'log_to_console': True, 05:01:30 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 05:01:30 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 05:01:30 INFO - 'opt_config_files': (), 05:01:30 INFO - 'pip_index': False, 05:01:30 INFO - 'suite': 'g4-e10s', 05:01:30 INFO - 'system_bits': '32', 05:01:30 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 05:01:30 INFO - 'title': 'talos-linux64-ix-028', 05:01:30 INFO - 'tooltool_cache': '/builds/tooltool_cache', 05:01:30 INFO - 'use_talos_json': True, 05:01:30 INFO - 'verify': 'False', 05:01:30 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 05:01:30 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 05:01:30 INFO - 'work_dir': 'build'} 05:01:30 INFO - [mozharness: 2017-10-08 12:01:30.919852Z] Running clobber step. 05:01:30 INFO - Running pre-action listener: _resource_record_pre_action 05:01:30 INFO - Running main action method: clobber 05:01:30 INFO - rmtree: /builds/slave/test/build 05:01:30 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 05:01:32 INFO - Running post-action listener: _resource_record_post_action 05:01:32 INFO - [mozharness: 2017-10-08 12:01:32.413141Z] Finished clobber step (success) 05:01:32 INFO - [mozharness: 2017-10-08 12:01:32.413239Z] Running read-buildbot-config step. 05:01:32 INFO - Running pre-action listener: _resource_record_pre_action 05:01:32 INFO - Running main action method: read_buildbot_config 05:01:32 INFO - Using buildbot properties: 05:01:32 INFO - { 05:01:32 INFO - "project": "", 05:01:32 INFO - "product": "firefox", 05:01:32 INFO - "who": "archaeopteryx@coole-files.de", 05:01:32 INFO - "installer_path": "public/build/target.tar.bz2", 05:01:32 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-e10s", 05:01:32 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 05:01:32 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-e10s", 05:01:32 INFO - "stage_platform": "linux64-pgo", 05:01:32 INFO - "basedir": "/builds/slave/test", 05:01:32 INFO - "buildnumber": 18, 05:01:32 INFO - "platform": "ubuntu64_hw", 05:01:32 INFO - "master": "http://buildbot-master104.bb.releng.scl3.mozilla.com:8201/", 05:01:32 INFO - "slavebuilddir": "test", 05:01:32 INFO - "taskId": "A_9G-zyzRRuQ7eYO7m-jig", 05:01:32 INFO - "branch": "mozilla-central", 05:01:32 INFO - "script_repo_revision": "production", 05:01:32 INFO - "revision": "8dba4037f395ce60309ce9e9b1675152f240ff98", 05:01:32 INFO - "slavename": "talos-linux64-ix-028", 05:01:32 INFO - "repo_path": "mozilla-central" 05:01:32 INFO - } 05:01:32 INFO - Finding installer, test and symbols from parent task. 05:01:32 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/A_9G-zyzRRuQ7eYO7m-jig'}, attempt #1 05:01:32 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/A_9G-zyzRRuQ7eYO7m-jig'}, attempt #1 05:01:33 INFO - Task dependencies: QsqBukZUQguVt8gnPU9ATA 05:01:33 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA'}, attempt #1 05:01:33 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2 05:01:33 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.test_packages.json 05:01:33 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.crashreporter-symbols.zip 05:01:33 INFO - Running post-action listener: _resource_record_post_action 05:01:33 INFO - [mozharness: 2017-10-08 12:01:33.738401Z] Finished read-buildbot-config step (success) 05:01:33 INFO - [mozharness: 2017-10-08 12:01:33.738620Z] Running download-and-extract step. 05:01:33 INFO - Running pre-action listener: _resource_record_pre_action 05:01:33 INFO - Running main action method: download_and_extract 05:01:33 INFO - mkdir: /builds/slave/test/build/tests 05:01:33 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:33 INFO - trying https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.test_packages.json 05:01:33 INFO - Downloading https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 05:01:33 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 05:01:34 INFO - Downloaded 989 bytes. 05:01:34 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 05:01:34 INFO - Using the following test package requirements: 05:01:34 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 05:01:34 INFO - u'common': [u'target.common.tests.zip'], 05:01:34 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 05:01:34 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 05:01:34 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 05:01:34 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 05:01:34 INFO - u'mozbase': [u'target.common.tests.zip'], 05:01:34 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 05:01:34 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 05:01:34 INFO - u'web-platform': [u'target.common.tests.zip', 05:01:34 INFO - u'target.web-platform.tests.tar.gz'], 05:01:34 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 05:01:34 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 05:01:34 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.common.tests.zip 05:01:34 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.common.tests.zip'}, attempt #1 05:01:34 INFO - Fetch https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.common.tests.zip into memory 05:01:35 INFO - Content-Length response header: 55886941 05:01:35 INFO - Bytes received: 55886941 05:01:46 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.talos.tests.zip 05:01:46 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.talos.tests.zip'}, attempt #1 05:01:46 INFO - Fetch https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.talos.tests.zip into memory 05:01:47 INFO - Content-Length response header: 14431952 05:01:47 INFO - Bytes received: 14431952 05:01: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')]} 05:01:47 INFO - trying https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2 05:01:47 INFO - Downloading https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 05:01:47 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 05:01:48 INFO - Downloaded 62627691 bytes. 05:01:49 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2 05:01:49 INFO - mkdir: /builds/slave/test/properties 05:01:49 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 05:01:49 INFO - Writing to file /builds/slave/test/properties/build_url 05:01:49 INFO - Contents: 05:01:49 INFO - build_url:https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2 05:01:49 INFO - Running post-action listener: _resource_record_post_action 05:01:49 INFO - Running post-action listener: find_tests_for_verification 05:01:49 INFO - Running post-action listener: set_extra_try_arguments 05:01:49 INFO - [mozharness: 2017-10-08 12:01:49.012651Z] Finished download-and-extract step (success) 05:01:49 INFO - [mozharness: 2017-10-08 12:01:49.012893Z] Running populate-webroot step. 05:01:49 INFO - Running pre-action listener: _resource_record_pre_action 05:01:49 INFO - Running main action method: populate_webroot 05:01:49 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 05:01:49 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['tresize', 05:01:49 INFO - 'tcanvasmark']}, 05:01:49 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 05:01:49 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['dromaeo_css', 05:01:49 INFO - 'kraken']}, 05:01:49 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 05:01:49 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 05:01:49 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'tests': ['damp', 'tps']}, 05:01:49 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['damp', 'tps']}, 05:01:49 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 05:01:49 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['dromaeo_dom']}, 05:01:49 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 05:01:49 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['basic_compositor_video', 05:01:49 INFO - 'glvideo']}, 05:01:49 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 05:01:49 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['ts_paint_webext', 05:01:49 INFO - 'tp5o_webext']}, 05:01:49 INFO - 'other-e10s': {'tests': ['a11yr', 05:01:49 INFO - 'ts_paint', 05:01:49 INFO - 'tpaint', 05:01:49 INFO - 'sessionrestore', 05:01:49 INFO - 'sessionrestore_many_windows', 05:01:49 INFO - 'sessionrestore_no_auto_restore', 05:01:49 INFO - 'tabpaint', 05:01:49 INFO - 'cpstartup']}, 05:01:49 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['a11yr', 05:01:49 INFO - 'ts_paint', 05:01:49 INFO - 'tpaint', 05:01:49 INFO - 'sessionrestore', 05:01:49 INFO - 'sessionrestore_many_windows', 05:01:49 INFO - 'sessionrestore_no_auto_restore', 05:01:49 INFO - 'tabpaint', 05:01:49 INFO - 'cpstartup']}, 05:01:49 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 05:01:49 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 05:01:49 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['perf_reftest_singletons']}, 05:01:49 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['perf_reftest']}, 05:01:49 INFO - 'svgr-e10s': {'tests': ['tsvgx', 05:01:49 INFO - 'tsvgr_opacity', 05:01:49 INFO - 'tart', 05:01:49 INFO - 'tscrollx', 05:01:49 INFO - 'tsvg_static']}, 05:01:49 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['tsvgx', 05:01:49 INFO - 'tsvgr_opacity', 05:01:49 INFO - 'tart', 05:01:49 INFO - 'tscrollx', 05:01:49 INFO - 'tsvg_static']}, 05:01:49 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 05:01:49 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'talos_options': ['--disable-stylo'], 05:01:49 INFO - 'tests': ['tp5o']}, 05:01:49 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 05:01:49 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 05:01:49 INFO - 'talos_options': ['--mitmproxy', 05:01:49 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 05:01:49 INFO - '--firstNonBlankPaint'], 05:01:49 INFO - 'tests': ['tp6_google', 05:01:49 INFO - 'tp6_youtube', 05:01:49 INFO - 'tp6_amazon', 05:01:49 INFO - 'tp6_facebook']}, 05:01:49 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 05:01:49 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 05:01:49 INFO - 'talos_options': ['--disable-stylo', 05:01:49 INFO - '--mitmproxy', 05:01:49 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 05:01:49 INFO - '--firstNonBlankPaint'], 05:01:49 INFO - 'tests': ['tp6_google', 05:01:49 INFO - 'tp6_youtube', 05:01:49 INFO - 'tp6_amazon', 05:01:49 INFO - 'tp6_facebook']}, 05:01:49 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 05:01:49 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 05:01:49 INFO - 'talos_options': ['--stylo-threads=1', 05:01:49 INFO - '--mitmproxy', 05:01:49 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 05:01:49 INFO - '--firstNonBlankPaint'], 05:01:49 INFO - 'tests': ['tp6_google', 05:01:49 INFO - 'tp6_youtube', 05:01:49 INFO - 'tp6_amazon', 05:01:49 INFO - 'tp6_facebook']}, 05:01:49 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'talos_options': ['--xperf_path', 05:01:49 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 05:01:49 INFO - 'tests': ['tp5n']}, 05:01:49 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 05:01:49 INFO - 'talos_options': ['--disable-stylo', 05:01:49 INFO - '--xperf_path', 05:01:49 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 05:01:49 INFO - 'tests': ['tp5n']}}} 05:01:49 INFO - Running post-action listener: _resource_record_post_action 05:01:49 INFO - [mozharness: 2017-10-08 12:01:49.039082Z] Finished populate-webroot step (success) 05:01:49 INFO - [mozharness: 2017-10-08 12:01:49.039172Z] Running create-virtualenv step. 05:01:49 INFO - Running pre-action listener: _resource_record_pre_action 05:01:49 INFO - Running main action method: create_virtualenv 05:01:49 INFO - Creating virtualenv /builds/slave/test/build/venv 05:01:49 INFO - Running command: ['virtualenv', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 05:01:49 INFO - Copy/paste: virtualenv --no-site-packages --distribute /builds/slave/test/build/venv 05:01:49 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 05:01:49 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 05:01:49 INFO - New python executable in /builds/slave/test/build/venv/bin/python 05:01:49 INFO - Installing distribute.............................................................................................................................................................................................done. 05:01:49 INFO - Installing pip...............done. 05:01:49 INFO - Return code: 0 05:01:49 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 05:01:49 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 05:01:50 INFO - Reading from file tmpfile_stdout 05:01:50 INFO - Output received: 05:01:50 INFO - pip 1.1 from /builds/slave/test/build/venv/lib/python2.7/site-packages/pip-1.1-py2.7.egg (python 2.7) 05:01:50 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 05:01:50 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:50 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:01:50 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:50 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:01:50 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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:01:50 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 05:01:50 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 05:01:50 INFO - Using env: {'DISPLAY': ':0', 05:01:50 INFO - 'HOME': '/home/cltbld', 05:01:50 INFO - 'LANG': 'en_US.UTF-8', 05:01:50 INFO - 'LANGUAGE': 'en_US:en', 05:01:50 INFO - 'LOGNAME': 'cltbld', 05:01:50 INFO - 'MAIL': '/var/mail/cltbld', 05:01:50 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:01:50 INFO - 'MOZ_NO_REMOTE': '1', 05:01:50 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:01:50 INFO - 'NO_EM_RESTART': '1', 05:01:50 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:01:50 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:01:50 INFO - 'PWD': '/builds/slave/test', 05:01:50 INFO - 'SHELL': '/bin/bash', 05:01:50 INFO - 'SHLVL': '1', 05:01:50 INFO - 'TERM': 'linux', 05:01:50 INFO - 'TMOUT': '86400', 05:01:50 INFO - 'USER': 'cltbld', 05:01:50 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:01:50 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:01:50 INFO - '_': '/tools/buildbot/bin/python'} 05:01:51 INFO - Ignoring indexes: http://pypi.python.org/simple/ 05:01:51 INFO - Downloading/unpacking pip>=1.5 05:01:51 INFO - Running setup.py egg_info for package pip 05:01:51 INFO - warning: no files found matching 'pip/cacert.pem' 05:01:51 INFO - warning: no files found matching '*.html' under directory 'docs' 05:01:51 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 05:01:51 INFO - no previously-included directories found matching 'docs/_build/_sources' 05:01:51 INFO - Installing collected packages: pip 05:01:51 INFO - Found existing installation: pip 1.1 05:01:51 INFO - Uninstalling pip: 05:01:51 INFO - Successfully uninstalled pip 05:01:51 INFO - Running setup.py install for pip 05:01:51 INFO - warning: no files found matching 'pip/cacert.pem' 05:01:51 INFO - warning: no files found matching '*.html' under directory 'docs' 05:01:51 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 05:01:51 INFO - no previously-included directories found matching 'docs/_build/_sources' 05:01:51 INFO - Installing pip script to /builds/slave/test/build/venv/bin 05:01:51 INFO - Installing pip2.7 script to /builds/slave/test/build/venv/bin 05:01:51 INFO - Installing pip2 script to /builds/slave/test/build/venv/bin 05:01:51 INFO - Successfully installed pip 05:01:51 INFO - Cleaning up... 05:01:51 INFO - Return code: 0 05:01:51 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 05:01:51 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:51 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:01:51 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:51 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:01:51 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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:01:51 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 05:01:51 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 05:01:51 INFO - Using env: {'DISPLAY': ':0', 05:01:51 INFO - 'HOME': '/home/cltbld', 05:01:51 INFO - 'LANG': 'en_US.UTF-8', 05:01:51 INFO - 'LANGUAGE': 'en_US:en', 05:01:51 INFO - 'LOGNAME': 'cltbld', 05:01:51 INFO - 'MAIL': '/var/mail/cltbld', 05:01:51 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:01:51 INFO - 'MOZ_NO_REMOTE': '1', 05:01:51 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:01:51 INFO - 'NO_EM_RESTART': '1', 05:01:51 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:01:51 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:01:51 INFO - 'PWD': '/builds/slave/test', 05:01:51 INFO - 'SHELL': '/bin/bash', 05:01:51 INFO - 'SHLVL': '1', 05:01:51 INFO - 'TERM': 'linux', 05:01:51 INFO - 'TMOUT': '86400', 05:01:51 INFO - 'USER': 'cltbld', 05:01:51 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:01:51 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:01:51 INFO - '_': '/tools/buildbot/bin/python'} 05:01:51 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:01:51 INFO - Downloading/unpacking psutil>=3.1.1 05:01:51 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 05:01:51 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 05:01:51 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 05:01:51 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 05:01:52 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 05:01:52 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 05:01:52 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 05:01:52 INFO - Installing collected packages: psutil 05:01:52 INFO - Running setup.py install for psutil 05:01:52 INFO - building 'psutil._psutil_linux' extension 05:01:52 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 05:01:52 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 05:01:53 INFO - building 'psutil._psutil_posix' extension 05:01:53 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 05:01:53 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 05:01:53 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 05:01:53 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 05:01:53 INFO - Successfully installed psutil 05:01:53 INFO - Cleaning up... 05:01:53 INFO - Return code: 0 05:01:53 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 05:01:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:53 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:01:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:53 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:01:53 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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:01:53 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 05:01:53 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 05:01:53 INFO - Using env: {'DISPLAY': ':0', 05:01:53 INFO - 'HOME': '/home/cltbld', 05:01:53 INFO - 'LANG': 'en_US.UTF-8', 05:01:53 INFO - 'LANGUAGE': 'en_US:en', 05:01:53 INFO - 'LOGNAME': 'cltbld', 05:01:53 INFO - 'MAIL': '/var/mail/cltbld', 05:01:53 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:01:53 INFO - 'MOZ_NO_REMOTE': '1', 05:01:53 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:01:53 INFO - 'NO_EM_RESTART': '1', 05:01:53 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:01:53 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:01:53 INFO - 'PWD': '/builds/slave/test', 05:01:53 INFO - 'SHELL': '/bin/bash', 05:01:53 INFO - 'SHLVL': '1', 05:01:53 INFO - 'TERM': 'linux', 05:01:53 INFO - 'TMOUT': '86400', 05:01:53 INFO - 'USER': 'cltbld', 05:01:53 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:01:53 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:01:53 INFO - '_': '/tools/buildbot/bin/python'} 05:01:53 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:01:53 INFO - Downloading/unpacking mozsystemmonitor==0.3 05:01:53 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 05:01:53 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 05:01:53 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 05:01:53 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 05:01:54 INFO - Downloading mozsystemmonitor-0.3.tar.gz 05:01:54 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 05:01:54 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 05:01:54 INFO - Installing collected packages: mozsystemmonitor 05:01:54 INFO - Running setup.py install for mozsystemmonitor 05:01:54 INFO - Successfully installed mozsystemmonitor 05:01:54 INFO - Cleaning up... 05:01:57 INFO - Return code: 0 05:01:57 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 05:01:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:01:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:01:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:01:57 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:01:57 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1'] in /builds/slave/test/build 05:01:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema==2.5.1 05:01:57 INFO - Using env: {'DISPLAY': ':0', 05:01:57 INFO - 'HOME': '/home/cltbld', 05:01:57 INFO - 'LANG': 'en_US.UTF-8', 05:01:57 INFO - 'LANGUAGE': 'en_US:en', 05:01:57 INFO - 'LOGNAME': 'cltbld', 05:01:57 INFO - 'MAIL': '/var/mail/cltbld', 05:01:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:01:57 INFO - 'MOZ_NO_REMOTE': '1', 05:01:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:01:57 INFO - 'NO_EM_RESTART': '1', 05:01:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:01:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:01:57 INFO - 'PWD': '/builds/slave/test', 05:01:57 INFO - 'SHELL': '/bin/bash', 05:01:57 INFO - 'SHLVL': '1', 05:01:57 INFO - 'TERM': 'linux', 05:01:57 INFO - 'TMOUT': '86400', 05:01:57 INFO - 'USER': 'cltbld', 05:01:57 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:01:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:01:57 INFO - '_': '/tools/buildbot/bin/python'} 05:01:57 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:01:57 INFO - Downloading/unpacking jsonschema==2.5.1 05:01:57 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 05:01:57 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 05:01:57 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 05:01:57 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 05:01:59 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 05:01:59 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 05:01:59 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 05:01:59 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 05:01:59 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 05:01:59 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 05:01:59 INFO - Downloading functools32-3.2.3-2.tar.gz 05:01:59 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 05:01:59 INFO - warning: no files found matching '*.txt' 05:01:59 INFO - no previously-included directories found matching 'build' 05:01:59 INFO - no previously-included directories found matching 'dist' 05:01:59 INFO - no previously-included directories found matching '.git*' 05:02:00 INFO - Installing collected packages: jsonschema, functools32 05:02:00 INFO - Running setup.py install for functools32 05:02:00 INFO - warning: no files found matching '*.txt' 05:02:00 INFO - no previously-included directories found matching 'build' 05:02:00 INFO - no previously-included directories found matching 'dist' 05:02:00 INFO - no previously-included directories found matching '.git*' 05:02:00 INFO - Successfully installed jsonschema functools32 05:02:00 INFO - Cleaning up... 05:02:00 INFO - Return code: 0 05:02:00 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 05:02:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:02:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:02:00 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:02:00 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'functools32==3.2.3-2'] in /builds/slave/test/build 05:02:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub functools32==3.2.3-2 05:02:00 INFO - Using env: {'DISPLAY': ':0', 05:02:00 INFO - 'HOME': '/home/cltbld', 05:02:00 INFO - 'LANG': 'en_US.UTF-8', 05:02:00 INFO - 'LANGUAGE': 'en_US:en', 05:02:00 INFO - 'LOGNAME': 'cltbld', 05:02:00 INFO - 'MAIL': '/var/mail/cltbld', 05:02:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:00 INFO - 'MOZ_NO_REMOTE': '1', 05:02:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:00 INFO - 'NO_EM_RESTART': '1', 05:02:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:00 INFO - 'PWD': '/builds/slave/test', 05:02:00 INFO - 'SHELL': '/bin/bash', 05:02:00 INFO - 'SHLVL': '1', 05:02:00 INFO - 'TERM': 'linux', 05:02:00 INFO - 'TMOUT': '86400', 05:02:00 INFO - 'USER': 'cltbld', 05:02:00 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:00 INFO - '_': '/tools/buildbot/bin/python'} 05:02:00 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:02:00 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 05:02:00 INFO - Cleaning up... 05:02:00 INFO - Return code: 0 05:02:00 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 05:02:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:02:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:02:00 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:02:00 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 05:02:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 05:02:00 INFO - Using env: {'DISPLAY': ':0', 05:02:00 INFO - 'HOME': '/home/cltbld', 05:02:00 INFO - 'LANG': 'en_US.UTF-8', 05:02:00 INFO - 'LANGUAGE': 'en_US:en', 05:02:00 INFO - 'LOGNAME': 'cltbld', 05:02:00 INFO - 'MAIL': '/var/mail/cltbld', 05:02:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:00 INFO - 'MOZ_NO_REMOTE': '1', 05:02:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:00 INFO - 'NO_EM_RESTART': '1', 05:02:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:00 INFO - 'PWD': '/builds/slave/test', 05:02:00 INFO - 'SHELL': '/bin/bash', 05:02:00 INFO - 'SHLVL': '1', 05:02:00 INFO - 'TERM': 'linux', 05:02:00 INFO - 'TMOUT': '86400', 05:02:00 INFO - 'USER': 'cltbld', 05:02:00 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:00 INFO - '_': '/tools/buildbot/bin/python'} 05:02:00 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:02:00 INFO - Downloading/unpacking blobuploader==1.2.4 05:02:00 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 05:02:00 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 05:02:00 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 05:02:00 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 05:02:01 INFO - Downloading blobuploader-1.2.4.tar.gz 05:02:01 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 05:02:01 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 05:02:01 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 05:02:01 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 05:02:01 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 05:02:01 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 05:02:01 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 05:02:02 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 05:02:02 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 05:02:02 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 05:02:02 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 05:02:02 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 05:02:02 INFO - Downloading docopt-0.6.1.tar.gz 05:02:02 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 05:02:02 INFO - Installing collected packages: blobuploader, requests, docopt 05:02:02 INFO - Running setup.py install for blobuploader 05:02:02 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 05:02:02 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 05:02:02 INFO - Running setup.py install for requests 05:02:02 INFO - Running setup.py install for docopt 05:02:02 INFO - Successfully installed blobuploader requests docopt 05:02:02 INFO - Cleaning up... 05:02:02 INFO - Return code: 0 05:02:02 INFO - Installing None into virtualenv /builds/slave/test/build/venv 05:02:02 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:02 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:02:02 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:02 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:02:02 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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:02:02 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 05:02:02 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 05:02:02 INFO - Using env: {'DISPLAY': ':0', 05:02:02 INFO - 'HOME': '/home/cltbld', 05:02:02 INFO - 'LANG': 'en_US.UTF-8', 05:02:02 INFO - 'LANGUAGE': 'en_US:en', 05:02:02 INFO - 'LOGNAME': 'cltbld', 05:02:02 INFO - 'MAIL': '/var/mail/cltbld', 05:02:02 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:02 INFO - 'MOZ_NO_REMOTE': '1', 05:02:02 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:02 INFO - 'NO_EM_RESTART': '1', 05:02:02 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:02 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:02 INFO - 'PWD': '/builds/slave/test', 05:02:02 INFO - 'SHELL': '/bin/bash', 05:02:02 INFO - 'SHLVL': '1', 05:02:02 INFO - 'TERM': 'linux', 05:02:02 INFO - 'TMOUT': '86400', 05:02:02 INFO - 'USER': 'cltbld', 05:02:02 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:02 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:02 INFO - '_': '/tools/buildbot/bin/python'} 05:02:03 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 05:02:03 INFO - Running setup.py (path:/tmp/pip-vXpUTK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 05:02:03 INFO - Running setup.py (path:/tmp/pip-E1tQBs-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 05:02:03 INFO - Running setup.py (path:/tmp/pip-jwD8D7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 05:02:03 INFO - Running setup.py (path:/tmp/pip-oUuqVB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 05:02:03 INFO - Running setup.py (path:/tmp/pip-jsBD6W-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 05:02:03 INFO - Running setup.py (path:/tmp/pip-6qIPrh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 05:02:03 INFO - Running setup.py (path:/tmp/pip-ZURrm2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 05:02:03 INFO - Running setup.py (path:/tmp/pip-DathKT-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 05:02:03 INFO - Running setup.py (path:/tmp/pip-xjmOEZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 05:02:03 INFO - Running setup.py (path:/tmp/pip-Gtz9eR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 05:02:03 INFO - Running setup.py (path:/tmp/pip-_HaAQ2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 05:02:03 INFO - Running setup.py (path:/tmp/pip-7Ijn5y-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 05:02:03 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 05:02:03 INFO - Running setup.py (path:/tmp/pip-Rm8TfI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 05:02:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 05:02:04 INFO - Running setup.py (path:/tmp/pip-Jb5vA4-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 05:02:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 05:02:04 INFO - Running setup.py (path:/tmp/pip-wPRRMB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 05:02:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 05:02:04 INFO - Running setup.py (path:/tmp/pip-w0IEOy-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 05:02:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 05:02:04 INFO - Running setup.py (path:/tmp/pip-gqVFqG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 05:02:04 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 05:02:04 INFO - Running setup.py install for manifestparser 05:02:04 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 05:02:04 INFO - Running setup.py install for mozcrash 05:02:04 INFO - Running setup.py install for mozdebug 05:02:04 INFO - Running setup.py install for mozdevice 05:02:04 INFO - Installing dm script to /builds/slave/test/build/venv/bin 05:02:04 INFO - Running setup.py install for mozfile 05:02:04 INFO - Running setup.py install for mozhttpd 05:02:04 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 05:02:04 INFO - Running setup.py install for mozinfo 05:02:04 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Running setup.py install for mozInstall 05:02:05 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Running setup.py install for mozleak 05:02:05 INFO - Running setup.py install for mozlog 05:02:05 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Running setup.py install for moznetwork 05:02:05 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Running setup.py install for mozprocess 05:02:05 INFO - Running setup.py install for mozprofile 05:02:05 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Running setup.py install for mozrunner 05:02:05 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 05:02:05 INFO - Running setup.py install for mozscreenshot 05:02:05 INFO - Running setup.py install for moztest 05:02:05 INFO - Running setup.py install for mozversion 05:02:06 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 05:02:06 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 05:02:06 INFO - Cleaning up... 05:02:06 INFO - Return code: 0 05:02:06 INFO - Installing None into virtualenv /builds/slave/test/build/venv 05:02:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:06 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:02:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:06 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:02:06 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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:02:06 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 05:02:06 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 05:02:06 INFO - Using env: {'DISPLAY': ':0', 05:02:06 INFO - 'HOME': '/home/cltbld', 05:02:06 INFO - 'LANG': 'en_US.UTF-8', 05:02:06 INFO - 'LANGUAGE': 'en_US:en', 05:02:06 INFO - 'LOGNAME': 'cltbld', 05:02:06 INFO - 'MAIL': '/var/mail/cltbld', 05:02:06 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:06 INFO - 'MOZ_NO_REMOTE': '1', 05:02:06 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:06 INFO - 'NO_EM_RESTART': '1', 05:02:06 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:06 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:06 INFO - 'PWD': '/builds/slave/test', 05:02:06 INFO - 'SHELL': '/bin/bash', 05:02:06 INFO - 'SHLVL': '1', 05:02:06 INFO - 'TERM': 'linux', 05:02:06 INFO - 'TMOUT': '86400', 05:02:06 INFO - 'USER': 'cltbld', 05:02:06 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:06 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:06 INFO - '_': '/tools/buildbot/bin/python'} 05:02:06 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 05:02:06 INFO - Running setup.py (path:/tmp/pip-iy90to-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 05:02:06 INFO - Running setup.py (path:/tmp/pip-X3BNyZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 05:02:06 INFO - Running setup.py (path:/tmp/pip-kYlvFh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 05:02:06 INFO - Running setup.py (path:/tmp/pip-d8a4SR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 05:02:06 INFO - Running setup.py (path:/tmp/pip-0qSWrY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 05:02:06 INFO - Running setup.py (path:/tmp/pip-HSQHbB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 05:02:06 INFO - Running setup.py (path:/tmp/pip-Th7Lva-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 05:02:06 INFO - Running setup.py (path:/tmp/pip-jsQdfs-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 05:02:06 INFO - Running setup.py (path:/tmp/pip-RmAs0Y-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 05:02:06 INFO - Running setup.py (path:/tmp/pip-hF8LYw-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 05:02:06 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)) 05:02:06 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 05:02:06 INFO - Running setup.py (path:/tmp/pip-B2skXV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 05:02:07 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)) 05:02:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 05:02:07 INFO - Running setup.py (path:/tmp/pip-2fJzFl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 05:02:07 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)) 05:02:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 05:02:07 INFO - Running setup.py (path:/tmp/pip-pdloq_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 05:02:07 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)) 05:02:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 05:02:07 INFO - Running setup.py (path:/tmp/pip-ZWnb_f-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 05:02:07 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)) 05:02:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 05:02:07 INFO - Running setup.py (path:/tmp/pip-9L6ESb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 05:02:07 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)) 05:02:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 05:02:07 INFO - Running setup.py (path:/tmp/pip-gLDBUh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 05:02:07 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)) 05:02:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 05:02:07 INFO - Running setup.py (path:/tmp/pip-JLaxey-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 05:02:07 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)) 05:02:07 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)) 05:02:07 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)) 05:02:07 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)) 05:02:07 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)) 05:02:07 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)) 05:02:07 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)) 05:02:07 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 05:02:07 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 05:02:07 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 05:02:07 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 05:02:07 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 05:02:08 INFO - Downloading blessings-1.6.tar.gz 05:02:08 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 05:02:08 INFO - Installing collected packages: blessings 05:02:08 INFO - Running setup.py install for blessings 05:02:08 INFO - Successfully installed blessings 05:02:08 INFO - Cleaning up... 05:02:08 INFO - Return code: 0 05:02:08 INFO - Done creating virtualenv /builds/slave/test/build/venv. 05:02:08 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 05:02:08 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 05:02:09 INFO - Reading from file tmpfile_stdout 05:02:09 INFO - Current package versions: 05:02:09 INFO - argparse == 1.2.1 05:02:09 INFO - blessings == 1.6 05:02:09 INFO - blobuploader == 1.2.4 05:02:09 INFO - docopt == 0.6.1 05:02:09 INFO - functools32 == 3.2.3-2 05:02:09 INFO - jsonschema == 2.5.1 05:02:09 INFO - manifestparser == 1.1 05:02:09 INFO - mozInstall == 1.13 05:02:09 INFO - mozcrash == 1.0 05:02:09 INFO - mozdebug == 0.1 05:02:09 INFO - mozdevice == 0.51 05:02:09 INFO - mozfile == 1.2 05:02:09 INFO - mozhttpd == 0.7 05:02:09 INFO - mozinfo == 0.10 05:02:09 INFO - mozleak == 0.1 05:02:09 INFO - mozlog == 3.5 05:02:09 INFO - moznetwork == 0.27 05:02:09 INFO - mozprocess == 0.25 05:02:09 INFO - mozprofile == 0.28 05:02:09 INFO - mozrunner == 6.13 05:02:09 INFO - mozscreenshot == 0.1 05:02:09 INFO - mozsystemmonitor == 0.3 05:02:09 INFO - moztest == 0.8 05:02:09 INFO - mozversion == 1.4 05:02:09 INFO - psutil == 3.1.1 05:02:09 INFO - requests == 1.2.3 05:02:09 INFO - wsgiref == 0.1.2 05:02:09 INFO - Installing None into virtualenv /builds/slave/test/build/venv 05:02: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')]} 05:02:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:02: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')]} 05:02:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:02:09 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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:02:09 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 05:02:09 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 05:02:09 INFO - Using env: {'DISPLAY': ':0', 05:02:09 INFO - 'HOME': '/home/cltbld', 05:02:09 INFO - 'LANG': 'en_US.UTF-8', 05:02:09 INFO - 'LANGUAGE': 'en_US:en', 05:02:09 INFO - 'LOGNAME': 'cltbld', 05:02:09 INFO - 'MAIL': '/var/mail/cltbld', 05:02:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:09 INFO - 'MOZ_NO_REMOTE': '1', 05:02:09 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:09 INFO - 'NO_EM_RESTART': '1', 05:02:09 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:09 INFO - 'PWD': '/builds/slave/test', 05:02:09 INFO - 'SHELL': '/bin/bash', 05:02:09 INFO - 'SHLVL': '1', 05:02:09 INFO - 'TERM': 'linux', 05:02:09 INFO - 'TMOUT': '86400', 05:02:09 INFO - 'USER': 'cltbld', 05:02:09 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:09 INFO - '_': '/tools/buildbot/bin/python'} 05:02:09 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:02:09 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)) 05:02:09 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)) 05:02:09 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)) 05:02:09 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)) 05:02:09 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)) 05:02:09 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)) 05:02:09 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)) 05:02:09 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)) 05:02:09 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)) 05:02:09 INFO - Downloading/unpacking simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 05:02: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 05:02: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 05:02: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 05:02: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 05:02:10 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/simplejson/setup.py) egg_info for package simplejson 05:02:10 INFO - Downloading/unpacking requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 05:02:10 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 05:02:10 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 05:02:10 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 05:02:10 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 05:02:10 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 05:02:10 INFO - warning: no files found matching 'test_requests.py' 05:02:10 INFO - warning: no files found matching 'requirements.txt' 05:02:10 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)) 05:02:10 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)) 05:02:10 INFO - Installing collected packages: simplejson, requests 05:02:10 INFO - Running setup.py install for simplejson 05:02:10 INFO - building 'simplejson._speedups' extension 05:02:10 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 05:02:11 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 05:02:11 INFO - Found existing installation: requests 1.2.3 05:02:11 INFO - Uninstalling requests: 05:02:11 INFO - Successfully uninstalled requests 05:02:11 INFO - Running setup.py install for requests 05:02:11 INFO - warning: no files found matching 'test_requests.py' 05:02:11 INFO - warning: no files found matching 'requirements.txt' 05:02:12 INFO - Successfully installed simplejson requests 05:02:12 INFO - Cleaning up... 05:02:12 INFO - Return code: 0 05:02:12 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 05:02:12 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')]} 05:02:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 05:02:12 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')]} 05:02:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 05:02:12 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 0x288f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a57b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfc9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, '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': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', '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 05:02:12 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 05:02:12 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 05:02:12 INFO - Using env: {'DISPLAY': ':0', 05:02:12 INFO - 'HOME': '/home/cltbld', 05:02:12 INFO - 'LANG': 'en_US.UTF-8', 05:02:12 INFO - 'LANGUAGE': 'en_US:en', 05:02:12 INFO - 'LOGNAME': 'cltbld', 05:02:12 INFO - 'MAIL': '/var/mail/cltbld', 05:02:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:12 INFO - 'MOZ_NO_REMOTE': '1', 05:02:12 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:12 INFO - 'NO_EM_RESTART': '1', 05:02:12 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:12 INFO - 'PWD': '/builds/slave/test', 05:02:12 INFO - 'SHELL': '/bin/bash', 05:02:12 INFO - 'SHLVL': '1', 05:02:12 INFO - 'TERM': 'linux', 05:02:12 INFO - 'TMOUT': '86400', 05:02:12 INFO - 'USER': 'cltbld', 05:02:12 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:12 INFO - '_': '/tools/buildbot/bin/python'} 05:02:12 INFO - Ignoring indexes: https://pypi.python.org/simple/ 05:02:12 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 05:02:12 INFO - Cleaning up... 05:02:12 INFO - Return code: 0 05:02:12 INFO - Running post-action listener: _resource_record_post_action 05:02:12 INFO - Running post-action listener: _start_resource_monitoring 05:02:12 INFO - Starting resource monitoring. 05:02:12 INFO - [mozharness: 2017-10-08 12:02:12.562745Z] Finished create-virtualenv step (success) 05:02:12 INFO - [mozharness: 2017-10-08 12:02:12.563216Z] Running install step. 05:02:12 INFO - Running pre-action listener: _resource_record_pre_action 05:02:12 INFO - Running main action method: install 05:02:12 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 05:02:12 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 05:02:12 INFO - Reading from file tmpfile_stdout 05:02:12 INFO - Detecting whether we're running mozinstall >=1.0... 05:02:12 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 05:02:12 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 05:02:12 INFO - Reading from file tmpfile_stdout 05:02:12 INFO - Output received: 05:02:12 INFO - Usage: mozinstall [options] installer 05:02:12 INFO - Options: 05:02:12 INFO - -h, --help show this help message and exit 05:02:12 INFO - -d DEST, --destination=DEST 05:02:12 INFO - Directory to install application into. [default: 05:02:12 INFO - "/builds/slave/test"] 05:02:12 INFO - --app=APP Application being installed. [default: firefox] 05:02:12 INFO - mkdir: /builds/slave/test/build/application 05:02:12 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'] 05:02:12 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 05:02:30 INFO - Reading from file tmpfile_stdout 05:02:30 INFO - Output received: 05:02:30 INFO - /builds/slave/test/build/application/firefox/firefox 05:02:30 INFO - Running post-action listener: _resource_record_post_action 05:02:30 INFO - [mozharness: 2017-10-08 12:02:30.640660Z] Finished install step (success) 05:02:30 INFO - [mozharness: 2017-10-08 12:02:30.640806Z] Running setup-mitmproxy step. 05:02:30 INFO - Running pre-action listener: _resource_record_pre_action 05:02:30 INFO - Running main action method: setup_mitmproxy 05:02:30 INFO - Skipping: mitmproxy is not required 05:02:30 INFO - Running post-action listener: _resource_record_post_action 05:02:30 INFO - [mozharness: 2017-10-08 12:02:30.641490Z] Finished setup-mitmproxy step (success) 05:02:30 INFO - [mozharness: 2017-10-08 12:02:30.641714Z] Running run-tests step. 05:02:30 INFO - Running pre-action listener: _resource_record_pre_action 05:02:30 INFO - Running pre-action listener: _set_gcov_prefix 05:02:30 INFO - Running main action method: run_tests 05:02:30 WARNING - Try message not found. 05:02:30 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 05:02:30 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 05:02:30 INFO - Python 2.7.3 05:02:30 INFO - Return code: 0 05:02:30 INFO - grabbing minidump binary from tooltool 05:02:30 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 05:02:30 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 0x2bf9d60>, '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 0x2bfaa60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfaef0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 05:02:30 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 05:02:30 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 05:02:30 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 05:02:30 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 05:02:30 INFO - Return code: 0 05:02:30 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 05:02:30 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 05:02:30 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 05:02:30 INFO - ENV: RUST_BACKTRACE is now full 05:02:30 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 05:02:30 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 05:02:30 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/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-028', '--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 05:02:30 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/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-028 --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 05:02:30 INFO - Using env: {'DISPLAY': ':0', 05:02:30 INFO - 'HOME': '/home/cltbld', 05:02:30 INFO - 'LANG': 'en_US.UTF-8', 05:02:30 INFO - 'LANGUAGE': 'en_US:en', 05:02:30 INFO - 'LOGNAME': 'cltbld', 05:02:30 INFO - 'MAIL': '/var/mail/cltbld', 05:02:30 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 05:02:30 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 05:02:30 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:30 INFO - 'MOZ_NO_REMOTE': '1', 05:02:30 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 05:02:30 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:30 INFO - 'NO_EM_RESTART': '1', 05:02:30 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:30 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:30 INFO - 'PWD': '/builds/slave/test', 05:02:30 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 05:02:30 INFO - 'RUST_BACKTRACE': 'full', 05:02:30 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 05:02:30 INFO - 'SHELL': '/bin/bash', 05:02:30 INFO - 'SHLVL': '1', 05:02:30 INFO - 'TERM': 'linux', 05:02:30 INFO - 'TMOUT': '86400', 05:02:30 INFO - 'USER': 'cltbld', 05:02:30 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:30 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:30 INFO - '_': '/tools/buildbot/bin/python'} 05:02:30 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/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-028', '--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 05:02:31 INFO - mozversion application_buildid: 20171008094448 05:02:31 INFO - mozversion application_changeset: 8dba4037f395ce60309ce9e9b1675152f240ff98 05:02:31 INFO - mozversion application_display_name: Nightly 05:02:31 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 05:02:31 INFO - mozversion application_name: Firefox 05:02:31 INFO - mozversion application_remotingname: firefox 05:02:31 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 05:02:31 INFO - mozversion application_vendor: Mozilla 05:02:31 INFO - mozversion application_version: 58.0a1 05:02:31 INFO - mozversion platform_buildid: 20171008094448 05:02:31 INFO - mozversion platform_changeset: 8dba4037f395ce60309ce9e9b1675152f240ff98 05:02:31 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 05:02:31 INFO - mozversion platform_version: 58.0a1 05:02:31 INFO - using testdate: 1507464151 05:02:31 INFO - actual date: 1507464151 05:02:31 INFO - starting webserver on 'localhost:45017' 05:02:31 INFO - SUITE-START | Running 2 tests 05:02:31 INFO - TEST-START | basic_compositor_video 05:02:31 INFO - Initialising browser for basic_compositor_video test... 05:02:31 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:45017/getInfo.html -profile /tmp/tmpuRObgA/profile 05:02:31 INFO - TEST-INFO | started process 12431 (/builds/slave/test/build/application/firefox/firefox http://localhost:45017/getInfo.html) 05:02:36 INFO - TEST-INFO | 12431: exit 0 05:02:36 INFO - Browser initialized. 05:02:36 INFO - Running cycle 1/1 for basic_compositor_video test... 05:02:36 INFO - Using env: {'DISPLAY': ':0', 05:02:36 INFO - 'HOME': '/home/cltbld', 05:02:36 INFO - 'JSGC_DISABLE_POISONING': '1', 05:02:36 INFO - 'LANG': 'en_US.UTF-8', 05:02:36 INFO - 'LANGUAGE': 'en_US:en', 05:02:36 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 05:02:36 INFO - 'LOGNAME': 'cltbld', 05:02:36 INFO - 'MAIL': '/var/mail/cltbld', 05:02:36 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 05:02:36 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 05:02:36 INFO - 'MOZ_CRASHREPORTER': '1', 05:02:36 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:02:36 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 05:02:36 INFO - 'MOZ_NO_REMOTE': '1', 05:02:36 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 05:02:36 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:02:36 INFO - 'NO_EM_RESTART': '1', 05:02:36 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:02:36 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:02:36 INFO - 'PWD': '/builds/slave/test', 05:02:36 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 05:02:36 INFO - 'RUST_BACKTRACE': 'full', 05:02:36 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 05:02:36 INFO - 'SHELL': '/bin/bash', 05:02:36 INFO - 'SHLVL': '1', 05:02:36 INFO - 'TERM': 'linux', 05:02:36 INFO - 'TMOUT': '86400', 05:02:36 INFO - 'USER': 'cltbld', 05:02:36 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:02:36 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:02:36 INFO - '_': '/tools/buildbot/bin/python'} 05:02:36 INFO - TEST-INFO | started process 12707 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpuRObgA/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 05:02:37 INFO - PID 12707 | 05:02:37 INFO - PID 12707 | (/builds/slave/test/build/application/firefox/firefox:12757): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 05:02:37 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6764413407821228 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6687364470391997 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7304411764705887 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7470087336244533 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 3.995758988015979 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.124371134020618 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.41000568181818 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.361848739495797 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.5460905730129415 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.494642857142855 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 9.74050324675325 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 9.571267942583734 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.031709558823517 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.696283422459903 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.39973140495868 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.840680473372764 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.584266409266426 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.874347826086943 ms/frame 05:03:24 INFO - PID 12707 | 05:03:24 INFO - PID 12707 | Cycle 1(1): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:04:10 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.690554929577465 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6669083333333337 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7777399289099525 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7777822222222215 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.037860026917902 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.7684463276836158 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.624064009661838 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5285890652557304 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.567894248608536 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.540387811634344 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.002833333333328 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 9.710388349514563 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.991282051282061 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.64021276595745 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.50147916666668 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.633517441860445 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.497950191570895 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.870624999999999 ms/frame 05:04:10 INFO - PID 12707 | 05:04:10 INFO - PID 12707 | Cycle 1(2): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:04:56 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6789563514269725 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6715914786967423 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.760985915492958 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7293301642178054 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 3.958608179419525 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.08187755102041 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.44105504587156 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.351172529313235 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.683134469696969 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.405824324324331 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.034113712374584 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 10.102727272727273 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.113962962962951 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.756666666666694 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.24502040816326 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.767411764705876 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.113518518518523 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.875869565217371 ms/frame 05:04:56 INFO - PID 12707 | 05:04:56 INFO - PID 12707 | Cycle 1(3): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:05:42 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6902535211267604 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6670541666666667 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7525759345794392 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7185352233676976 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.082544217687075 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.009849699398799 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.417272209567198 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3394824707846387 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.556092592592587 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.556833333333341 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.490856643356638 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 9.757780487804883 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.154535315985129 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.53205263157893 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.296311475409818 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.121575757575744 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.584266409266426 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.240477528089889 ms/frame 05:05:42 INFO - PID 12707 | 05:05:42 INFO - PID 12707 | Cycle 1(4): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:06:28 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6856657303370788 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6683986655546288 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7892218246869407 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7322683982683986 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.174019471488177 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.115884773662551 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.417135535307516 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.357541946308727 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.725734732824427 ms/frame 05:06:28 INFO - PID 12707 | 05:06:28 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.667110481586406 ms/frame 05:06:28 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.604116607773852 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 10.106388888888882 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.99111721611722 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.641010638297884 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.555564853556481 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.434514285714291 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.583359073359059 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.174748603351949 ms/frame 05:06:29 INFO - PID 12707 | 05:06:29 INFO - PID 12707 | Cycle 1(5): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:07:15 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6820739910313902 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.667775 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7757810650887573 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7669787985865726 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.156094182825483 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.117242798353912 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.505105140186915 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.413779863481232 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.671474480151227 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.494587912087909 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.417638888888884 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 10.205892857142873 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.872137681159417 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.583333333333334 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.450394190871362 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.567109826589599 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.152509293680303 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.753924731182774 ms/frame 05:07:15 INFO - PID 12707 | 05:07:15 INFO - PID 12707 | Cycle 1(6): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:08:01 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6816872197309418 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6673000000000002 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7847114812611542 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.750139982502187 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9743642384105966 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.185533472803346 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.5009393232205372 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5219190140845082 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.683645833333333 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5417867036011055 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 9.805081699346404 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 9.66183574879227 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.116425925925931 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.640186170212782 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.399462809917349 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.122999999999989 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.451812977099237 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.930191256830632 ms/frame 05:08:01 INFO - PID 12707 | 05:08:01 INFO - PID 12707 | Cycle 1(7): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:08:47 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6835409652076319 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6730267558528424 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7445784883720932 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7170643776824035 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0663279132791335 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.125257731958763 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.5222652582159637 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3739460370994943 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.7044866920152115 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5574861111111105 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.138429054054061 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 10.992637362637362 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.073413284132842 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.639813829787252 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.60533613445378 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.053463855421686 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.321471698113216 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.812810810810825 ms/frame 05:08:47 INFO - PID 12707 | 05:08:47 INFO - PID 12707 | Cycle 1(8): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:09:33 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.685629213483146 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6726003344481604 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7806320474777453 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7380278019113808 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.082972789115645 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.176252609603343 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.5672592152199747 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.496756993006994 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.545406654343806 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.450544959128071 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.034197324414711 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 10.104494949494962 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.152936802973962 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.753279569892475 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.45201244813277 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.628023255813977 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.365113636363635 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.930382513661213 ms/frame 05:09:33 INFO - PID 12707 | 05:09:33 INFO - PID 12707 | Cycle 1(9): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:10:19 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6784703579418345 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6676249999999997 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7386500579374276 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.781500445235975 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.172475660639778 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.000350000000002 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.429251428571428 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.379518581081086 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.769788461538464 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.334706666666665 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 10.345034482758626 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 9.854433497536949 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.03242647058822 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.643537234042556 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.822286324786328 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.980119760479043 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.366098484848491 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.992609890109884 ms/frame 05:10:19 INFO - PID 12707 | 05:10:19 INFO - PID 12707 | Cycle 1(10): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:11:06 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.685691011235955 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6712656641604011 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.776204854943754 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7599648197009674 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0444474393531 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9526778656126487 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.456198156682027 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4193931623931646 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.66061320754717 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.48139726027398 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 9.872088815789478 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 9.807034313725483 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.989322344322328 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.586957671957698 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.349753086419774 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.769147058823513 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.628643410852694 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.304604519774017 ms/frame 05:11:06 INFO - PID 12707 | 05:11:06 INFO - PID 12707 | Cycle 1(11): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:11:52 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_startup = 1.679040290990487 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.668256880733945 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7362905092592589 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7095683760683758 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_startup = 4.071906377204885 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.124525773195874 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_startup = 3.601926770708284 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5477216312056754 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.598208955223879 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.558652777777782 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_startup = 9.869851973684202 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.480p.60fps.webm_scale_2_inclip = 10.583042328042326 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.071143911439124 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.642207446808476 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.609663865546212 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.347129629629633 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.322226415094338 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.641622340425531 ms/frame 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | Cycle 1(12): loaded http://localhost:45017/tests/video/video_playback.html (next: http://localhost:45017/tests/video/video_playback.html) 05:11:52 INFO - PID 12707 | __start_tp_report 05:11:52 INFO - PID 12707 | _x_x_mozilla_page_load 05:11:52 INFO - PID 12707 | _x_x_mozilla_page_load_details 05:11:52 INFO - PID 12707 | |i|pagename|runs| 05:11:52 INFO - PID 12707 | |0;240p.120fps.mp4_scale_1_startup;1.6764413407821228;1.690554929577465;1.6789563514269725;1.6902535211267604;1.6856657303370788;1.6820739910313902;1.6816872197309418;1.6835409652076319;1.685629213483146;1.6784703579418345;1.685691011235955;1.679040290990487 05:11:52 INFO - PID 12707 | |1;240p.120fps.mp4_scale_1_inclip;1.6687364470391997;1.6669083333333337;1.6715914786967423;1.6670541666666667;1.6683986655546288;1.667775;1.6673000000000002;1.6730267558528424;1.6726003344481604;1.6676249999999997;1.6712656641604011;1.668256880733945 05:11:52 INFO - PID 12707 | |2;240p.120fps.mp4_scale_1.1_startup;1.7304411764705887;1.7777399289099525;1.760985915492958;1.7525759345794392;1.7892218246869407;1.7757810650887573;1.7847114812611542;1.7445784883720932;1.7806320474777453;1.7386500579374276;1.776204854943754;1.7362905092592589 05:11:52 INFO - PID 12707 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7470087336244533;1.7777822222222215;1.7293301642178054;1.7185352233676976;1.7322683982683986;1.7669787985865726;1.750139982502187;1.7170643776824035;1.7380278019113808;1.781500445235975;1.7599648197009674;1.7095683760683758 05:11:52 INFO - PID 12707 | |4;240p.120fps.mp4_scale_2_startup;3.995758988015979;4.037860026917902;3.958608179419525;4.082544217687075;4.174019471488177;4.156094182825483;3.9743642384105966;4.0663279132791335;4.082972789115645;4.172475660639778;4.0444474393531;4.071906377204885 05:11:52 INFO - PID 12707 | |5;240p.120fps.mp4_scale_2_inclip;4.124371134020618;3.7684463276836158;4.08187755102041;4.009849699398799;4.115884773662551;4.117242798353912;4.185533472803346;4.125257731958763;4.176252609603343;4.000350000000002;3.9526778656126487;4.124525773195874 05:11:52 INFO - PID 12707 | |6;480p.60fps.webm_scale_1_startup;3.41000568181818;3.624064009661838;3.44105504587156;3.417272209567198;3.417135535307516;3.505105140186915;3.5009393232205372;3.5222652582159637;3.5672592152199747;3.429251428571428;3.456198156682027;3.601926770708284 05:11:52 INFO - PID 12707 | |7;480p.60fps.webm_scale_1_inclip;3.361848739495797;3.5285890652557304;3.351172529313235;3.3394824707846387;3.357541946308727;3.413779863481232;3.5219190140845082;3.3739460370994943;3.496756993006994;3.379518581081086;3.4193931623931646;3.5477216312056754 05:11:52 INFO - PID 12707 | |8;480p.60fps.webm_scale_1.1_startup;5.5460905730129415;5.567894248608536;5.683134469696969;5.556092592592587;5.725734732824427;5.671474480151227;5.683645833333333;5.7044866920152115;5.545406654343806;5.769788461538464;5.66061320754717;5.598208955223879 05:11:52 INFO - PID 12707 | |9;480p.60fps.webm_scale_1.1_inclip;5.494642857142855;5.540387811634344;5.405824324324331;5.556833333333341;5.667110481586406;5.494587912087909;5.5417867036011055;5.5574861111111105;5.450544959128071;5.334706666666665;5.48139726027398;5.558652777777782 05:11:52 INFO - PID 12707 | |10;480p.60fps.webm_scale_2_startup;9.74050324675325;10.002833333333328;10.034113712374584;10.490856643356638;10.604116607773852;10.417638888888884;9.805081699346404;10.138429054054061;10.034197324414711;10.345034482758626;9.872088815789478;9.869851973684202 05:11:52 INFO - PID 12707 | |11;480p.60fps.webm_scale_2_inclip;9.571267942583734;9.710388349514563;10.102727272727273;9.757780487804883;10.106388888888882;10.205892857142873;9.66183574879227;10.992637362637362;10.104494949494962;9.854433497536949;9.807034313725483;10.583042328042326 05:11:52 INFO - PID 12707 | |12;1080p.60fps.mp4_scale_1_startup;11.031709558823517;10.991282051282061;11.113962962962951;11.154535315985129;10.99111721611722;10.872137681159417;11.116425925925931;11.073413284132842;11.152936802973962;11.03242647058822;10.989322344322328;11.071143911439124 05:11:52 INFO - PID 12707 | |13;1080p.60fps.mp4_scale_1_inclip;10.696283422459903;10.64021276595745;10.756666666666694;10.53205263157893;10.641010638297884;10.583333333333334;10.640186170212782;10.639813829787252;10.753279569892475;10.643537234042556;10.586957671957698;10.642207446808476 05:11:52 INFO - PID 12707 | |14;1080p.60fps.mp4_scale_1.1_startup;12.39973140495868;12.50147916666668;12.24502040816326;12.296311475409818;12.555564853556481;12.450394190871362;12.399462809917349;12.60533613445378;12.45201244813277;12.822286324786328;12.349753086419774;12.609663865546212 05:11:52 INFO - PID 12707 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.840680473372764;11.633517441860445;11.767411764705876;12.121575757575744;11.434514285714291;11.567109826589599;12.122999999999989;12.053463855421686;11.628023255813977;11.980119760479043;11.769147058823513;12.347129629629633 05:11:52 INFO - PID 12707 | |16;1080p.60fps.mp4_scale_2_startup;11.584266409266426;11.497950191570895;11.113518518518523;11.584266409266426;11.583359073359059;11.152509293680303;11.451812977099237;11.321471698113216;11.365113636363635;11.366098484848491;11.628643410852694;11.322226415094338 05:11:52 INFO - PID 12707 | |17;1080p.60fps.mp4_scale_2_inclip;10.874347826086943;10.870624999999999;10.875869565217371;11.240477528089889;11.174748603351949;10.753924731182774;10.930191256830632;10.812810810810825;10.930382513661213;10.992609890109884;11.304604519774017;10.641622340425531 05:11:52 INFO - PID 12707 | __end_tp_report 05:11:52 INFO - PID 12707 | __start_cc_report 05:11:52 INFO - PID 12707 | _x_x_mozilla_cycle_collect,564 05:11:52 INFO - PID 12707 | __end_cc_report 05:11:52 INFO - PID 12707 | __startTimestamp1507464712453__endTimestamp 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | ------- Summary: start ------- 05:11:52 INFO - PID 12707 | Number of tests: 18 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.00 (0.3%) stddev-sans-first:0.00 05:11:52 INFO - PID 12707 | 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 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#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 05:11:52 INFO - PID 12707 | 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 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.76 Median:1.78 stddev:0.02 (1.2%) stddev-sans-first:0.02 05:11:52 INFO - PID 12707 | Values: 1.7 1.8 1.8 1.8 1.8 1.8 1.8 1.7 1.8 1.7 1.8 1.7 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.74 Median:1.75 stddev:0.02 (1.4%) stddev-sans-first:0.03 05:11:52 INFO - PID 12707 | Values: 1.7 1.8 1.7 1.7 1.7 1.8 1.8 1.7 1.7 1.8 1.8 1.7 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.07 Median:4.08 stddev:0.07 (1.8%) stddev-sans-first:0.07 05:11:52 INFO - PID 12707 | Values: 4.0 4.0 4.0 4.1 4.2 4.2 4.0 4.1 4.1 4.2 4.0 4.1 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.07 Median:4.12 stddev:0.12 (2.8%) stddev-sans-first:0.12 05:11:52 INFO - PID 12707 | Values: 4.1 3.8 4.1 4.0 4.1 4.1 4.2 4.1 4.2 4.0 4.0 4.1 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.49 Median:3.50 stddev:0.08 (2.1%) stddev-sans-first:0.07 05:11:52 INFO - PID 12707 | Values: 3.4 3.6 3.4 3.4 3.4 3.5 3.5 3.5 3.6 3.4 3.5 3.6 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.42 Median:3.42 stddev:0.08 (2.3%) stddev-sans-first:0.08 05:11:52 INFO - PID 12707 | Values: 3.4 3.5 3.4 3.3 3.4 3.4 3.5 3.4 3.5 3.4 3.4 3.5 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.64 Median:5.68 stddev:0.08 (1.4%) stddev-sans-first:0.07 05:11:52 INFO - PID 12707 | Values: 5.5 5.6 5.7 5.6 5.7 5.7 5.7 5.7 5.5 5.8 5.7 5.6 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.51 Median:5.54 stddev:0.09 (1.5%) stddev-sans-first:0.09 05:11:52 INFO - PID 12707 | Values: 5.5 5.5 5.4 5.6 5.7 5.5 5.5 5.6 5.5 5.3 5.5 5.6 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.11 Median:10.55 stddev:0.29 (2.7%) stddev-sans-first:0.27 05:11:52 INFO - PID 12707 | Values: 9.7 10.0 10.0 10.5 10.6 10.4 9.8 10.1 10.0 10.3 9.9 9.9 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:10.04 Median:9.62 stddev:0.41 (4.3%) stddev-sans-first:0.41 05:11:52 INFO - PID 12707 | Values: 9.6 9.7 10.1 9.8 10.1 10.2 9.7 11.0 10.1 9.9 9.8 10.6 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.05 Median:11.07 stddev:0.08 (0.7%) stddev-sans-first:0.09 05:11:52 INFO - PID 12707 | Values: 11.0 11.0 11.1 11.2 11.0 10.9 11.1 11.1 11.2 11.0 11.0 11.1 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.65 Median:10.64 stddev:0.07 (0.6%) stddev-sans-first:0.07 05:11:52 INFO - PID 12707 | Values: 10.7 10.6 10.8 10.5 10.6 10.6 10.6 10.6 10.8 10.6 10.6 10.6 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.47 Median:12.48 stddev:0.16 (1.3%) stddev-sans-first:0.16 05:11:52 INFO - PID 12707 | Values: 12.4 12.5 12.2 12.3 12.6 12.5 12.4 12.6 12.5 12.8 12.3 12.6 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.86 Median:11.91 stddev:0.27 (2.3%) stddev-sans-first:0.29 05:11:52 INFO - PID 12707 | Values: 11.8 11.6 11.8 12.1 11.4 11.6 12.1 12.1 11.6 12.0 11.8 12.3 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.41 Median:11.47 stddev:0.17 (1.5%) stddev-sans-first:0.17 05:11:52 INFO - PID 12707 | Values: 11.6 11.5 11.1 11.6 11.6 11.2 11.5 11.3 11.4 11.4 11.6 11.3 05:11:52 INFO - PID 12707 | 05:11:52 INFO - PID 12707 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.95 Median:10.93 stddev:0.20 (1.8%) stddev-sans-first:0.21 05:11:52 INFO - PID 12707 | Values: 10.9 10.9 10.9 11.2 11.2 10.8 10.9 10.8 10.9 11.0 11.3 10.6 05:11:52 INFO - PID 12707 | -------- Summary: end -------- 05:11:52 INFO - PID 12707 | 05:11:53 INFO - TEST-INFO | 12707: exit 0 05:11:53 INFO - TEST-OK | basic_compositor_video | took 562228ms 05:11:53 INFO - TEST-START | glvideo 05:11:53 INFO - Initialising browser for glvideo test... 05:11:53 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:45017/getInfo.html -profile /tmp/tmpvcnECK/profile 05:11:53 INFO - TEST-INFO | started process 14078 (/builds/slave/test/build/application/firefox/firefox http://localhost:45017/getInfo.html) 05:11:58 INFO - TEST-INFO | 14078: exit 0 05:11:58 INFO - Browser initialized. 05:11:58 INFO - Running cycle 1/1 for glvideo test... 05:11:58 INFO - Using env: {'DISPLAY': ':0', 05:11:58 INFO - 'HOME': '/home/cltbld', 05:11:58 INFO - 'JSGC_DISABLE_POISONING': '1', 05:11:58 INFO - 'LANG': 'en_US.UTF-8', 05:11:58 INFO - 'LANGUAGE': 'en_US:en', 05:11:58 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 05:11:58 INFO - 'LOGNAME': 'cltbld', 05:11:58 INFO - 'MAIL': '/var/mail/cltbld', 05:11:58 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 05:11:58 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 05:11:58 INFO - 'MOZ_CRASHREPORTER': '1', 05:11:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 05:11:58 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 05:11:58 INFO - 'MOZ_NO_REMOTE': '1', 05:11:58 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 05:11:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 05:11:58 INFO - 'NO_EM_RESTART': '1', 05:11:58 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 05:11:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 05:11:58 INFO - 'PWD': '/builds/slave/test', 05:11:58 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 05:11:58 INFO - 'RUST_BACKTRACE': 'full', 05:11:58 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 05:11:58 INFO - 'SHELL': '/bin/bash', 05:11:58 INFO - 'SHLVL': '1', 05:11:58 INFO - 'TERM': 'linux', 05:11:58 INFO - 'TMOUT': '86400', 05:11:58 INFO - 'USER': 'cltbld', 05:11:58 INFO - 'XDG_SESSION_COOKIE': '836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705', 05:11:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 05:11:58 INFO - '_': '/tools/buildbot/bin/python'} 05:11:58 INFO - TEST-INFO | started process 14351 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpvcnECK/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 05:11:59 INFO - PID 14351 | 05:11:59 INFO - PID 14351 | (/builds/slave/test/build/application/firefox/firefox:14401): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 05:11:59 INFO - PID 14351 | 05:12:00 INFO - PID 14351 | [talos glvideo result] Mean tick time across 100 ticks: 6.9422500000000005 ms 05:12:00 INFO - PID 14351 | Cycle 1(1): loaded http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html) 05:12:02 INFO - PID 14351 | [talos glvideo result] Mean tick time across 100 ticks: 6.4792 ms 05:12:02 INFO - PID 14351 | Cycle 1(2): loaded http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html) 05:12:03 INFO - PID 14351 | [talos glvideo result] Mean tick time across 100 ticks: 6.4644 ms 05:12:03 INFO - PID 14351 | Cycle 1(3): loaded http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html) 05:12:04 INFO - PID 14351 | [talos glvideo result] Mean tick time across 100 ticks: 6.526700000000001 ms 05:12:04 INFO - PID 14351 | Cycle 1(4): loaded http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html) 05:12:06 INFO - PID 14351 | [talos glvideo result] Mean tick time across 100 ticks: 6.537100000000001 ms 05:12:06 INFO - PID 14351 | Cycle 1(5): loaded http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45017/tests/webgl/benchmarks/video/video_upload.html) 05:12:06 INFO - PID 14351 | __start_tp_report 05:12:06 INFO - PID 14351 | _x_x_mozilla_page_load 05:12:06 INFO - PID 14351 | _x_x_mozilla_page_load_details 05:12:06 INFO - PID 14351 | |i|pagename|runs| 05:12:06 INFO - PID 14351 | |0;Mean tick time across 100 ticks: ;6.9422500000000005;6.4792;6.4644;6.526700000000001;6.537100000000001 05:12:06 INFO - PID 14351 | __end_tp_report 05:12:06 INFO - PID 14351 | __start_cc_report 05:12:06 INFO - PID 14351 | _x_x_mozilla_cycle_collect,263 05:12:06 INFO - PID 14351 | __end_cc_report 05:12:06 INFO - PID 14351 | __startTimestamp1507464726553__endTimestamp 05:12:06 INFO - PID 14351 | 05:12:06 INFO - PID 14351 | ------- Summary: start ------- 05:12:06 INFO - PID 14351 | Number of tests: 1 05:12:06 INFO - PID 14351 | 05:12:06 INFO - PID 14351 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.59 Median:6.53 stddev:0.20 (3.1%) stddev-sans-first:0.04 05:12:06 INFO - PID 14351 | Values: 6.9 6.5 6.5 6.5 6.5 05:12:06 INFO - PID 14351 | -------- Summary: end -------- 05:12:06 INFO - PID 14351 | 05:12:07 INFO - PID 14351 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 05:12:07 INFO - TEST-INFO | 14351: exit 0 05:12:07 INFO - TEST-OK | glvideo | took 13989ms 05:12:07 INFO - SUITE-END | took 576s 05:12:07 INFO - Completed test suite (00:09:36) 05:12:07 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.5795227645018945, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6764413407821228, 1.690554929577465, 1.6789563514269725, 1.6902535211267604, 1.6856657303370788, 1.6820739910313902, 1.6816872197309418, 1.6835409652076319, 1.685629213483146, 1.6784703579418345, 1.685691011235955, 1.679040290990487], "value": 1.6835409652076319, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6687364470391997, 1.6669083333333337, 1.6715914786967423, 1.6670541666666667, 1.6683986655546288, 1.667775, 1.6673000000000002, 1.6730267558528424, 1.6726003344481604, 1.6676249999999997, 1.6712656641604011, 1.668256880733945], "value": 1.668256880733945, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7304411764705887, 1.7777399289099525, 1.760985915492958, 1.7525759345794392, 1.7892218246869407, 1.7757810650887573, 1.7847114812611542, 1.7445784883720932, 1.7806320474777453, 1.7386500579374276, 1.776204854943754, 1.7362905092592589], "value": 1.7757810650887573, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7470087336244533, 1.7777822222222215, 1.7293301642178054, 1.7185352233676976, 1.7322683982683986, 1.7669787985865726, 1.750139982502187, 1.7170643776824035, 1.7380278019113808, 1.781500445235975, 1.7599648197009674, 1.7095683760683758], "value": 1.7380278019113808, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.995758988015979, 4.037860026917902, 3.958608179419525, 4.082544217687075, 4.174019471488177, 4.156094182825483, 3.9743642384105966, 4.0663279132791335, 4.082972789115645, 4.172475660639778, 4.0444474393531, 4.071906377204885], "value": 4.071906377204885, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.124371134020618, 3.7684463276836158, 4.08187755102041, 4.009849699398799, 4.115884773662551, 4.117242798353912, 4.185533472803346, 4.125257731958763, 4.176252609603343, 4.000350000000002, 3.9526778656126487, 4.124525773195874], "value": 4.115884773662551, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.41000568181818, 3.624064009661838, 3.44105504587156, 3.417272209567198, 3.417135535307516, 3.505105140186915, 3.5009393232205372, 3.5222652582159637, 3.5672592152199747, 3.429251428571428, 3.456198156682027, 3.601926770708284], "value": 3.5009393232205372, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.361848739495797, 3.5285890652557304, 3.351172529313235, 3.3394824707846387, 3.357541946308727, 3.413779863481232, 3.5219190140845082, 3.3739460370994943, 3.496756993006994, 3.379518581081086, 3.4193931623931646, 3.5477216312056754], "value": 3.413779863481232, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.5460905730129415, 5.567894248608536, 5.683134469696969, 5.556092592592587, 5.725734732824427, 5.671474480151227, 5.683645833333333, 5.7044866920152115, 5.545406654343806, 5.769788461538464, 5.66061320754717, 5.598208955223879], "value": 5.671474480151227, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.494642857142855, 5.540387811634344, 5.405824324324331, 5.556833333333341, 5.667110481586406, 5.494587912087909, 5.5417867036011055, 5.5574861111111105, 5.450544959128071, 5.334706666666665, 5.48139726027398, 5.558652777777782], "value": 5.540387811634344, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.74050324675325, 10.002833333333328, 10.034113712374584, 10.490856643356638, 10.604116607773852, 10.417638888888884, 9.805081699346404, 10.138429054054061, 10.034197324414711, 10.345034482758626, 9.872088815789478, 9.869851973684202], "value": 10.034197324414711, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.571267942583734, 9.710388349514563, 10.102727272727273, 9.757780487804883, 10.106388888888882, 10.205892857142873, 9.66183574879227, 10.992637362637362, 10.104494949494962, 9.854433497536949, 9.807034313725483, 10.583042328042326], "value": 10.102727272727273, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.031709558823517, 10.991282051282061, 11.113962962962951, 11.154535315985129, 10.99111721611722, 10.872137681159417, 11.116425925925931, 11.073413284132842, 11.152936802973962, 11.03242647058822, 10.989322344322328, 11.071143911439124], "value": 11.071143911439124, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.696283422459903, 10.64021276595745, 10.756666666666694, 10.53205263157893, 10.641010638297884, 10.583333333333334, 10.640186170212782, 10.639813829787252, 10.753279569892475, 10.643537234042556, 10.586957671957698, 10.642207446808476], "value": 10.64021276595745, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.39973140495868, 12.50147916666668, 12.24502040816326, 12.296311475409818, 12.555564853556481, 12.450394190871362, 12.399462809917349, 12.60533613445378, 12.45201244813277, 12.822286324786328, 12.349753086419774, 12.609663865546212], "value": 12.45201244813277, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.840680473372764, 11.633517441860445, 11.767411764705876, 12.121575757575744, 11.434514285714291, 11.567109826589599, 12.122999999999989, 12.053463855421686, 11.628023255813977, 11.980119760479043, 11.769147058823513, 12.347129629629633], "value": 11.769147058823513, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.584266409266426, 11.497950191570895, 11.113518518518523, 11.584266409266426, 11.583359073359059, 11.152509293680303, 11.451812977099237, 11.321471698113216, 11.365113636363635, 11.366098484848491, 11.628643410852694, 11.322226415094338], "value": 11.366098484848491, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.874347826086943, 10.870624999999999, 10.875869565217371, 11.240477528089889, 11.174748603351949, 10.753924731182774, 10.930191256830632, 10.812810810810825, 10.930382513661213, 10.992609890109884, 11.304604519774017, 10.641622340425531], "value": 10.930191256830632, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.9422500000000005, 6.4792, 6.4644, 6.526700000000001, 6.537100000000001], "value": 6.50295, "unit": "ms"}], "extraOptions": ["e10s"], "name": "glvideo", "alertThreshold": 2.0}]} 05:12:07 INFO - Return code: 0 05:12:07 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 05:12:07 INFO - # TBPL SUCCESS # 05:12:07 INFO - Running post-action listener: _package_coverage_data 05:12:07 INFO - Running post-action listener: _resource_record_post_action 05:12:07 INFO - [mozharness: 2017-10-08 12:12:07.715780Z] Finished run-tests step (success) 05:12:07 INFO - Running post-run listener: _resource_record_post_run 05:12:07 INFO - Total resource usage - Wall time: 595s; CPU: 38.0%; Read bytes: 2805760; Write bytes: 318169088; Read time: 232; Write time: 428240 05:12:07 INFO - TinderboxPrint: CPU usage
38.4% 05:12:07 INFO - TinderboxPrint: I/O read bytes / time
2,805,760 / 232 05:12:07 INFO - TinderboxPrint: I/O write bytes / time
318,169,088 / 428,240 05:12:07 INFO - TinderboxPrint: CPU idle
2,875.6 (61.6%) 05:12:07 INFO - TinderboxPrint: CPU system
299.2 (6.4%) 05:12:07 INFO - TinderboxPrint: CPU user
1,477.3 (31.6%) 05:12:07 INFO - TinderboxPrint: Swap in / out
0 / 0 05:12:07 INFO - install - Wall time: 18s; CPU: 13.0%; Read bytes: 0; Write bytes: 13426688; Read time: 0; Write time: 3124 05:12:07 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 05:12:07 INFO - run-tests - Wall time: 577s; CPU: 39.0%; Read bytes: 2801664; Write bytes: 304283648; Read time: 220; Write time: 425092 05:12:08 INFO - Running post-run listener: _upload_blobber_files 05:12:08 INFO - Blob upload gear active. 05:12:08 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 05:12:08 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 05:12:08 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'] 05:12:08 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 05:12:08 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 05:12:08 INFO - SNIMissingWarning 05:12:08 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 05:12:08 INFO - InsecurePlatformWarning 05:12:08 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.) 05:12:08 INFO - SubjectAltNameWarning 05:12:08 INFO - (blobuploader) - INFO - Open directory for files ... 05:12:08 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 05:12:08 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 05:12:08 INFO - (blobuploader) - INFO - Uploading, attempt #1. 05:12:08 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 05:12:08 INFO - InsecurePlatformWarning 05:12:08 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.) 05:12:08 INFO - SubjectAltNameWarning 05:12:09 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 05:12:09 INFO - InsecurePlatformWarning 05:12:09 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 05:12:09 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 05:12:09 INFO - (blobuploader) - INFO - Done attempting. 05:12:09 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 05:12:09 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 05:12:09 INFO - (blobuploader) - INFO - Uploading, attempt #1. 05:12:09 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 05:12:09 INFO - InsecurePlatformWarning 05:12:09 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.) 05:12:09 INFO - SubjectAltNameWarning 05:12:11 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 05:12:11 INFO - InsecurePlatformWarning 05:12:11 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 05:12:11 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 05:12:11 INFO - (blobuploader) - INFO - Done attempting. 05:12:11 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 05:12:11 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 05:12:11 INFO - (blobuploader) - INFO - Uploading, attempt #1. 05:12:11 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 05:12:11 INFO - InsecurePlatformWarning 05:12:11 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.) 05:12:11 INFO - SubjectAltNameWarning 05:12:11 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 05:12:11 INFO - InsecurePlatformWarning 05:12:12 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 05:12:12 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 05:12:12 INFO - (blobuploader) - INFO - Done attempting. 05:12:12 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 05:12:12 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 05:12:12 INFO - (blobuploader) - INFO - Uploading, attempt #1. 05:12:12 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 05:12:12 INFO - InsecurePlatformWarning 05:12:12 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.) 05:12:12 INFO - SubjectAltNameWarning 05:12:14 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 05:12:14 INFO - InsecurePlatformWarning 05:12:14 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 05:12:14 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 05:12:14 INFO - (blobuploader) - INFO - Done attempting. 05:12:14 INFO - (blobuploader) - INFO - Iteration through files over. 05:12:14 INFO - Return code: 0 05:12:14 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 05:12:14 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 05:12:14 INFO - Setting buildbot property blobber_files to {"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/5dacfc2106023bda5a4de19e2ac506b01dacd6719b0f4bb76fb0c9d678d9401000258acbe5d50f8b8f133bcea60efddb3b9b877d6bf00a47b378e6b3227e0eeb", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/c51ecf4578924b36e2a3c677f4bc364f4d05e1362feaafb1f56b31503f682989846d3685239428d8e673320fef29f44777625374ca689beb0b9e334e7c010b6f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8cb775f1bba0abb465a5f25456ae99753340ffb17006f274c3f243a288b8a2d0b5a8415daf2eba15025ee3cf88c286c96de43ee2ae961c517139e28b693eba2d", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/45fc5354d2a4b547e9a7420d8e6b3975719b3dacc69fedf6885f7a33d0356f83937ab60f44712d112c5d042291b676fc83f41219c274b3d8ef439b58422da940"} 05:12:14 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 05:12:14 INFO - Writing to file /builds/slave/test/properties/blobber_files 05:12:14 INFO - Contents: 05:12:14 INFO - blobber_files:{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/5dacfc2106023bda5a4de19e2ac506b01dacd6719b0f4bb76fb0c9d678d9401000258acbe5d50f8b8f133bcea60efddb3b9b877d6bf00a47b378e6b3227e0eeb", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/c51ecf4578924b36e2a3c677f4bc364f4d05e1362feaafb1f56b31503f682989846d3685239428d8e673320fef29f44777625374ca689beb0b9e334e7c010b6f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8cb775f1bba0abb465a5f25456ae99753340ffb17006f274c3f243a288b8a2d0b5a8415daf2eba15025ee3cf88c286c96de43ee2ae961c517139e28b693eba2d", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/45fc5354d2a4b547e9a7420d8e6b3975719b3dacc69fedf6885f7a33d0356f83937ab60f44712d112c5d042291b676fc83f41219c274b3d8ef439b58422da940"} 05:12:14 INFO - Running post-run listener: copy_logs_to_upload_dir 05:12:14 INFO - Copying logs to upload dir... 05:12:14 INFO - mkdir: /builds/slave/test/build/upload/logs 05:12:14 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=643.952030 ========= master_lag: 0.05 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 44 secs) (at 2017-10-08 05:12:14.724581) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-08 05:12:14.728614) ========= 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=836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705 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/5dacfc2106023bda5a4de19e2ac506b01dacd6719b0f4bb76fb0c9d678d9401000258acbe5d50f8b8f133bcea60efddb3b9b877d6bf00a47b378e6b3227e0eeb", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/c51ecf4578924b36e2a3c677f4bc364f4d05e1362feaafb1f56b31503f682989846d3685239428d8e673320fef29f44777625374ca689beb0b9e334e7c010b6f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8cb775f1bba0abb465a5f25456ae99753340ffb17006f274c3f243a288b8a2d0b5a8415daf2eba15025ee3cf88c286c96de43ee2ae961c517139e28b693eba2d", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/45fc5354d2a4b547e9a7420d8e6b3975719b3dacc69fedf6885f7a33d0356f83937ab60f44712d112c5d042291b676fc83f41219c274b3d8ef439b58422da940"} build_url:https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011270 build_url: 'https://queue.taskcluster.net/v1/task/QsqBukZUQguVt8gnPU9ATA/artifacts/public/build/target.tar.bz2' blobber_files: '{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/5dacfc2106023bda5a4de19e2ac506b01dacd6719b0f4bb76fb0c9d678d9401000258acbe5d50f8b8f133bcea60efddb3b9b877d6bf00a47b378e6b3227e0eeb", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/c51ecf4578924b36e2a3c677f4bc364f4d05e1362feaafb1f56b31503f682989846d3685239428d8e673320fef29f44777625374ca689beb0b9e334e7c010b6f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8cb775f1bba0abb465a5f25456ae99753340ffb17006f274c3f243a288b8a2d0b5a8415daf2eba15025ee3cf88c286c96de43ee2ae961c517139e28b693eba2d", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/45fc5354d2a4b547e9a7420d8e6b3975719b3dacc69fedf6885f7a33d0356f83937ab60f44712d112c5d042291b676fc83f41219c274b3d8ef439b58422da940"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-08 05:12:14.764086) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:12:14.764599) ========= 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=836cfdc75598d54cb747368e000001a9-1507450705.820897-1288019705 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004516 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 05:12:14.847098) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-08 05:12:14.847416) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-08 05:12:14.847725) ========= ========= Total master_lag: 0.29 =========