builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s slave: talos-linux64-ix-011 starttime: 1507198749.61 results: success (0) revision: 53bbdaaa2b8c1819061be26101b075c081b23260 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.611472) ========= master: http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.611876) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.612156) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.652290) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.652546) ========= 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=5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-10-05 03:19:09-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 46.6M=0s 2017-10-05 03:19:09 (46.6 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.131702 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.805560) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.805827) ========= 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=5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.015654 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.856398) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:09.856687) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 53bbdaaa2b8c1819061be26101b075c081b23260 --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 53bbdaaa2b8c1819061be26101b075c081b23260 --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=5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-10-05 03:19:09,924 truncating revision to first 12 chars 2017-10-05 03:19:09,924 Setting DEBUG logging. 2017-10-05 03:19:09,924 attempt 1/10 2017-10-05 03:19:09,924 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/53bbdaaa2b8c?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-10-05 03:19:10,285 unpacking tar archive at: mozilla-central-53bbdaaa2b8c/testing/mozharness/ program finished with exit code 0 elapsedTime=0.627912 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:10.509378) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:10.509640) ========= script_repo_revision: 53bbdaaa2b8c1819061be26101b075c081b23260 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:10.509982) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:10.510237) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-05 03:19:10.524368) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 3 secs) (at 2017-10-05 03:19:10.524624) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox-Non-PGO --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox-Non-PGO in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-stylo-disabled-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox-Non-PGO', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox-Non-PGO'] 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=5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 03:19:10 INFO - MultiFileLogger online at 20171005 03:19:10 in /builds/slave/test 03:19:10 INFO - Run as scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox-Non-PGO --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox-Non-PGO 03:19:10 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 03:19:10 INFO - {'append_to_log': False, 03:19:10 INFO - 'base_work_dir': '/builds/slave/test', 03:19:10 INFO - 'blob_upload_branch': 'Firefox-Non-PGO', 03:19:10 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 03:19:10 INFO - 'branch': 'Firefox-Non-PGO', 03:19:10 INFO - 'buildbot_json_path': 'buildprops.json', 03:19:10 INFO - 'code_coverage': False, 03:19:10 INFO - 'config_files': ('talos/linux_config.py',), 03:19:10 INFO - 'default_actions': ('clobber', 03:19:10 INFO - 'read-buildbot-config', 03:19:10 INFO - 'download-and-extract', 03:19:10 INFO - 'populate-webroot', 03:19:10 INFO - 'create-virtualenv', 03:19:10 INFO - 'install', 03:19:10 INFO - 'setup-mitmproxy', 03:19:10 INFO - 'run-tests'), 03:19:10 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 03:19:10 INFO - 'disable_ccov_upload': False, 03:19:10 INFO - 'disable_stylo': False, 03:19:10 INFO - 'download_minidump_stackwalk': True, 03:19:10 INFO - 'download_symbols': 'ondemand', 03:19:10 INFO - 'enable_stylo': False, 03:19:10 INFO - 'enable_webrender': False, 03:19:10 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 03:19:10 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 03:19:10 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 03:19:10 INFO - 'gecko_profile': False, 03:19:10 INFO - 'gecko_profile_interval': 0, 03:19:10 INFO - 'installer_path': 'installer.exe', 03:19:10 INFO - 'log_level': 'info', 03:19:10 INFO - 'log_name': 'talos', 03:19:10 INFO - 'log_to_console': True, 03:19:10 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 03:19:10 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 03:19:10 INFO - 'opt_config_files': (), 03:19:10 INFO - 'pip_index': False, 03:19:10 INFO - 'suite': 'g4-stylo-disabled-e10s', 03:19:10 INFO - 'system_bits': '32', 03:19:10 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 03:19:10 INFO - 'title': 'talos-linux64-ix-011', 03:19:10 INFO - 'tooltool_cache': '/builds/tooltool_cache', 03:19:10 INFO - 'use_talos_json': True, 03:19:10 INFO - 'verify': 'False', 03:19:10 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 03:19:10 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 03:19:10 INFO - 'work_dir': 'build'} 03:19:10 INFO - [mozharness: 2017-10-05 10:19:10.728266Z] Running clobber step. 03:19:10 INFO - Running pre-action listener: _resource_record_pre_action 03:19:10 INFO - Running main action method: clobber 03:19:10 INFO - rmtree: /builds/slave/test/build 03:19:10 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 03:19:12 INFO - Running post-action listener: _resource_record_post_action 03:19:12 INFO - [mozharness: 2017-10-05 10:19:12.234635Z] Finished clobber step (success) 03:19:12 INFO - [mozharness: 2017-10-05 10:19:12.234733Z] Running read-buildbot-config step. 03:19:12 INFO - Running pre-action listener: _resource_record_pre_action 03:19:12 INFO - Running main action method: read_buildbot_config 03:19:12 INFO - Using buildbot properties: 03:19:12 INFO - { 03:19:12 INFO - "project": "", 03:19:12 INFO - "product": "firefox", 03:19:12 INFO - "who": "archaeopteryx@coole-files.de", 03:19:12 INFO - "installer_path": "public/build/target.tar.bz2", 03:19:12 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s", 03:19:12 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 03:19:12 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central talos g4-stylo-disabled-e10s", 03:19:12 INFO - "stage_platform": "linux64", 03:19:12 INFO - "basedir": "/builds/slave/test", 03:19:12 INFO - "buildnumber": 78, 03:19:12 INFO - "platform": "ubuntu64_hw", 03:19:12 INFO - "master": "http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/", 03:19:12 INFO - "slavebuilddir": "test", 03:19:12 INFO - "taskId": "NSr16TwZQDiK8hlvgHPB0Q", 03:19:12 INFO - "branch": "mozilla-central", 03:19:12 INFO - "script_repo_revision": "production", 03:19:12 INFO - "revision": "53bbdaaa2b8c1819061be26101b075c081b23260", 03:19:12 INFO - "slavename": "talos-linux64-ix-011", 03:19:12 INFO - "repo_path": "mozilla-central" 03:19:12 INFO - } 03:19:12 INFO - Finding installer, test and symbols from parent task. 03:19:12 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/NSr16TwZQDiK8hlvgHPB0Q'}, attempt #1 03:19:12 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/NSr16TwZQDiK8hlvgHPB0Q'}, attempt #1 03:19:13 INFO - Task dependencies: WPmQbSifQt6WX_yxZOEmBw 03:19:13 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw'}, attempt #1 03:19:20 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2 03:19:20 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.test_packages.json 03:19:20 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.crashreporter-symbols.zip 03:19:20 INFO - Running post-action listener: _resource_record_post_action 03:19:20 INFO - [mozharness: 2017-10-05 10:19:20.583779Z] Finished read-buildbot-config step (success) 03:19:20 INFO - [mozharness: 2017-10-05 10:19:20.584000Z] Running download-and-extract step. 03:19:20 INFO - Running pre-action listener: _resource_record_pre_action 03:19:20 INFO - Running main action method: download_and_extract 03:19:20 INFO - mkdir: /builds/slave/test/build/tests 03:19:20 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 03:19:20 INFO - trying https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.test_packages.json 03:19:20 INFO - Downloading https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 03:19:20 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 03:19:21 INFO - Downloaded 989 bytes. 03:19:21 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 03:19:21 INFO - Using the following test package requirements: 03:19:21 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 03:19:21 INFO - u'common': [u'target.common.tests.zip'], 03:19:21 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 03:19:21 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 03:19:21 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 03:19:21 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 03:19:21 INFO - u'mozbase': [u'target.common.tests.zip'], 03:19:21 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 03:19:21 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 03:19:21 INFO - u'web-platform': [u'target.common.tests.zip', 03:19:21 INFO - u'target.web-platform.tests.tar.gz'], 03:19:21 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 03:19:21 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 03:19:21 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.common.tests.zip 03:19:21 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.common.tests.zip'}, attempt #1 03:19:21 INFO - Fetch https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.common.tests.zip into memory 03:19:22 INFO - Content-Length response header: 55311632 03:19:22 INFO - Bytes received: 55311632 03:19:32 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.talos.tests.zip 03:19:32 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.talos.tests.zip'}, attempt #1 03:19:32 INFO - Fetch https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.talos.tests.zip into memory 03:19:33 INFO - Content-Length response header: 14537881 03:19:33 INFO - Bytes received: 14537881 03:19: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')]} 03:19:33 INFO - trying https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2 03:19:33 INFO - Downloading https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 03:19:33 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 03:19:34 INFO - Downloaded 63524487 bytes. 03:19:34 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2 03:19:34 INFO - mkdir: /builds/slave/test/properties 03:19:34 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 03:19:34 INFO - Writing to file /builds/slave/test/properties/build_url 03:19:34 INFO - Contents: 03:19:34 INFO - build_url:https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2 03:19:34 INFO - Running post-action listener: _resource_record_post_action 03:19:34 INFO - Running post-action listener: find_tests_for_verification 03:19:34 INFO - Running post-action listener: set_extra_try_arguments 03:19:34 INFO - [mozharness: 2017-10-05 10:19:34.980511Z] Finished download-and-extract step (success) 03:19:34 INFO - [mozharness: 2017-10-05 10:19:34.980608Z] Running populate-webroot step. 03:19:34 INFO - Running pre-action listener: _resource_record_pre_action 03:19:34 INFO - Running main action method: populate_webroot 03:19:34 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 03:19:34 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['tresize', 03:19:34 INFO - 'tcanvasmark']}, 03:19:34 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 03:19:34 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['dromaeo_css', 03:19:34 INFO - 'kraken']}, 03:19:34 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 03:19:34 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 03:19:34 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'tests': ['damp', 'tps']}, 03:19:34 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['damp', 'tps']}, 03:19:34 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 03:19:34 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['dromaeo_dom']}, 03:19:34 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 03:19:34 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['basic_compositor_video', 03:19:34 INFO - 'glvideo']}, 03:19:34 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 03:19:34 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['ts_paint_webext', 03:19:34 INFO - 'tp5o_webext']}, 03:19:34 INFO - 'other-e10s': {'tests': ['a11yr', 03:19:34 INFO - 'ts_paint', 03:19:34 INFO - 'tpaint', 03:19:34 INFO - 'sessionrestore', 03:19:34 INFO - 'sessionrestore_many_windows', 03:19:34 INFO - 'sessionrestore_no_auto_restore', 03:19:34 INFO - 'tabpaint', 03:19:34 INFO - 'cpstartup']}, 03:19:34 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['a11yr', 03:19:34 INFO - 'ts_paint', 03:19:34 INFO - 'tpaint', 03:19:34 INFO - 'sessionrestore', 03:19:34 INFO - 'sessionrestore_many_windows', 03:19:34 INFO - 'sessionrestore_no_auto_restore', 03:19:34 INFO - 'tabpaint', 03:19:34 INFO - 'cpstartup']}, 03:19:34 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 03:19:34 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 03:19:34 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['perf_reftest_singletons']}, 03:19:34 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['perf_reftest']}, 03:19:34 INFO - 'svgr-e10s': {'tests': ['tsvgx', 03:19:34 INFO - 'tsvgr_opacity', 03:19:34 INFO - 'tart', 03:19:34 INFO - 'tscrollx', 03:19:34 INFO - 'tsvg_static']}, 03:19:34 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['tsvgx', 03:19:34 INFO - 'tsvgr_opacity', 03:19:34 INFO - 'tart', 03:19:34 INFO - 'tscrollx', 03:19:34 INFO - 'tsvg_static']}, 03:19:34 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 03:19:34 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'talos_options': ['--disable-stylo'], 03:19:34 INFO - 'tests': ['tp5o']}, 03:19:34 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 03:19:34 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 03:19:34 INFO - 'talos_options': ['--mitmproxy', 03:19:34 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 03:19:34 INFO - '--firstNonBlankPaint'], 03:19:34 INFO - 'tests': ['tp6_google', 03:19:34 INFO - 'tp6_youtube', 03:19:34 INFO - 'tp6_amazon', 03:19:34 INFO - 'tp6_facebook']}, 03:19:34 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 03:19:34 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 03:19:34 INFO - 'talos_options': ['--disable-stylo', 03:19:34 INFO - '--mitmproxy', 03:19:34 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 03:19:34 INFO - '--firstNonBlankPaint'], 03:19:34 INFO - 'tests': ['tp6_google', 03:19:34 INFO - 'tp6_youtube', 03:19:34 INFO - 'tp6_amazon', 03:19:34 INFO - 'tp6_facebook']}, 03:19:34 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 03:19:34 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 03:19:34 INFO - 'talos_options': ['--stylo-threads=1', 03:19:34 INFO - '--mitmproxy', 03:19:34 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 03:19:34 INFO - '--firstNonBlankPaint'], 03:19:34 INFO - 'tests': ['tp6_google', 03:19:34 INFO - 'tp6_youtube', 03:19:34 INFO - 'tp6_amazon', 03:19:34 INFO - 'tp6_facebook']}, 03:19:34 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'talos_options': ['--xperf_path', 03:19:34 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 03:19:34 INFO - 'tests': ['tp5n']}, 03:19:34 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 03:19:34 INFO - 'talos_options': ['--disable-stylo', 03:19:34 INFO - '--xperf_path', 03:19:34 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 03:19:34 INFO - 'tests': ['tp5n']}}} 03:19:34 INFO - Running post-action listener: _resource_record_post_action 03:19:34 INFO - [mozharness: 2017-10-05 10:19:34.996153Z] Finished populate-webroot step (success) 03:19:34 INFO - [mozharness: 2017-10-05 10:19:34.996243Z] Running create-virtualenv step. 03:19:34 INFO - Running pre-action listener: _resource_record_pre_action 03:19:34 INFO - Running main action method: create_virtualenv 03:19:34 INFO - Creating virtualenv /builds/slave/test/build/venv 03:19:34 INFO - Running command: ['virtualenv', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 03:19:34 INFO - Copy/paste: virtualenv --no-site-packages --distribute /builds/slave/test/build/venv 03:19:34 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 03:19:35 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 03:19:35 INFO - New python executable in /builds/slave/test/build/venv/bin/python 03:19:35 INFO - Installing distribute.............................................................................................................................................................................................done. 03:19:35 INFO - Installing pip...............done. 03:19:35 INFO - Return code: 0 03:19:35 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 03:19:35 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 03:19:36 INFO - Reading from file tmpfile_stdout 03:19:36 INFO - Output received: 03:19:36 INFO - pip 1.1 from /builds/slave/test/build/venv/lib/python2.7/site-packages/pip-1.1-py2.7.egg (python 2.7) 03:19:36 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 03:19:36 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')]} 03:19:36 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19:36 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')]} 03:19:36 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:36 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:36 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 03:19:36 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 03:19:36 INFO - Using env: {'DISPLAY': ':0', 03:19:36 INFO - 'HOME': '/home/cltbld', 03:19:36 INFO - 'LANG': 'en_US.UTF-8', 03:19:36 INFO - 'LANGUAGE': 'en_US:en', 03:19:36 INFO - 'LOGNAME': 'cltbld', 03:19:36 INFO - 'MAIL': '/var/mail/cltbld', 03:19:36 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:36 INFO - 'MOZ_NO_REMOTE': '1', 03:19:36 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:36 INFO - 'NO_EM_RESTART': '1', 03:19:36 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:36 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:36 INFO - 'PWD': '/builds/slave/test', 03:19:36 INFO - 'SHELL': '/bin/bash', 03:19:36 INFO - 'SHLVL': '1', 03:19:36 INFO - 'TERM': 'linux', 03:19:36 INFO - 'TMOUT': '86400', 03:19:36 INFO - 'USER': 'cltbld', 03:19:36 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:36 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:36 INFO - '_': '/tools/buildbot/bin/python'} 03:19:37 INFO - Ignoring indexes: http://pypi.python.org/simple/ 03:19:37 INFO - Downloading/unpacking pip>=1.5 03:19:37 INFO - Running setup.py egg_info for package pip 03:19:37 INFO - warning: no files found matching 'pip/cacert.pem' 03:19:37 INFO - warning: no files found matching '*.html' under directory 'docs' 03:19:37 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 03:19:37 INFO - no previously-included directories found matching 'docs/_build/_sources' 03:19:37 INFO - Installing collected packages: pip 03:19:37 INFO - Found existing installation: pip 1.1 03:19:37 INFO - Uninstalling pip: 03:19:37 INFO - Successfully uninstalled pip 03:19:37 INFO - Running setup.py install for pip 03:19:37 INFO - warning: no files found matching 'pip/cacert.pem' 03:19:37 INFO - warning: no files found matching '*.html' under directory 'docs' 03:19:37 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 03:19:37 INFO - no previously-included directories found matching 'docs/_build/_sources' 03:19:37 INFO - Installing pip script to /builds/slave/test/build/venv/bin 03:19:37 INFO - Installing pip2.7 script to /builds/slave/test/build/venv/bin 03:19:37 INFO - Installing pip2 script to /builds/slave/test/build/venv/bin 03:19:37 INFO - Successfully installed pip 03:19:37 INFO - Cleaning up... 03:19:37 INFO - Return code: 0 03:19:37 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 03:19:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 03:19:37 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19:37 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 03:19:37 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:37 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:37 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 03:19:37 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 03:19:37 INFO - Using env: {'DISPLAY': ':0', 03:19:37 INFO - 'HOME': '/home/cltbld', 03:19:37 INFO - 'LANG': 'en_US.UTF-8', 03:19:37 INFO - 'LANGUAGE': 'en_US:en', 03:19:37 INFO - 'LOGNAME': 'cltbld', 03:19:37 INFO - 'MAIL': '/var/mail/cltbld', 03:19:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:37 INFO - 'MOZ_NO_REMOTE': '1', 03:19:37 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:37 INFO - 'NO_EM_RESTART': '1', 03:19:37 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:37 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:37 INFO - 'PWD': '/builds/slave/test', 03:19:37 INFO - 'SHELL': '/bin/bash', 03:19:37 INFO - 'SHLVL': '1', 03:19:37 INFO - 'TERM': 'linux', 03:19:37 INFO - 'TMOUT': '86400', 03:19:37 INFO - 'USER': 'cltbld', 03:19:37 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:37 INFO - '_': '/tools/buildbot/bin/python'} 03:19:37 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:37 INFO - Downloading/unpacking psutil>=3.1.1 03:19:37 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 03:19:37 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 03:19:37 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 03:19:37 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 03:19:38 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 03:19:38 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 03:19:38 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 03:19:38 INFO - Installing collected packages: psutil 03:19:38 INFO - Running setup.py install for psutil 03:19:38 INFO - building 'psutil._psutil_linux' extension 03:19:38 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 03:19:38 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 03:19:38 INFO - building 'psutil._psutil_posix' extension 03:19:38 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 03:19:39 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 03:19:39 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 03:19:39 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 03:19:39 INFO - Successfully installed psutil 03:19:39 INFO - Cleaning up... 03:19:39 INFO - Return code: 0 03:19:39 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 03:19:39 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')]} 03:19:39 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19:39 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')]} 03:19:39 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:39 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:39 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 03:19:39 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 03:19:39 INFO - Using env: {'DISPLAY': ':0', 03:19:39 INFO - 'HOME': '/home/cltbld', 03:19:39 INFO - 'LANG': 'en_US.UTF-8', 03:19:39 INFO - 'LANGUAGE': 'en_US:en', 03:19:39 INFO - 'LOGNAME': 'cltbld', 03:19:39 INFO - 'MAIL': '/var/mail/cltbld', 03:19:39 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:39 INFO - 'MOZ_NO_REMOTE': '1', 03:19:39 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:39 INFO - 'NO_EM_RESTART': '1', 03:19:39 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:39 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:39 INFO - 'PWD': '/builds/slave/test', 03:19:39 INFO - 'SHELL': '/bin/bash', 03:19:39 INFO - 'SHLVL': '1', 03:19:39 INFO - 'TERM': 'linux', 03:19:39 INFO - 'TMOUT': '86400', 03:19:39 INFO - 'USER': 'cltbld', 03:19:39 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:39 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:39 INFO - '_': '/tools/buildbot/bin/python'} 03:19:39 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:39 INFO - Downloading/unpacking mozsystemmonitor==0.3 03:19:39 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 03:19:39 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 03:19:39 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 03:19:39 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 03:19:40 INFO - Downloading mozsystemmonitor-0.3.tar.gz 03:19:41 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 03:19:41 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 03:19:41 INFO - Installing collected packages: mozsystemmonitor 03:19:41 INFO - Running setup.py install for mozsystemmonitor 03:19:42 INFO - Successfully installed mozsystemmonitor 03:19:42 INFO - Cleaning up... 03:19:42 INFO - Return code: 0 03:19:42 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 03:19:42 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')]} 03:19:42 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19:42 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')]} 03:19:42 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:42 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:42 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 03:19:42 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 03:19:42 INFO - Using env: {'DISPLAY': ':0', 03:19:42 INFO - 'HOME': '/home/cltbld', 03:19:42 INFO - 'LANG': 'en_US.UTF-8', 03:19:42 INFO - 'LANGUAGE': 'en_US:en', 03:19:42 INFO - 'LOGNAME': 'cltbld', 03:19:42 INFO - 'MAIL': '/var/mail/cltbld', 03:19:42 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:42 INFO - 'MOZ_NO_REMOTE': '1', 03:19:42 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:42 INFO - 'NO_EM_RESTART': '1', 03:19:42 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:42 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:42 INFO - 'PWD': '/builds/slave/test', 03:19:42 INFO - 'SHELL': '/bin/bash', 03:19:42 INFO - 'SHLVL': '1', 03:19:42 INFO - 'TERM': 'linux', 03:19:42 INFO - 'TMOUT': '86400', 03:19:42 INFO - 'USER': 'cltbld', 03:19:42 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:42 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:42 INFO - '_': '/tools/buildbot/bin/python'} 03:19:42 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:42 INFO - Downloading/unpacking jsonschema==2.5.1 03:19:42 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 03:19:42 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 03:19:42 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 03:19:42 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 03:19:43 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 03:19:44 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 03:19:44 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 03:19:44 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 03:19:44 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 03:19:44 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 03:19:44 INFO - Downloading functools32-3.2.3-2.tar.gz 03:19:44 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 03:19:44 INFO - warning: no files found matching '*.txt' 03:19:44 INFO - no previously-included directories found matching 'build' 03:19:44 INFO - no previously-included directories found matching 'dist' 03:19:44 INFO - no previously-included directories found matching '.git*' 03:19:44 INFO - Installing collected packages: jsonschema, functools32 03:19:44 INFO - Running setup.py install for functools32 03:19:44 INFO - warning: no files found matching '*.txt' 03:19:44 INFO - no previously-included directories found matching 'build' 03:19:44 INFO - no previously-included directories found matching 'dist' 03:19:44 INFO - no previously-included directories found matching '.git*' 03:19:44 INFO - Successfully installed jsonschema functools32 03:19:44 INFO - Cleaning up... 03:19:44 INFO - Return code: 0 03:19:44 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 03:19:44 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')]} 03:19:44 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19:44 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')]} 03:19:44 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:44 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:44 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 03:19:44 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 03:19:44 INFO - Using env: {'DISPLAY': ':0', 03:19:44 INFO - 'HOME': '/home/cltbld', 03:19:44 INFO - 'LANG': 'en_US.UTF-8', 03:19:44 INFO - 'LANGUAGE': 'en_US:en', 03:19:44 INFO - 'LOGNAME': 'cltbld', 03:19:44 INFO - 'MAIL': '/var/mail/cltbld', 03:19:44 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:44 INFO - 'MOZ_NO_REMOTE': '1', 03:19:44 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:44 INFO - 'NO_EM_RESTART': '1', 03:19:44 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:44 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:44 INFO - 'PWD': '/builds/slave/test', 03:19:44 INFO - 'SHELL': '/bin/bash', 03:19:44 INFO - 'SHLVL': '1', 03:19:44 INFO - 'TERM': 'linux', 03:19:44 INFO - 'TMOUT': '86400', 03:19:44 INFO - 'USER': 'cltbld', 03:19:44 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:44 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:44 INFO - '_': '/tools/buildbot/bin/python'} 03:19:44 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:44 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 03:19:44 INFO - Cleaning up... 03:19:44 INFO - Return code: 0 03:19:44 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 03:19:44 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')]} 03:19:44 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19:44 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')]} 03:19:44 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:44 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:44 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 03:19:44 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 03:19:44 INFO - Using env: {'DISPLAY': ':0', 03:19:44 INFO - 'HOME': '/home/cltbld', 03:19:44 INFO - 'LANG': 'en_US.UTF-8', 03:19:44 INFO - 'LANGUAGE': 'en_US:en', 03:19:44 INFO - 'LOGNAME': 'cltbld', 03:19:44 INFO - 'MAIL': '/var/mail/cltbld', 03:19:44 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:44 INFO - 'MOZ_NO_REMOTE': '1', 03:19:44 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:44 INFO - 'NO_EM_RESTART': '1', 03:19:44 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:44 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:44 INFO - 'PWD': '/builds/slave/test', 03:19:44 INFO - 'SHELL': '/bin/bash', 03:19:44 INFO - 'SHLVL': '1', 03:19:44 INFO - 'TERM': 'linux', 03:19:44 INFO - 'TMOUT': '86400', 03:19:44 INFO - 'USER': 'cltbld', 03:19:44 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:44 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:44 INFO - '_': '/tools/buildbot/bin/python'} 03:19:44 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:44 INFO - Downloading/unpacking blobuploader==1.2.4 03:19:44 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 03:19:44 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 03:19:44 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 03:19:44 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 03:19:45 INFO - Downloading blobuploader-1.2.4.tar.gz 03:19:45 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 03:19:46 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 03:19:46 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 03:19:46 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 03:19:46 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 03:19:46 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 03:19:46 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 03:19:46 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 03:19:46 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 03:19:46 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 03:19:46 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 03:19:46 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 03:19:46 INFO - Downloading docopt-0.6.1.tar.gz 03:19:46 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 03:19:46 INFO - Installing collected packages: blobuploader, requests, docopt 03:19:46 INFO - Running setup.py install for blobuploader 03:19:46 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 03:19:46 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 03:19:46 INFO - Running setup.py install for requests 03:19:47 INFO - Running setup.py install for docopt 03:19:47 INFO - Successfully installed blobuploader requests docopt 03:19:47 INFO - Cleaning up... 03:19:47 INFO - Return code: 0 03:19:47 INFO - Installing None into virtualenv /builds/slave/test/build/venv 03:19: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')]} 03:19:47 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19: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')]} 03:19:47 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:47 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:47 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 03:19:47 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 03:19:47 INFO - Using env: {'DISPLAY': ':0', 03:19:47 INFO - 'HOME': '/home/cltbld', 03:19:47 INFO - 'LANG': 'en_US.UTF-8', 03:19:47 INFO - 'LANGUAGE': 'en_US:en', 03:19:47 INFO - 'LOGNAME': 'cltbld', 03:19:47 INFO - 'MAIL': '/var/mail/cltbld', 03:19:47 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:47 INFO - 'MOZ_NO_REMOTE': '1', 03:19:47 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:47 INFO - 'NO_EM_RESTART': '1', 03:19:47 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:47 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:47 INFO - 'PWD': '/builds/slave/test', 03:19:47 INFO - 'SHELL': '/bin/bash', 03:19:47 INFO - 'SHLVL': '1', 03:19:47 INFO - 'TERM': 'linux', 03:19:47 INFO - 'TMOUT': '86400', 03:19:47 INFO - 'USER': 'cltbld', 03:19:47 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:47 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:47 INFO - '_': '/tools/buildbot/bin/python'} 03:19:47 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 03:19:47 INFO - Running setup.py (path:/tmp/pip-0CMScS-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 03:19:47 INFO - Running setup.py (path:/tmp/pip-Aj40sc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 03:19:47 INFO - Running setup.py (path:/tmp/pip-ZvJFN3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 03:19:47 INFO - Running setup.py (path:/tmp/pip-gQRcJt-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 03:19:47 INFO - Running setup.py (path:/tmp/pip-jKizbx-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 03:19:47 INFO - Running setup.py (path:/tmp/pip-FygRTX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 03:19:47 INFO - Running setup.py (path:/tmp/pip-S_L3Kg-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 03:19:47 INFO - Running setup.py (path:/tmp/pip-N_j9e2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 03:19:47 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 03:19:47 INFO - Running setup.py (path:/tmp/pip-Ixw2uA-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 03:19:48 INFO - Running setup.py (path:/tmp/pip-S3D8Hb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 03:19:48 INFO - Running setup.py (path:/tmp/pip-auqsAI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 03:19:48 INFO - Running setup.py (path:/tmp/pip-bVx6Q_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 03:19:48 INFO - Running setup.py (path:/tmp/pip-M51Aj1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 03:19:48 INFO - Running setup.py (path:/tmp/pip-9zmuOw-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 03:19:48 INFO - Running setup.py (path:/tmp/pip-ecZgr3-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 03:19:48 INFO - Running setup.py (path:/tmp/pip-tdH5Nf-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 03:19:48 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 03:19:48 INFO - Running setup.py (path:/tmp/pip-lqoxpj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 03:19:48 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 03:19:48 INFO - Running setup.py install for manifestparser 03:19:48 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 03:19:48 INFO - Running setup.py install for mozcrash 03:19:48 INFO - Running setup.py install for mozdebug 03:19:48 INFO - Running setup.py install for mozdevice 03:19:48 INFO - Installing dm script to /builds/slave/test/build/venv/bin 03:19:48 INFO - Running setup.py install for mozfile 03:19:49 INFO - Running setup.py install for mozhttpd 03:19:49 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Running setup.py install for mozinfo 03:19:49 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Running setup.py install for mozInstall 03:19:49 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Running setup.py install for mozleak 03:19:49 INFO - Running setup.py install for mozlog 03:19:49 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Running setup.py install for moznetwork 03:19:49 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Running setup.py install for mozprocess 03:19:49 INFO - Running setup.py install for mozprofile 03:19:49 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 03:19:49 INFO - Running setup.py install for mozrunner 03:19:50 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 03:19:50 INFO - Running setup.py install for mozscreenshot 03:19:50 INFO - Running setup.py install for moztest 03:19:50 INFO - Running setup.py install for mozversion 03:19:50 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 03:19:50 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 03:19:50 INFO - Cleaning up... 03:19:50 INFO - Return code: 0 03:19:50 INFO - Installing None into virtualenv /builds/slave/test/build/venv 03:19: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')]} 03:19:50 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19: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')]} 03:19:50 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:50 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:50 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 03:19:50 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 03:19:50 INFO - Using env: {'DISPLAY': ':0', 03:19:50 INFO - 'HOME': '/home/cltbld', 03:19:50 INFO - 'LANG': 'en_US.UTF-8', 03:19:50 INFO - 'LANGUAGE': 'en_US:en', 03:19:50 INFO - 'LOGNAME': 'cltbld', 03:19:50 INFO - 'MAIL': '/var/mail/cltbld', 03:19:50 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:50 INFO - 'MOZ_NO_REMOTE': '1', 03:19:50 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:50 INFO - 'NO_EM_RESTART': '1', 03:19:50 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:50 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:50 INFO - 'PWD': '/builds/slave/test', 03:19:50 INFO - 'SHELL': '/bin/bash', 03:19:50 INFO - 'SHLVL': '1', 03:19:50 INFO - 'TERM': 'linux', 03:19:50 INFO - 'TMOUT': '86400', 03:19:50 INFO - 'USER': 'cltbld', 03:19:50 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:50 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:50 INFO - '_': '/tools/buildbot/bin/python'} 03:19:50 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 03:19:50 INFO - Running setup.py (path:/tmp/pip-ZqCP0E-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 03:19:50 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)) 03:19:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 03:19:50 INFO - Running setup.py (path:/tmp/pip-gZYPYP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 03:19:50 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)) 03:19:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 03:19:50 INFO - Running setup.py (path:/tmp/pip-okXR75-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 03:19:50 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)) 03:19:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 03:19:50 INFO - Running setup.py (path:/tmp/pip-UPPwht-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 03:19:50 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)) 03:19:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 03:19:50 INFO - Running setup.py (path:/tmp/pip-yXfVdk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 03:19:50 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)) 03:19:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 03:19:50 INFO - Running setup.py (path:/tmp/pip-MmjMV6-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 03:19:50 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)) 03:19:50 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 03:19:50 INFO - Running setup.py (path:/tmp/pip-J7biBp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 03:19:51 INFO - Running setup.py (path:/tmp/pip-3L9twG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 03:19:51 INFO - Running setup.py (path:/tmp/pip-F86nkH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 03:19:51 INFO - Running setup.py (path:/tmp/pip-qLJxtE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 03:19:51 INFO - Running setup.py (path:/tmp/pip-zYkppY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 03:19:51 INFO - Running setup.py (path:/tmp/pip-kKmfju-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 03:19:51 INFO - Running setup.py (path:/tmp/pip-AUWhxn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 03:19:51 INFO - Running setup.py (path:/tmp/pip-IHGZQc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 03:19:51 INFO - Running setup.py (path:/tmp/pip-ah5oRj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 03:19:51 INFO - Running setup.py (path:/tmp/pip-6FoqrX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 03:19:51 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)) 03:19:51 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 03:19:51 INFO - Running setup.py (path:/tmp/pip-jUUCur-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 03:19:51 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)) 03:19:51 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)) 03:19:51 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)) 03:19:51 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)) 03:19:51 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)) 03:19:51 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)) 03:19:51 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)) 03:19:51 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 03:19: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 03:19: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 03:19: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 03:19: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 03:19:52 INFO - Downloading blessings-1.6.tar.gz 03:19:52 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 03:19:52 INFO - Installing collected packages: blessings 03:19:52 INFO - Running setup.py install for blessings 03:19:53 INFO - Successfully installed blessings 03:19:53 INFO - Cleaning up... 03:19:53 INFO - Return code: 0 03:19:53 INFO - Done creating virtualenv /builds/slave/test/build/venv. 03:19:53 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 03:19:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 03:19:53 INFO - Reading from file tmpfile_stdout 03:19:53 INFO - Current package versions: 03:19:53 INFO - argparse == 1.2.1 03:19:53 INFO - blessings == 1.6 03:19:53 INFO - blobuploader == 1.2.4 03:19:53 INFO - docopt == 0.6.1 03:19:53 INFO - functools32 == 3.2.3-2 03:19:53 INFO - jsonschema == 2.5.1 03:19:53 INFO - manifestparser == 1.1 03:19:53 INFO - mozInstall == 1.13 03:19:53 INFO - mozcrash == 1.0 03:19:53 INFO - mozdebug == 0.1 03:19:53 INFO - mozdevice == 0.51 03:19:53 INFO - mozfile == 1.2 03:19:53 INFO - mozhttpd == 0.7 03:19:53 INFO - mozinfo == 0.10 03:19:53 INFO - mozleak == 0.1 03:19:53 INFO - mozlog == 3.5 03:19:53 INFO - moznetwork == 0.27 03:19:53 INFO - mozprocess == 0.25 03:19:53 INFO - mozprofile == 0.28 03:19:53 INFO - mozrunner == 6.13 03:19:53 INFO - mozscreenshot == 0.1 03:19:53 INFO - mozsystemmonitor == 0.3 03:19:53 INFO - moztest == 0.8 03:19:53 INFO - mozversion == 1.4 03:19:53 INFO - psutil == 3.1.1 03:19:53 INFO - requests == 1.2.3 03:19:53 INFO - wsgiref == 0.1.2 03:19:53 INFO - Installing None into virtualenv /builds/slave/test/build/venv 03:19: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')]} 03:19:53 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19: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')]} 03:19:53 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:53 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 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:53 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 03:19:53 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 03:19:53 INFO - Using env: {'DISPLAY': ':0', 03:19:53 INFO - 'HOME': '/home/cltbld', 03:19:53 INFO - 'LANG': 'en_US.UTF-8', 03:19:53 INFO - 'LANGUAGE': 'en_US:en', 03:19:53 INFO - 'LOGNAME': 'cltbld', 03:19:53 INFO - 'MAIL': '/var/mail/cltbld', 03:19:53 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:53 INFO - 'MOZ_NO_REMOTE': '1', 03:19:53 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:53 INFO - 'NO_EM_RESTART': '1', 03:19:53 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:53 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:53 INFO - 'PWD': '/builds/slave/test', 03:19:53 INFO - 'SHELL': '/bin/bash', 03:19:53 INFO - 'SHLVL': '1', 03:19:53 INFO - 'TERM': 'linux', 03:19:53 INFO - 'TMOUT': '86400', 03:19:53 INFO - 'USER': 'cltbld', 03:19:53 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:53 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:53 INFO - '_': '/tools/buildbot/bin/python'} 03:19:53 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 03:19:53 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 9)) 03:19:53 INFO - Downloading/unpacking simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 03:19: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 03:19: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 03:19: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 03:19: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 03:19:54 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/simplejson/setup.py) egg_info for package simplejson 03:19:54 INFO - Downloading/unpacking requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 03:19:54 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 03:19:54 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 03:19:54 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 03:19:54 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 03:19:54 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 03:19:54 INFO - warning: no files found matching 'test_requests.py' 03:19:54 INFO - warning: no files found matching 'requirements.txt' 03:19:55 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)) 03:19:55 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)) 03:19:55 INFO - Installing collected packages: simplejson, requests 03:19:55 INFO - Running setup.py install for simplejson 03:19:55 INFO - building 'simplejson._speedups' extension 03:19:55 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 03:19:55 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 03:19:56 INFO - Found existing installation: requests 1.2.3 03:19:56 INFO - Uninstalling requests: 03:19:56 INFO - Successfully uninstalled requests 03:19:56 INFO - Running setup.py install for requests 03:19:56 INFO - warning: no files found matching 'test_requests.py' 03:19:56 INFO - warning: no files found matching 'requirements.txt' 03:19:56 INFO - Successfully installed simplejson requests 03:19:56 INFO - Cleaning up... 03:19:56 INFO - Return code: 0 03:19:56 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 03:19:56 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 03:19:56 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 03:19:56 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 03:19:56 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 03:19:56 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0xf521f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x111ab70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x12bf9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, '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': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', '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 03:19:56 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema'] in /builds/slave/test/build 03:19:56 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema 03:19:56 INFO - Using env: {'DISPLAY': ':0', 03:19:56 INFO - 'HOME': '/home/cltbld', 03:19:56 INFO - 'LANG': 'en_US.UTF-8', 03:19:56 INFO - 'LANGUAGE': 'en_US:en', 03:19:56 INFO - 'LOGNAME': 'cltbld', 03:19:56 INFO - 'MAIL': '/var/mail/cltbld', 03:19:56 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:19:56 INFO - 'MOZ_NO_REMOTE': '1', 03:19:56 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:19:56 INFO - 'NO_EM_RESTART': '1', 03:19:56 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:19:56 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:19:56 INFO - 'PWD': '/builds/slave/test', 03:19:56 INFO - 'SHELL': '/bin/bash', 03:19:56 INFO - 'SHLVL': '1', 03:19:56 INFO - 'TERM': 'linux', 03:19:56 INFO - 'TMOUT': '86400', 03:19:56 INFO - 'USER': 'cltbld', 03:19:56 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:19:56 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:19:56 INFO - '_': '/tools/buildbot/bin/python'} 03:19:56 INFO - Ignoring indexes: https://pypi.python.org/simple/ 03:19:56 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 03:19:56 INFO - Cleaning up... 03:19:56 INFO - Return code: 0 03:19:56 INFO - Running post-action listener: _resource_record_post_action 03:19:56 INFO - Running post-action listener: _start_resource_monitoring 03:19:56 INFO - Starting resource monitoring. 03:19:56 INFO - [mozharness: 2017-10-05 10:19:56.800252Z] Finished create-virtualenv step (success) 03:19:56 INFO - [mozharness: 2017-10-05 10:19:56.800767Z] Running install step. 03:19:56 INFO - Running pre-action listener: _resource_record_pre_action 03:19:56 INFO - Running main action method: install 03:19:56 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 03:19:56 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 03:19:57 INFO - Reading from file tmpfile_stdout 03:19:57 INFO - Detecting whether we're running mozinstall >=1.0... 03:19:57 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 03:19:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 03:19:57 INFO - Reading from file tmpfile_stdout 03:19:57 INFO - Output received: 03:19:57 INFO - Usage: mozinstall [options] installer 03:19:57 INFO - Options: 03:19:57 INFO - -h, --help show this help message and exit 03:19:57 INFO - -d DEST, --destination=DEST 03:19:57 INFO - Directory to install application into. [default: 03:19:57 INFO - "/builds/slave/test"] 03:19:57 INFO - --app=APP Application being installed. [default: firefox] 03:19:57 INFO - mkdir: /builds/slave/test/build/application 03:19:57 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'] 03:19:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 03:20:15 INFO - Reading from file tmpfile_stdout 03:20:15 INFO - Output received: 03:20:15 INFO - /builds/slave/test/build/application/firefox/firefox 03:20:15 INFO - Running post-action listener: _resource_record_post_action 03:20:15 INFO - [mozharness: 2017-10-05 10:20:15.321558Z] Finished install step (success) 03:20:15 INFO - [mozharness: 2017-10-05 10:20:15.321819Z] Running setup-mitmproxy step. 03:20:15 INFO - Running pre-action listener: _resource_record_pre_action 03:20:15 INFO - Running main action method: setup_mitmproxy 03:20:15 INFO - Skipping: mitmproxy is not required 03:20:15 INFO - Running post-action listener: _resource_record_post_action 03:20:15 INFO - [mozharness: 2017-10-05 10:20:15.322958Z] Finished setup-mitmproxy step (success) 03:20:15 INFO - [mozharness: 2017-10-05 10:20:15.323178Z] Running run-tests step. 03:20:15 INFO - Running pre-action listener: _resource_record_pre_action 03:20:15 INFO - Running pre-action listener: _set_gcov_prefix 03:20:15 INFO - Running main action method: run_tests 03:20:15 WARNING - Try message not found. 03:20:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 03:20:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 03:20:15 INFO - Python 2.7.3 03:20:15 INFO - Return code: 0 03:20:15 INFO - grabbing minidump binary from tooltool 03:20:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 03:20:15 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 0x12bcd60>, '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 0x12bda60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x12bdef0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 03:20:15 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 03:20:15 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 03:20:15 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 03:20:15 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 03:20:15 INFO - Return code: 0 03:20:15 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 03:20:15 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 03:20:15 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 03:20:15 INFO - ENV: RUST_BACKTRACE is now full 03:20:15 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 03:20:15 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 03:20:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox-Non-PGO', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-011', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] in /builds/slave/test/build 03:20:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox-Non-PGO --suite g4-stylo-disabled-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-011 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log 03:20:15 INFO - Using env: {'DISPLAY': ':0', 03:20:15 INFO - 'HOME': '/home/cltbld', 03:20:15 INFO - 'LANG': 'en_US.UTF-8', 03:20:15 INFO - 'LANGUAGE': 'en_US:en', 03:20:15 INFO - 'LOGNAME': 'cltbld', 03:20:15 INFO - 'MAIL': '/var/mail/cltbld', 03:20:15 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 03:20:15 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 03:20:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:20:15 INFO - 'MOZ_NO_REMOTE': '1', 03:20:15 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 03:20:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:20:15 INFO - 'NO_EM_RESTART': '1', 03:20:15 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:20:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:20:15 INFO - 'PWD': '/builds/slave/test', 03:20:15 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 03:20:15 INFO - 'RUST_BACKTRACE': 'full', 03:20:15 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 03:20:15 INFO - 'SHELL': '/bin/bash', 03:20:15 INFO - 'SHLVL': '1', 03:20:15 INFO - 'TERM': 'linux', 03:20:15 INFO - 'TMOUT': '86400', 03:20:15 INFO - 'USER': 'cltbld', 03:20:15 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:20:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:20:15 INFO - '_': '/tools/buildbot/bin/python'} 03:20:15 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox-Non-PGO', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-011', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] with output_timeout 3600 03:20:15 INFO - mozversion application_buildid: 20171005085601 03:20:15 INFO - mozversion application_changeset: 53bbdaaa2b8c1819061be26101b075c081b23260 03:20:15 INFO - mozversion application_display_name: Nightly 03:20:15 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 03:20:15 INFO - mozversion application_name: Firefox 03:20:15 INFO - mozversion application_remotingname: firefox 03:20:15 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 03:20:15 INFO - mozversion application_vendor: Mozilla 03:20:15 INFO - mozversion application_version: 58.0a1 03:20:15 INFO - mozversion platform_buildid: 20171005085601 03:20:15 INFO - mozversion platform_changeset: 53bbdaaa2b8c1819061be26101b075c081b23260 03:20:15 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 03:20:15 INFO - mozversion platform_version: 58.0a1 03:20:15 INFO - using testdate: 1507198815 03:20:15 INFO - actual date: 1507198815 03:20:15 INFO - starting webserver on 'localhost:56600' 03:20:15 INFO - SUITE-START | Running 2 tests 03:20:15 INFO - TEST-START | basic_compositor_video 03:20:15 INFO - Initialising browser for basic_compositor_video test... 03:20:15 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:56600/getInfo.html -profile /tmp/tmpzXFeNw/profile 03:20:15 INFO - TEST-INFO | started process 28860 (/builds/slave/test/build/application/firefox/firefox http://localhost:56600/getInfo.html) 03:20:21 INFO - TEST-INFO | 28860: exit 0 03:20:21 INFO - Browser initialized. 03:20:21 INFO - Running cycle 1/1 for basic_compositor_video test... 03:20:21 INFO - Using env: {'DISPLAY': ':0', 03:20:21 INFO - 'HOME': '/home/cltbld', 03:20:21 INFO - 'JSGC_DISABLE_POISONING': '1', 03:20:21 INFO - 'LANG': 'en_US.UTF-8', 03:20:21 INFO - 'LANGUAGE': 'en_US:en', 03:20:21 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 03:20:21 INFO - 'LOGNAME': 'cltbld', 03:20:21 INFO - 'MAIL': '/var/mail/cltbld', 03:20:21 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 03:20:21 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 03:20:21 INFO - 'MOZ_CRASHREPORTER': '1', 03:20:21 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:20:21 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 03:20:21 INFO - 'MOZ_NO_REMOTE': '1', 03:20:21 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 03:20:21 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:20:21 INFO - 'NO_EM_RESTART': '1', 03:20:21 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:20:21 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:20:21 INFO - 'PWD': '/builds/slave/test', 03:20:21 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 03:20:21 INFO - 'RUST_BACKTRACE': 'full', 03:20:21 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 03:20:21 INFO - 'SHELL': '/bin/bash', 03:20:21 INFO - 'SHLVL': '1', 03:20:21 INFO - 'STYLO_FORCE_DISABLED': '1', 03:20:21 INFO - 'TERM': 'linux', 03:20:21 INFO - 'TMOUT': '86400', 03:20:21 INFO - 'USER': 'cltbld', 03:20:21 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:20:21 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:20:21 INFO - '_': '/tools/buildbot/bin/python'} 03:20:21 INFO - TEST-INFO | started process 29130 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpzXFeNw/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 03:20:22 INFO - PID 29130 | 03:20:22 INFO - PID 29130 | (/builds/slave/test/build/application/firefox/firefox:29178): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 03:20:22 INFO - PID 29130 | 03:20:33 INFO - PID 29130 | RSS: Main: 150482944 03:20:33 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6925888324873097 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6713283208020049 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.736475694444445 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7159262435677518 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0833265306122435 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.082806122448981 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.473437500000001 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.395857385398981 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.792277992277988 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.619466292134838 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.617916666666657 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.952910447761212 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.236816479400748 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.699304812834207 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.350370370370367 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.630639534883727 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.586737451737438 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.990961538461557 ms/frame 03:21:19 INFO - PID 29130 | 03:21:19 INFO - PID 29130 | Cycle 1(1): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:21:19 INFO - PID 29130 | RSS: Main: 316030976 03:21:19 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6903380281690144 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6698497495826377 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7927419354838705 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7731737588652485 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.161054091539527 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.158461538461541 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.489023255813953 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3959677419354812 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.672542533081288 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.525193370165743 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.615945512820511 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.348878504672896 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.239475655430708 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.99428571428571 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.821987179487184 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.196006097560955 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.677081712062265 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.929426229508191 ms/frame 03:22:05 INFO - PID 29130 | 03:22:05 INFO - PID 29130 | Cycle 1(2): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:22:05 INFO - PID 29130 | RSS: Main: 320376832 03:22:05 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6867594154019112 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6687698081734783 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.8295000000000001 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7552412280701757 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.161310679611651 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.074154786150713 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.501207701283547 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4310034305317347 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.825407766990289 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.619157303370792 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 10.346637931034488 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.853719211822643 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.410608365019003 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.812783783783813 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.610042016806702 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.0552108433735 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.496800766283528 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.05497237569059 ms/frame 03:22:51 INFO - PID 29130 | 03:22:51 INFO - PID 29130 | Cycle 1(3): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:22:52 INFO - PID 29130 | RSS: Main: 319094784 03:22:52 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6821720852017938 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.677200335289187 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7691096698113207 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.8121240942028993 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.167486111111112 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.229693446088796 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.468531791907513 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4257619863013704 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.630403377110696 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.526077348066295 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.7728990228013 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.133904109589045 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.365890151515142 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.870624999999999 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.400433884297517 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.907529761904785 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.454064885496198 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.872853260869544 ms/frame 03:23:37 INFO - PID 29130 | 03:23:37 INFO - PID 29130 | Cycle 1(4): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:23:38 INFO - PID 29130 | RSS: Main: 321257472 03:23:38 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6915811724915446 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6681609674728937 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.80001799640072 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7780533333333328 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.109678082191781 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.090490797546012 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.4770336037079934 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.379315878378379 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.703802281368823 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.698233618233613 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.96813953488372 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.667077294686004 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.409638783269964 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.932786885245886 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.449792531120337 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.980089820359298 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.452690839694641 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.699278074866307 ms/frame 03:24:23 INFO - PID 29130 | 03:24:23 INFO - PID 29130 | Cycle 1(5): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:24:24 INFO - PID 29130 | RSS: Main: 319397888 03:24:24 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.683804713804714 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.667616666666666 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7776421800947866 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.751611208406305 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.054716216216216 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.185711297071131 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.4606401384083068 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.39557724957555 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.781801541425821 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.466816939890709 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.804526143790842 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.711577669902908 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.408098859315595 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 11.052292817679538 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.824700854700868 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.906994047619047 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.453645038167924 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.11661111111114 ms/frame 03:25:10 INFO - PID 29130 | 03:25:10 INFO - PID 29130 | Cycle 1(6): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:25:10 INFO - PID 29130 | RSS: Main: 319385600 03:25:10 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6866273187183813 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6713032581453635 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7497026239067055 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.748636363636364 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.190216480446927 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.149491701244814 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.489627906976742 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.385465313028767 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.736653919694073 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.699772079772077 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 10.310223367697587 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.348785046728969 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.542615384615392 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.812891891891903 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.247693877551011 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.274294478527603 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.541557692307693 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.929098360655706 ms/frame 03:25:56 INFO - PID 29130 | 03:25:56 INFO - PID 29130 | Cycle 1(7): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:25:56 INFO - PID 29130 | RSS: Main: 319488000 03:25:56 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6924534686971238 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.668390325271059 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7913402985074627 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7701902654867252 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 3.958377308707125 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.133780991735537 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.4850929152148673 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4253510273972583 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.802901353965181 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.558430555555555 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.58686900958466 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.711917475728168 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.195652985074618 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.643085106382987 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.50024999999999 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.837100591715982 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.719550781250007 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.115694444444468 ms/frame 03:26:42 INFO - PID 29130 | 03:26:42 INFO - PID 29130 | Cycle 1(8): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:26:42 INFO - PID 29130 | RSS: Main: 313081856 03:26:42 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.68402076318743 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6710568086883877 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7764594434576675 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7599560246262091 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.144102209944754 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.081693877551018 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.588564593301434 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4969580419580457 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.715190476190481 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.63573239436619 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.464905362776026 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.761658536585363 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.198358208955224 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.873315217391317 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.346296296296302 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.906309523809536 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.539038461538468 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.871141304347791 ms/frame 03:27:28 INFO - PID 29130 | 03:27:28 INFO - PID 29130 | Cycle 1(9): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:27:29 INFO - PID 29130 | RSS: Main: 320651264 03:27:29 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6923040045121263 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6687781484570474 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.8118810386473432 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7958303411131062 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.184748953974895 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.184947698744772 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.6325968523002397 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5471365248227 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.769567307692307 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.668399433427761 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 10.171135593220342 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.132488584474883 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.195074626865667 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.869347826086951 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.609348739495804 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.906309523809492 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.366931818181827 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.816297297297295 ms/frame 03:28:14 INFO - PID 29130 | 03:28:14 INFO - PID 29130 | Cycle 1(10): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:28:15 INFO - PID 29130 | RSS: Main: 320782336 03:28:15 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6837261503928171 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.667116666666667 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7710448642266827 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.793216845878136 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.178955431754875 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.132355371900829 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.4767728852838955 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4139078498293505 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.51590073529412 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.618469101123593 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.968006644518281 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.394718309859158 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.49570881226054 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.930601092896191 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.504124999999991 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.052530120481935 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.63025193798448 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.991565934065955 ms/frame 03:29:00 INFO - PID 29130 | 03:29:00 INFO - PID 29130 | Cycle 1(11): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:29:01 INFO - PID 29130 | RSS: Main: 316227584 03:29:01 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6885734383792912 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6727215719063544 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.789192009540847 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7565935030728703 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_startup = 4.071255088195386 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9688293650793667 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_startup = 3.5717440476190467 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1_inclip = 3.553134991119007 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.576858736059477 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.651440677966104 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_startup = 9.774234527687293 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.480p.60fps.webm_scale_2_inclip = 9.137420091324206 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.629689922480631 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.990137362637332 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.503104166666677 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.906696428571411 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.628953488372108 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.23634831460674 ms/frame 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | Cycle 1(12): loaded http://localhost:56600/tests/video/video_playback.html (next: http://localhost:56600/tests/video/video_playback.html) 03:29:47 INFO - PID 29130 | RSS: Main: 320180224 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | __start_tp_report 03:29:47 INFO - PID 29130 | _x_x_mozilla_page_load 03:29:47 INFO - PID 29130 | _x_x_mozilla_page_load_details 03:29:47 INFO - PID 29130 | |i|pagename|runs| 03:29:47 INFO - PID 29130 | |0;240p.120fps.mp4_scale_1_startup;1.6925888324873097;1.6903380281690144;1.6867594154019112;1.6821720852017938;1.6915811724915446;1.683804713804714;1.6866273187183813;1.6924534686971238;1.68402076318743;1.6923040045121263;1.6837261503928171;1.6885734383792912 03:29:47 INFO - PID 29130 | |1;240p.120fps.mp4_scale_1_inclip;1.6713283208020049;1.6698497495826377;1.6687698081734783;1.677200335289187;1.6681609674728937;1.667616666666666;1.6713032581453635;1.668390325271059;1.6710568086883877;1.6687781484570474;1.667116666666667;1.6727215719063544 03:29:47 INFO - PID 29130 | |2;240p.120fps.mp4_scale_1.1_startup;1.736475694444445;1.7927419354838705;1.8295000000000001;1.7691096698113207;1.80001799640072;1.7776421800947866;1.7497026239067055;1.7913402985074627;1.7764594434576675;1.8118810386473432;1.7710448642266827;1.789192009540847 03:29:47 INFO - PID 29130 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7159262435677518;1.7731737588652485;1.7552412280701757;1.8121240942028993;1.7780533333333328;1.751611208406305;1.748636363636364;1.7701902654867252;1.7599560246262091;1.7958303411131062;1.793216845878136;1.7565935030728703 03:29:47 INFO - PID 29130 | |4;240p.120fps.mp4_scale_2_startup;4.0833265306122435;4.161054091539527;4.161310679611651;4.167486111111112;4.109678082191781;4.054716216216216;4.190216480446927;3.958377308707125;4.144102209944754;4.184748953974895;4.178955431754875;4.071255088195386 03:29:47 INFO - PID 29130 | |5;240p.120fps.mp4_scale_2_inclip;4.082806122448981;4.158461538461541;4.074154786150713;4.229693446088796;4.090490797546012;4.185711297071131;4.149491701244814;4.133780991735537;4.081693877551018;4.184947698744772;4.132355371900829;3.9688293650793667 03:29:47 INFO - PID 29130 | |6;480p.60fps.webm_scale_1_startup;3.473437500000001;3.489023255813953;3.501207701283547;3.468531791907513;3.4770336037079934;3.4606401384083068;3.489627906976742;3.4850929152148673;3.588564593301434;3.6325968523002397;3.4767728852838955;3.5717440476190467 03:29:47 INFO - PID 29130 | |7;480p.60fps.webm_scale_1_inclip;3.395857385398981;3.3959677419354812;3.4310034305317347;3.4257619863013704;3.379315878378379;3.39557724957555;3.385465313028767;3.4253510273972583;3.4969580419580457;3.5471365248227;3.4139078498293505;3.553134991119007 03:29:47 INFO - PID 29130 | |8;480p.60fps.webm_scale_1.1_startup;5.792277992277988;5.672542533081288;5.825407766990289;5.630403377110696;5.703802281368823;5.781801541425821;5.736653919694073;5.802901353965181;5.715190476190481;5.769567307692307;5.51590073529412;5.576858736059477 03:29:47 INFO - PID 29130 | |9;480p.60fps.webm_scale_1.1_inclip;5.619466292134838;5.525193370165743;5.619157303370792;5.526077348066295;5.698233618233613;5.466816939890709;5.699772079772077;5.558430555555555;5.63573239436619;5.668399433427761;5.618469101123593;5.651440677966104 03:29:47 INFO - PID 29130 | |10;480p.60fps.webm_scale_2_startup;9.617916666666657;9.615945512820511;10.346637931034488;9.7728990228013;9.96813953488372;9.804526143790842;10.310223367697587;9.58686900958466;9.464905362776026;10.171135593220342;9.968006644518281;9.774234527687293 03:29:47 INFO - PID 29130 | |11;480p.60fps.webm_scale_2_inclip;9.952910447761212;9.348878504672896;9.853719211822643;9.133904109589045;9.667077294686004;9.711577669902908;9.348785046728969;9.711917475728168;9.761658536585363;9.132488584474883;9.394718309859158;9.137420091324206 03:29:47 INFO - PID 29130 | |12;1080p.60fps.mp4_scale_1_startup;11.236816479400748;11.239475655430708;11.410608365019003;11.365890151515142;11.409638783269964;11.408098859315595;11.542615384615392;11.195652985074618;11.198358208955224;11.195074626865667;11.49570881226054;11.629689922480631 03:29:47 INFO - PID 29130 | |13;1080p.60fps.mp4_scale_1_inclip;10.699304812834207;10.99428571428571;10.812783783783813;10.870624999999999;10.932786885245886;11.052292817679538;10.812891891891903;10.643085106382987;10.873315217391317;10.869347826086951;10.930601092896191;10.990137362637332 03:29:47 INFO - PID 29130 | |14;1080p.60fps.mp4_scale_1.1_startup;12.350370370370367;12.821987179487184;12.610042016806702;12.400433884297517;12.449792531120337;12.824700854700868;12.247693877551011;12.50024999999999;12.346296296296302;12.609348739495804;12.504124999999991;12.503104166666677 03:29:47 INFO - PID 29130 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.630639534883727;12.196006097560955;12.0552108433735;11.907529761904785;11.980089820359298;11.906994047619047;12.274294478527603;11.837100591715982;11.906309523809536;11.906309523809492;12.052530120481935;11.906696428571411 03:29:47 INFO - PID 29130 | |16;1080p.60fps.mp4_scale_2_startup;11.586737451737438;11.677081712062265;11.496800766283528;11.454064885496198;11.452690839694641;11.453645038167924;11.541557692307693;11.719550781250007;11.539038461538468;11.366931818181827;11.63025193798448;11.628953488372108 03:29:47 INFO - PID 29130 | |17;1080p.60fps.mp4_scale_2_inclip;10.990961538461557;10.929426229508191;11.05497237569059;10.872853260869544;10.699278074866307;11.11661111111114;10.929098360655706;11.115694444444468;10.871141304347791;10.816297297297295;10.991565934065955;11.23634831460674 03:29:47 INFO - PID 29130 | __end_tp_report 03:29:47 INFO - PID 29130 | __start_cc_report 03:29:47 INFO - PID 29130 | _x_x_mozilla_cycle_collect,572 03:29:47 INFO - PID 29130 | __end_cc_report 03:29:47 INFO - PID 29130 | __startTimestamp1507199387335__endTimestamp 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | ------- Summary: start ------- 03:29:47 INFO - PID 29130 | Number of tests: 18 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.69 Median:1.69 stddev:0.00 (0.2%) stddev-sans-first:0.00 03:29:47 INFO - PID 29130 | 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 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:1.67 Median:1.67 stddev:0.00 (0.2%) stddev-sans-first:0.00 03:29:47 INFO - PID 29130 | 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 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.78 Median:1.79 stddev:0.03 (1.4%) stddev-sans-first:0.02 03:29:47 INFO - PID 29130 | Values: 1.7 1.8 1.8 1.8 1.8 1.8 1.7 1.8 1.8 1.8 1.8 1.8 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.77 Median:1.77 stddev:0.03 (1.4%) stddev-sans-first:0.02 03:29:47 INFO - PID 29130 | Values: 1.7 1.8 1.8 1.8 1.8 1.8 1.7 1.8 1.8 1.8 1.8 1.8 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.12 Median:4.16 stddev:0.07 (1.7%) stddev-sans-first:0.07 03:29:47 INFO - PID 29130 | Values: 4.1 4.2 4.2 4.2 4.1 4.1 4.2 4.0 4.1 4.2 4.2 4.1 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.12 Median:4.14 stddev:0.07 (1.7%) stddev-sans-first:0.07 03:29:47 INFO - PID 29130 | Values: 4.1 4.2 4.1 4.2 4.1 4.2 4.1 4.1 4.1 4.2 4.1 4.0 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.51 Median:3.49 stddev:0.06 (1.6%) stddev-sans-first:0.06 03:29:47 INFO - PID 29130 | Values: 3.5 3.5 3.5 3.5 3.5 3.5 3.5 3.5 3.6 3.6 3.5 3.6 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.44 Median:3.43 stddev:0.06 (1.8%) stddev-sans-first:0.06 03:29:47 INFO - PID 29130 | Values: 3.4 3.4 3.4 3.4 3.4 3.4 3.4 3.4 3.5 3.5 3.4 3.6 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.71 Median:5.75 stddev:0.10 (1.7%) stddev-sans-first:0.10 03:29:47 INFO - PID 29130 | Values: 5.8 5.7 5.8 5.6 5.7 5.8 5.7 5.8 5.7 5.8 5.5 5.6 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.61 Median:5.63 stddev:0.07 (1.3%) stddev-sans-first:0.08 03:29:47 INFO - PID 29130 | Values: 5.6 5.5 5.6 5.5 5.7 5.5 5.7 5.6 5.6 5.7 5.6 5.7 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:9.87 Median:9.70 stddev:0.29 (3.0%) stddev-sans-first:0.29 03:29:47 INFO - PID 29130 | Values: 9.6 9.6 10.3 9.8 10.0 9.8 10.3 9.6 9.5 10.2 10.0 9.8 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.51 Median:9.69 stddev:0.30 (3.1%) stddev-sans-first:0.28 03:29:47 INFO - PID 29130 | Values: 10.0 9.3 9.9 9.1 9.7 9.7 9.3 9.7 9.8 9.1 9.4 9.1 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.36 Median:11.41 stddev:0.15 (1.3%) stddev-sans-first:0.15 03:29:47 INFO - PID 29130 | Values: 11.2 11.2 11.4 11.4 11.4 11.4 11.5 11.2 11.2 11.2 11.5 11.6 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.87 Median:10.90 stddev:0.12 (1.1%) stddev-sans-first:0.11 03:29:47 INFO - PID 29130 | Values: 10.7 11.0 10.8 10.9 10.9 11.1 10.8 10.6 10.9 10.9 10.9 11.0 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.51 Median:12.50 stddev:0.18 (1.4%) stddev-sans-first:0.18 03:29:47 INFO - PID 29130 | Values: 12.4 12.8 12.6 12.4 12.4 12.8 12.2 12.5 12.3 12.6 12.5 12.5 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.96 Median:11.94 stddev:0.17 (1.4%) stddev-sans-first:0.14 03:29:47 INFO - PID 29130 | Values: 11.6 12.2 12.1 11.9 12.0 11.9 12.3 11.8 11.9 11.9 12.1 11.9 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.55 Median:11.56 stddev:0.11 (0.9%) stddev-sans-first:0.11 03:29:47 INFO - PID 29130 | Values: 11.6 11.7 11.5 11.5 11.5 11.5 11.5 11.7 11.5 11.4 11.6 11.6 03:29:47 INFO - PID 29130 | 03:29:47 INFO - PID 29130 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.97 Median:10.99 stddev:0.15 (1.3%) stddev-sans-first:0.16 03:29:47 INFO - PID 29130 | Values: 11.0 10.9 11.1 10.9 10.7 11.1 10.9 11.1 10.9 10.8 11.0 11.2 03:29:47 INFO - PID 29130 | -------- Summary: end -------- 03:29:47 INFO - PID 29130 | 03:29:47 INFO - TEST-INFO | 29130: exit 0 03:29:47 INFO - TEST-OK | basic_compositor_video | took 572181ms 03:29:47 INFO - TEST-START | glvideo 03:29:47 INFO - Initialising browser for glvideo test... 03:29:47 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:56600/getInfo.html -profile /tmp/tmpNWPsKN/profile 03:29:47 INFO - TEST-INFO | started process 30384 (/builds/slave/test/build/application/firefox/firefox http://localhost:56600/getInfo.html) 03:29:53 INFO - TEST-INFO | 30384: exit 0 03:29:53 INFO - Browser initialized. 03:29:53 INFO - Running cycle 1/1 for glvideo test... 03:29:53 INFO - Using env: {'DISPLAY': ':0', 03:29:53 INFO - 'HOME': '/home/cltbld', 03:29:53 INFO - 'JSGC_DISABLE_POISONING': '1', 03:29:53 INFO - 'LANG': 'en_US.UTF-8', 03:29:53 INFO - 'LANGUAGE': 'en_US:en', 03:29:53 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 03:29:53 INFO - 'LOGNAME': 'cltbld', 03:29:53 INFO - 'MAIL': '/var/mail/cltbld', 03:29:53 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 03:29:53 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 03:29:53 INFO - 'MOZ_CRASHREPORTER': '1', 03:29:53 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 03:29:53 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 03:29:53 INFO - 'MOZ_NO_REMOTE': '1', 03:29:53 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 03:29:53 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 03:29:53 INFO - 'NO_EM_RESTART': '1', 03:29:53 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 03:29:53 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 03:29:53 INFO - 'PWD': '/builds/slave/test', 03:29:53 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 03:29:53 INFO - 'RUST_BACKTRACE': 'full', 03:29:53 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 03:29:53 INFO - 'SHELL': '/bin/bash', 03:29:53 INFO - 'SHLVL': '1', 03:29:53 INFO - 'STYLO_FORCE_DISABLED': '1', 03:29:53 INFO - 'TERM': 'linux', 03:29:53 INFO - 'TMOUT': '86400', 03:29:53 INFO - 'USER': 'cltbld', 03:29:53 INFO - 'XDG_SESSION_COOKIE': '5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387', 03:29:53 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 03:29:53 INFO - '_': '/tools/buildbot/bin/python'} 03:29:53 INFO - TEST-INFO | started process 30659 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpNWPsKN/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 03:29:54 INFO - PID 30659 | 03:29:54 INFO - PID 30659 | (/builds/slave/test/build/application/firefox/firefox:30707): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 03:29:54 INFO - PID 30659 | 03:30:04 INFO - PID 30659 | RSS: Main: 150597632 03:30:04 INFO - PID 30659 | 03:30:06 INFO - PID 30659 | [talos glvideo result] Mean tick time across 100 ticks: 8.96125 ms 03:30:06 INFO - PID 30659 | Cycle 1(1): loaded http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html) 03:30:06 INFO - PID 30659 | RSS: Main: 152064000 03:30:06 INFO - PID 30659 | 03:30:07 INFO - PID 30659 | [talos glvideo result] Mean tick time across 100 ticks: 6.6299 ms 03:30:07 INFO - PID 30659 | Cycle 1(2): loaded http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html) 03:30:08 INFO - PID 30659 | RSS: Main: 151601152 03:30:08 INFO - PID 30659 | 03:30:08 INFO - PID 30659 | [talos glvideo result] Mean tick time across 100 ticks: 6.545050000000001 ms 03:30:08 INFO - PID 30659 | Cycle 1(3): loaded http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html) 03:30:09 INFO - PID 30659 | RSS: Main: 151564288 03:30:09 INFO - PID 30659 | 03:30:10 INFO - PID 30659 | [talos glvideo result] Mean tick time across 100 ticks: 6.527149999999999 ms 03:30:10 INFO - PID 30659 | Cycle 1(4): loaded http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html) 03:30:10 INFO - PID 30659 | RSS: Main: 151908352 03:30:10 INFO - PID 30659 | 03:30:11 INFO - PID 30659 | [talos glvideo result] Mean tick time across 100 ticks: 6.551699999999999 ms 03:30:11 INFO - PID 30659 | Cycle 1(5): loaded http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:56600/tests/webgl/benchmarks/video/video_upload.html) 03:30:11 INFO - PID 30659 | RSS: Main: 152264704 03:30:11 INFO - PID 30659 | 03:30:11 INFO - PID 30659 | __start_tp_report 03:30:11 INFO - PID 30659 | _x_x_mozilla_page_load 03:30:11 INFO - PID 30659 | _x_x_mozilla_page_load_details 03:30:11 INFO - PID 30659 | |i|pagename|runs| 03:30:11 INFO - PID 30659 | |0;Mean tick time across 100 ticks: ;8.96125;6.6299;6.545050000000001;6.527149999999999;6.551699999999999 03:30:11 INFO - PID 30659 | __end_tp_report 03:30:11 INFO - PID 30659 | __start_cc_report 03:30:11 INFO - PID 30659 | _x_x_mozilla_cycle_collect,243 03:30:11 INFO - PID 30659 | __end_cc_report 03:30:11 INFO - PID 30659 | __startTimestamp1507199411755__endTimestamp 03:30:11 INFO - PID 30659 | 03:30:11 INFO - PID 30659 | ------- Summary: start ------- 03:30:11 INFO - PID 30659 | Number of tests: 1 03:30:11 INFO - PID 30659 | 03:30:11 INFO - PID 30659 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:7.04 Median:6.55 stddev:1.07 (16.4%) stddev-sans-first:0.05 03:30:11 INFO - PID 30659 | Values: 9.0 6.6 6.5 6.5 6.6 03:30:11 INFO - PID 30659 | -------- Summary: end -------- 03:30:11 INFO - PID 30659 | 03:30:12 INFO - PID 30659 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 03:30:12 INFO - TEST-INFO | 30659: exit 0 03:30:12 INFO - TEST-OK | glvideo | took 24520ms 03:30:12 INFO - SUITE-END | took 596s 03:30:12 INFO - Completed test suite (00:09:57) 03:30:12 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.59639677019696, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6925888324873097, 1.6903380281690144, 1.6867594154019112, 1.6821720852017938, 1.6915811724915446, 1.683804713804714, 1.6866273187183813, 1.6924534686971238, 1.68402076318743, 1.6923040045121263, 1.6837261503928171, 1.6885734383792912], "value": 1.6867594154019112, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6713283208020049, 1.6698497495826377, 1.6687698081734783, 1.677200335289187, 1.6681609674728937, 1.667616666666666, 1.6713032581453635, 1.668390325271059, 1.6710568086883877, 1.6687781484570474, 1.667116666666667, 1.6727215719063544], "value": 1.6687781484570474, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.736475694444445, 1.7927419354838705, 1.8295000000000001, 1.7691096698113207, 1.80001799640072, 1.7776421800947866, 1.7497026239067055, 1.7913402985074627, 1.7764594434576675, 1.8118810386473432, 1.7710448642266827, 1.789192009540847], "value": 1.789192009540847, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7159262435677518, 1.7731737588652485, 1.7552412280701757, 1.8121240942028993, 1.7780533333333328, 1.751611208406305, 1.748636363636364, 1.7701902654867252, 1.7599560246262091, 1.7958303411131062, 1.793216845878136, 1.7565935030728703], "value": 1.7701902654867252, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.0833265306122435, 4.161054091539527, 4.161310679611651, 4.167486111111112, 4.109678082191781, 4.054716216216216, 4.190216480446927, 3.958377308707125, 4.144102209944754, 4.184748953974895, 4.178955431754875, 4.071255088195386], "value": 4.161054091539527, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.082806122448981, 4.158461538461541, 4.074154786150713, 4.229693446088796, 4.090490797546012, 4.185711297071131, 4.149491701244814, 4.133780991735537, 4.081693877551018, 4.184947698744772, 4.132355371900829, 3.9688293650793667], "value": 4.133780991735537, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.473437500000001, 3.489023255813953, 3.501207701283547, 3.468531791907513, 3.4770336037079934, 3.4606401384083068, 3.489627906976742, 3.4850929152148673, 3.588564593301434, 3.6325968523002397, 3.4767728852838955, 3.5717440476190467], "value": 3.489023255813953, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.395857385398981, 3.3959677419354812, 3.4310034305317347, 3.4257619863013704, 3.379315878378379, 3.39557724957555, 3.385465313028767, 3.4253510273972583, 3.4969580419580457, 3.5471365248227, 3.4139078498293505, 3.553134991119007], "value": 3.4253510273972583, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.792277992277988, 5.672542533081288, 5.825407766990289, 5.630403377110696, 5.703802281368823, 5.781801541425821, 5.736653919694073, 5.802901353965181, 5.715190476190481, 5.769567307692307, 5.51590073529412, 5.576858736059477], "value": 5.715190476190481, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.619466292134838, 5.525193370165743, 5.619157303370792, 5.526077348066295, 5.698233618233613, 5.466816939890709, 5.699772079772077, 5.558430555555555, 5.63573239436619, 5.668399433427761, 5.618469101123593, 5.651440677966104], "value": 5.619157303370792, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.617916666666657, 9.615945512820511, 10.346637931034488, 9.7728990228013, 9.96813953488372, 9.804526143790842, 10.310223367697587, 9.58686900958466, 9.464905362776026, 10.171135593220342, 9.968006644518281, 9.774234527687293], "value": 9.804526143790842, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.952910447761212, 9.348878504672896, 9.853719211822643, 9.133904109589045, 9.667077294686004, 9.711577669902908, 9.348785046728969, 9.711917475728168, 9.761658536585363, 9.132488584474883, 9.394718309859158, 9.137420091324206], "value": 9.394718309859158, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.236816479400748, 11.239475655430708, 11.410608365019003, 11.365890151515142, 11.409638783269964, 11.408098859315595, 11.542615384615392, 11.195652985074618, 11.198358208955224, 11.195074626865667, 11.49570881226054, 11.629689922480631], "value": 11.408098859315595, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.699304812834207, 10.99428571428571, 10.812783783783813, 10.870624999999999, 10.932786885245886, 11.052292817679538, 10.812891891891903, 10.643085106382987, 10.873315217391317, 10.869347826086951, 10.930601092896191, 10.990137362637332], "value": 10.873315217391317, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.350370370370367, 12.821987179487184, 12.610042016806702, 12.400433884297517, 12.449792531120337, 12.824700854700868, 12.247693877551011, 12.50024999999999, 12.346296296296302, 12.609348739495804, 12.504124999999991, 12.503104166666677], "value": 12.503104166666677, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.630639534883727, 12.196006097560955, 12.0552108433735, 11.907529761904785, 11.980089820359298, 11.906994047619047, 12.274294478527603, 11.837100591715982, 11.906309523809536, 11.906309523809492, 12.052530120481935, 11.906696428571411], "value": 11.907529761904785, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.586737451737438, 11.677081712062265, 11.496800766283528, 11.454064885496198, 11.452690839694641, 11.453645038167924, 11.541557692307693, 11.719550781250007, 11.539038461538468, 11.366931818181827, 11.63025193798448, 11.628953488372108], "value": 11.539038461538468, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.990961538461557, 10.929426229508191, 11.05497237569059, 10.872853260869544, 10.699278074866307, 11.11661111111114, 10.929098360655706, 11.115694444444468, 10.871141304347791, 10.816297297297295, 10.991565934065955, 11.23634831460674], "value": 10.929426229508191, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [8.96125, 6.6299, 6.545050000000001, 6.527149999999999, 6.551699999999999], "value": 6.548375, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]} 03:30:12 INFO - Return code: 0 03:30:12 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 03:30:12 INFO - # TBPL SUCCESS # 03:30:12 INFO - Running post-action listener: _package_coverage_data 03:30:12 INFO - Running post-action listener: _resource_record_post_action 03:30:12 INFO - [mozharness: 2017-10-05 10:30:12.910335Z] Finished run-tests step (success) 03:30:12 INFO - Running post-run listener: _resource_record_post_run 03:30:12 INFO - Total resource usage - Wall time: 616s; CPU: 37.0%; Read bytes: 8777728; Write bytes: 324161536; Read time: 784; Write time: 339740 03:30:12 INFO - TinderboxPrint: CPU usage
37.5% 03:30:12 INFO - TinderboxPrint: I/O read bytes / time
8,777,728 / 784 03:30:12 INFO - TinderboxPrint: I/O write bytes / time
324,161,536 / 339,740 03:30:12 INFO - TinderboxPrint: CPU idle
3,026.3 (62.6%) 03:30:12 INFO - TinderboxPrint: CPU system
298.5 (6.2%) 03:30:12 INFO - TinderboxPrint: CPU user
1,497.0 (30.9%) 03:30:12 INFO - TinderboxPrint: Swap in / out
0 / 0 03:30:12 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 13385728; Read time: 0; Write time: 1120 03:30:12 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 03:30:12 INFO - run-tests - Wall time: 598s; CPU: 38.0%; Read bytes: 8773632; Write bytes: 310775808; Read time: 768; Write time: 338620 03:30:13 INFO - Running post-run listener: _upload_blobber_files 03:30:13 INFO - Blob upload gear active. 03:30:13 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 03:30:13 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 03:30:13 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-Non-PGO', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 03:30:13 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-Non-PGO -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 03:30:13 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 03:30:13 INFO - SNIMissingWarning 03:30:13 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 03:30:13 INFO - InsecurePlatformWarning 03:30:13 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.) 03:30:13 INFO - SubjectAltNameWarning 03:30:13 INFO - Traceback (most recent call last): 03:30:13 INFO - File "/builds/slave/test/build/venv/bin/blobberc.py", line 253, in 03:30:13 INFO - main() 03:30:13 INFO - File "/builds/slave/test/build/venv/bin/blobberc.py", line 235, in main 03:30:13 INFO - filetype_whitelist = get_server_whitelist(args['--url']) 03:30:13 INFO - File "/builds/slave/test/build/venv/bin/blobberc.py", line 69, in get_server_whitelist 03:30:13 INFO - return set(response.json().get('whitelist', [])) 03:30:13 INFO - File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/models.py", line 866, in json 03:30:13 INFO - return complexjson.loads(self.text, **kwargs) 03:30:13 INFO - File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/simplejson/__init__.py", line 488, in loads 03:30:13 INFO - return _default_decoder.decode(s) 03:30:13 INFO - File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/simplejson/decoder.py", line 370, in decode 03:30:13 INFO - obj, end = self.raw_decode(s) 03:30:13 INFO - File "/builds/slave/test/build/venv/local/lib/python2.7/site-packages/simplejson/decoder.py", line 389, in raw_decode 03:30:13 INFO - return self.scan_once(s, idx=_w(s, idx).end()) 03:30:13 INFO - simplejson.scanner.JSONDecodeError: Expecting value: line 1 column 1 (char 0) 03:30:13 ERROR - Return code: 1 03:30:13 INFO - Setting buildbot property blobber_files to {} 03:30:13 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 03:30:13 INFO - Writing to file /builds/slave/test/properties/blobber_files 03:30:13 INFO - Contents: 03:30:13 INFO - blobber_files:{} 03:30:13 INFO - Running post-run listener: copy_logs_to_upload_dir 03:30:13 INFO - Copying logs to upload dir... 03:30:13 INFO - mkdir: /builds/slave/test/build/upload/logs 03:30:13 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=663.160970 ========= master_lag: 0.06 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 3 secs) (at 2017-10-05 03:30:13.747168) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-05 03:30:13.754348) ========= 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=5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{} build_url:https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011309 build_url: 'https://queue.taskcluster.net/v1/task/WPmQbSifQt6WX_yxZOEmBw/artifacts/public/build/target.tar.bz2' blobber_files: '{}' ========= master_lag: 0.04 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-05 03:30:13.808545) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:30:13.808874) ========= 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=5cf47e208febbcd81da23b2e0000026f-1507196958.628555-1257308387 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004559 ========= master_lag: 0.05 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-05 03:30:13.858640) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-05 03:30:13.861969) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-05 03:30:13.862268) ========= ========= Total master_lag: 0.23 =========