builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s slave: talos-linux64-ix-048 starttime: 1507446326.32 results: success (0) revision: 5ff0d35d56cd79aa65d4017e1e285e2c5f7ec72a ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.321672) ========= master: http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.322109) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.322387) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.388966) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.389241) ========= 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=fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-10-08 00:05:26-- 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% 225M=0s 2017-10-08 00:05:26 (225 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.090209 ========= master_lag: 0.04 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.522872) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.523190) ========= 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=fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.023320 ========= master_lag: 0.04 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:26.585800) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 12 secs) (at 2017-10-08 00:05:26.586143) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 5ff0d35d56cd79aa65d4017e1e285e2c5f7ec72a --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 5ff0d35d56cd79aa65d4017e1e285e2c5f7ec72a --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=fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-10-08 00:05:26,560 truncating revision to first 12 chars 2017-10-08 00:05:26,560 Setting DEBUG logging. 2017-10-08 00:05:26,560 attempt 1/10 2017-10-08 00:05:26,561 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/5ff0d35d56cd?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-10-08 00:05:26,919 attempt 1/10 2017-10-08 00:05:27,520 current task status: no status available at this point. state: STARTED 2017-10-08 00:05:27,520 sleeping for 11.00s (attempt 1/10) 2017-10-08 00:05:38,532 attempt 2/10 2017-10-08 00:05:38,823 current task status: Task completed! Check 's3_urls' for upload locations. state: SUCCESS 2017-10-08 00:05:39,016 unpacking tar archive at: mozilla-central-5ff0d35d56cd/testing/mozharness/ program finished with exit code 0 elapsedTime=12.796412 ========= master_lag: 0.03 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 12 secs) (at 2017-10-08 00:05:39.414035) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:39.414413) ========= script_repo_revision: 5ff0d35d56cd79aa65d4017e1e285e2c5f7ec72a ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:39.414864) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:39.415147) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-08 00:05:39.436339) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 43 secs) (at 2017-10-08 00:05:39.436717) ========= /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=fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 00:05:39 INFO - MultiFileLogger online at 20171008 00:05:39 in /builds/slave/test 00:05:39 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 00:05:39 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 00:05:39 INFO - {'append_to_log': False, 00:05:39 INFO - 'base_work_dir': '/builds/slave/test', 00:05:39 INFO - 'blob_upload_branch': 'Firefox-Non-PGO', 00:05:39 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 00:05:39 INFO - 'branch': 'Firefox-Non-PGO', 00:05:39 INFO - 'buildbot_json_path': 'buildprops.json', 00:05:39 INFO - 'code_coverage': False, 00:05:39 INFO - 'config_files': ('talos/linux_config.py',), 00:05:39 INFO - 'default_actions': ('clobber', 00:05:39 INFO - 'read-buildbot-config', 00:05:39 INFO - 'download-and-extract', 00:05:39 INFO - 'populate-webroot', 00:05:39 INFO - 'create-virtualenv', 00:05:39 INFO - 'install', 00:05:39 INFO - 'setup-mitmproxy', 00:05:39 INFO - 'run-tests'), 00:05:39 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 00:05:39 INFO - 'disable_ccov_upload': False, 00:05:39 INFO - 'disable_stylo': False, 00:05:39 INFO - 'download_minidump_stackwalk': True, 00:05:39 INFO - 'download_symbols': 'ondemand', 00:05:39 INFO - 'enable_stylo': False, 00:05:39 INFO - 'enable_webrender': False, 00:05:39 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 00:05:39 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 00:05:39 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 00:05:39 INFO - 'gecko_profile': False, 00:05:39 INFO - 'gecko_profile_interval': 0, 00:05:39 INFO - 'installer_path': 'installer.exe', 00:05:39 INFO - 'log_level': 'info', 00:05:39 INFO - 'log_name': 'talos', 00:05:39 INFO - 'log_to_console': True, 00:05:39 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 00:05:39 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 00:05:39 INFO - 'opt_config_files': (), 00:05:39 INFO - 'pip_index': False, 00:05:39 INFO - 'suite': 'g4-stylo-disabled-e10s', 00:05:39 INFO - 'system_bits': '32', 00:05:39 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 00:05:39 INFO - 'title': 'talos-linux64-ix-048', 00:05:39 INFO - 'tooltool_cache': '/builds/tooltool_cache', 00:05:39 INFO - 'use_talos_json': True, 00:05:39 INFO - 'verify': 'False', 00:05:39 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 00:05:39 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 00:05:39 INFO - 'work_dir': 'build'} 00:05:39 INFO - [mozharness: 2017-10-08 07:05:39.550470Z] Running clobber step. 00:05:39 INFO - Running pre-action listener: _resource_record_pre_action 00:05:39 INFO - Running main action method: clobber 00:05:39 INFO - rmtree: /builds/slave/test/build 00:05:39 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 00:05:40 INFO - Running post-action listener: _resource_record_post_action 00:05:40 INFO - [mozharness: 2017-10-08 07:05:40.544175Z] Finished clobber step (success) 00:05:40 INFO - [mozharness: 2017-10-08 07:05:40.544272Z] Running read-buildbot-config step. 00:05:40 INFO - Running pre-action listener: _resource_record_pre_action 00:05:40 INFO - Running main action method: read_buildbot_config 00:05:40 INFO - Using buildbot properties: 00:05:40 INFO - { 00:05:40 INFO - "project": "", 00:05:40 INFO - "product": "firefox", 00:05:40 INFO - "who": "ffxbld@noreply.mozilla.org", 00:05:40 INFO - "installer_path": "public/build/target.tar.bz2", 00:05:40 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s", 00:05:40 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 00:05:40 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central talos g4-stylo-disabled-e10s", 00:05:40 INFO - "stage_platform": "linux64", 00:05:40 INFO - "basedir": "/builds/slave/test", 00:05:40 INFO - "buildnumber": 81, 00:05:40 INFO - "platform": "ubuntu64_hw", 00:05:40 INFO - "master": "http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/", 00:05:40 INFO - "slavebuilddir": "test", 00:05:40 INFO - "taskId": "AWswJSq-Sz60jlybYXIFSw", 00:05:40 INFO - "branch": "mozilla-central", 00:05:40 INFO - "script_repo_revision": "production", 00:05:40 INFO - "revision": "5ff0d35d56cd79aa65d4017e1e285e2c5f7ec72a", 00:05:40 INFO - "slavename": "talos-linux64-ix-048", 00:05:40 INFO - "repo_path": "mozilla-central" 00:05:40 INFO - } 00:05:40 INFO - Finding installer, test and symbols from parent task. 00:05:40 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/AWswJSq-Sz60jlybYXIFSw'}, attempt #1 00:05:40 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/AWswJSq-Sz60jlybYXIFSw'}, attempt #1 00:05:41 INFO - Task dependencies: BRtHMBD2T2aZzIPBWYVDdQ 00:05:41 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ'}, attempt #1 00:05:41 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2 00:05:41 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.test_packages.json 00:05:41 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.crashreporter-symbols.zip 00:05:41 INFO - Running post-action listener: _resource_record_post_action 00:05:41 INFO - [mozharness: 2017-10-08 07:05:41.864710Z] Finished read-buildbot-config step (success) 00:05:41 INFO - [mozharness: 2017-10-08 07:05:41.864930Z] Running download-and-extract step. 00:05:41 INFO - Running pre-action listener: _resource_record_pre_action 00:05:41 INFO - Running main action method: download_and_extract 00:05:41 INFO - mkdir: /builds/slave/test/build/tests 00:05:41 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')]} 00:05:41 INFO - trying https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.test_packages.json 00:05:41 INFO - Downloading https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 00:05:41 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 00:05:42 INFO - Downloaded 989 bytes. 00:05:42 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 00:05:42 INFO - Using the following test package requirements: 00:05:42 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 00:05:42 INFO - u'common': [u'target.common.tests.zip'], 00:05:42 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 00:05:42 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 00:05:42 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 00:05:42 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 00:05:42 INFO - u'mozbase': [u'target.common.tests.zip'], 00:05:42 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 00:05:42 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 00:05:42 INFO - u'web-platform': [u'target.common.tests.zip', 00:05:42 INFO - u'target.web-platform.tests.tar.gz'], 00:05:42 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 00:05:42 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 00:05:42 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.common.tests.zip 00:05:42 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.common.tests.zip'}, attempt #1 00:05:42 INFO - Fetch https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.common.tests.zip into memory 00:05:43 INFO - Content-Length response header: 55318510 00:05:43 INFO - Bytes received: 55318510 00:05:54 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.talos.tests.zip 00:05:54 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.talos.tests.zip'}, attempt #1 00:05:54 INFO - Fetch https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.talos.tests.zip into memory 00:05:55 INFO - Content-Length response header: 14430198 00:05:55 INFO - Bytes received: 14430198 00:05:55 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')]} 00:05:55 INFO - trying https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2 00:05:55 INFO - Downloading https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 00:05:55 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 00:05:56 INFO - Downloaded 61883808 bytes. 00:05:56 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2 00:05:56 INFO - mkdir: /builds/slave/test/properties 00:05:56 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 00:05:56 INFO - Writing to file /builds/slave/test/properties/build_url 00:05:56 INFO - Contents: 00:05:56 INFO - build_url:https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2 00:05:56 INFO - Running post-action listener: _resource_record_post_action 00:05:56 INFO - Running post-action listener: find_tests_for_verification 00:05:56 INFO - Running post-action listener: set_extra_try_arguments 00:05:56 INFO - [mozharness: 2017-10-08 07:05:56.930657Z] Finished download-and-extract step (success) 00:05:56 INFO - [mozharness: 2017-10-08 07:05:56.930824Z] Running populate-webroot step. 00:05:56 INFO - Running pre-action listener: _resource_record_pre_action 00:05:56 INFO - Running main action method: populate_webroot 00:05:56 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 00:05:56 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['tresize', 00:05:56 INFO - 'tcanvasmark']}, 00:05:56 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 00:05:56 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['dromaeo_css', 00:05:56 INFO - 'kraken']}, 00:05:56 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 00:05:56 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 00:05:56 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'tests': ['damp', 'tps']}, 00:05:56 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['damp', 'tps']}, 00:05:56 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 00:05:56 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['dromaeo_dom']}, 00:05:56 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 00:05:56 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['basic_compositor_video', 00:05:56 INFO - 'glvideo']}, 00:05:56 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 00:05:56 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['ts_paint_webext', 00:05:56 INFO - 'tp5o_webext']}, 00:05:56 INFO - 'other-e10s': {'tests': ['a11yr', 00:05:56 INFO - 'ts_paint', 00:05:56 INFO - 'tpaint', 00:05:56 INFO - 'sessionrestore', 00:05:56 INFO - 'sessionrestore_many_windows', 00:05:56 INFO - 'sessionrestore_no_auto_restore', 00:05:56 INFO - 'tabpaint', 00:05:56 INFO - 'cpstartup']}, 00:05:56 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['a11yr', 00:05:56 INFO - 'ts_paint', 00:05:56 INFO - 'tpaint', 00:05:56 INFO - 'sessionrestore', 00:05:56 INFO - 'sessionrestore_many_windows', 00:05:56 INFO - 'sessionrestore_no_auto_restore', 00:05:56 INFO - 'tabpaint', 00:05:56 INFO - 'cpstartup']}, 00:05:56 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 00:05:56 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 00:05:56 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['perf_reftest_singletons']}, 00:05:56 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['perf_reftest']}, 00:05:56 INFO - 'svgr-e10s': {'tests': ['tsvgx', 00:05:56 INFO - 'tsvgr_opacity', 00:05:56 INFO - 'tart', 00:05:56 INFO - 'tscrollx', 00:05:56 INFO - 'tsvg_static']}, 00:05:56 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['tsvgx', 00:05:56 INFO - 'tsvgr_opacity', 00:05:56 INFO - 'tart', 00:05:56 INFO - 'tscrollx', 00:05:56 INFO - 'tsvg_static']}, 00:05:56 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 00:05:56 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'talos_options': ['--disable-stylo'], 00:05:56 INFO - 'tests': ['tp5o']}, 00:05:56 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 00:05:56 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 00:05:56 INFO - 'talos_options': ['--mitmproxy', 00:05:56 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 00:05:56 INFO - '--firstNonBlankPaint'], 00:05:56 INFO - 'tests': ['tp6_google', 00:05:56 INFO - 'tp6_youtube', 00:05:56 INFO - 'tp6_amazon', 00:05:56 INFO - 'tp6_facebook']}, 00:05:56 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 00:05:56 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 00:05:56 INFO - 'talos_options': ['--disable-stylo', 00:05:56 INFO - '--mitmproxy', 00:05:56 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 00:05:56 INFO - '--firstNonBlankPaint'], 00:05:56 INFO - 'tests': ['tp6_google', 00:05:56 INFO - 'tp6_youtube', 00:05:56 INFO - 'tp6_amazon', 00:05:56 INFO - 'tp6_facebook']}, 00:05:56 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 00:05:56 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 00:05:56 INFO - 'talos_options': ['--stylo-threads=1', 00:05:56 INFO - '--mitmproxy', 00:05:56 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 00:05:56 INFO - '--firstNonBlankPaint'], 00:05:56 INFO - 'tests': ['tp6_google', 00:05:56 INFO - 'tp6_youtube', 00:05:56 INFO - 'tp6_amazon', 00:05:56 INFO - 'tp6_facebook']}, 00:05:56 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'talos_options': ['--xperf_path', 00:05:56 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 00:05:56 INFO - 'tests': ['tp5n']}, 00:05:56 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 00:05:56 INFO - 'talos_options': ['--disable-stylo', 00:05:56 INFO - '--xperf_path', 00:05:56 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 00:05:56 INFO - 'tests': ['tp5n']}}} 00:05:56 INFO - Running post-action listener: _resource_record_post_action 00:05:56 INFO - [mozharness: 2017-10-08 07:05:56.948239Z] Finished populate-webroot step (success) 00:05:56 INFO - [mozharness: 2017-10-08 07:05:56.948328Z] Running create-virtualenv step. 00:05:56 INFO - Running pre-action listener: _resource_record_pre_action 00:05:56 INFO - Running main action method: create_virtualenv 00:05:56 INFO - Creating virtualenv /builds/slave/test/build/venv 00:05:56 INFO - Running command: ['virtualenv', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 00:05:56 INFO - Copy/paste: virtualenv --no-site-packages --distribute /builds/slave/test/build/venv 00:05:56 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 00:05:57 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 00:05:57 INFO - New python executable in /builds/slave/test/build/venv/bin/python 00:05:57 INFO - Installing distribute.............................................................................................................................................................................................done. 00:05:57 INFO - Installing pip...............done. 00:05:57 INFO - Return code: 0 00:05:57 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 00:05:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 00:05:57 INFO - Reading from file tmpfile_stdout 00:05:57 INFO - Output received: 00:05:57 INFO - pip 1.1 from /builds/slave/test/build/venv/lib/python2.7/site-packages/pip-1.1-py2.7.egg (python 2.7) 00:05:57 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 00:05:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:05:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:05:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:05:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:05:57 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:05:57 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build 00:05:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5 00:05:57 INFO - Using env: {'DISPLAY': ':0', 00:05:57 INFO - 'HOME': '/home/cltbld', 00:05:57 INFO - 'LANG': 'en_US.UTF-8', 00:05:57 INFO - 'LANGUAGE': 'en_US:en', 00:05:57 INFO - 'LOGNAME': 'cltbld', 00:05:57 INFO - 'MAIL': '/var/mail/cltbld', 00:05:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:05:57 INFO - 'MOZ_NO_REMOTE': '1', 00:05:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:05:57 INFO - 'NO_EM_RESTART': '1', 00:05:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:05:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:05:57 INFO - 'PWD': '/builds/slave/test', 00:05:57 INFO - 'SHELL': '/bin/bash', 00:05:57 INFO - 'SHLVL': '1', 00:05:57 INFO - 'TERM': 'linux', 00:05:57 INFO - 'TMOUT': '86400', 00:05:57 INFO - 'USER': 'cltbld', 00:05:57 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:05:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:05:57 INFO - '_': '/tools/buildbot/bin/python'} 00:05:59 INFO - Ignoring indexes: http://pypi.python.org/simple/ 00:05:59 INFO - Downloading/unpacking pip>=1.5 00:05:59 INFO - Running setup.py egg_info for package pip 00:05:59 INFO - warning: no files found matching 'pip/cacert.pem' 00:05:59 INFO - warning: no files found matching '*.html' under directory 'docs' 00:05:59 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 00:05:59 INFO - no previously-included directories found matching 'docs/_build/_sources' 00:05:59 INFO - Installing collected packages: pip 00:05:59 INFO - Found existing installation: pip 1.1 00:05:59 INFO - Uninstalling pip: 00:05:59 INFO - Successfully uninstalled pip 00:05:59 INFO - Running setup.py install for pip 00:05:59 INFO - warning: no files found matching 'pip/cacert.pem' 00:05:59 INFO - warning: no files found matching '*.html' under directory 'docs' 00:05:59 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 00:05:59 INFO - no previously-included directories found matching 'docs/_build/_sources' 00:05:59 INFO - Installing pip script to /builds/slave/test/build/venv/bin 00:05:59 INFO - Installing pip2.7 script to /builds/slave/test/build/venv/bin 00:05:59 INFO - Installing pip2 script to /builds/slave/test/build/venv/bin 00:05:59 INFO - Successfully installed pip 00:05:59 INFO - Cleaning up... 00:05:59 INFO - Return code: 0 00:05:59 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 00:05:59 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')]} 00:05:59 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:05:59 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')]} 00:05:59 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:05:59 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:05:59 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 00:05:59 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 00:05:59 INFO - Using env: {'DISPLAY': ':0', 00:05:59 INFO - 'HOME': '/home/cltbld', 00:05:59 INFO - 'LANG': 'en_US.UTF-8', 00:05:59 INFO - 'LANGUAGE': 'en_US:en', 00:05:59 INFO - 'LOGNAME': 'cltbld', 00:05:59 INFO - 'MAIL': '/var/mail/cltbld', 00:05:59 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:05:59 INFO - 'MOZ_NO_REMOTE': '1', 00:05:59 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:05:59 INFO - 'NO_EM_RESTART': '1', 00:05:59 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:05:59 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:05:59 INFO - 'PWD': '/builds/slave/test', 00:05:59 INFO - 'SHELL': '/bin/bash', 00:05:59 INFO - 'SHLVL': '1', 00:05:59 INFO - 'TERM': 'linux', 00:05:59 INFO - 'TMOUT': '86400', 00:05:59 INFO - 'USER': 'cltbld', 00:05:59 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:05:59 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:05:59 INFO - '_': '/tools/buildbot/bin/python'} 00:05:59 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:05:59 INFO - Downloading/unpacking psutil>=3.1.1 00:05:59 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:05:59 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:05:59 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:05:59 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:00 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 00:06:00 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 00:06:00 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 00:06:00 INFO - Installing collected packages: psutil 00:06:00 INFO - Running setup.py install for psutil 00:06:00 INFO - building 'psutil._psutil_linux' extension 00:06:00 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 00:06:00 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 00:06:00 INFO - building 'psutil._psutil_posix' extension 00:06:00 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 00:06:01 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 00:06:01 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 00:06:01 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 00:06:01 INFO - Successfully installed psutil 00:06:01 INFO - Cleaning up... 00:06:01 INFO - Return code: 0 00:06:01 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 00:06:01 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')]} 00:06:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06:01 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')]} 00:06:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:01 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:01 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 00:06:01 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 00:06:01 INFO - Using env: {'DISPLAY': ':0', 00:06:01 INFO - 'HOME': '/home/cltbld', 00:06:01 INFO - 'LANG': 'en_US.UTF-8', 00:06:01 INFO - 'LANGUAGE': 'en_US:en', 00:06:01 INFO - 'LOGNAME': 'cltbld', 00:06:01 INFO - 'MAIL': '/var/mail/cltbld', 00:06:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:01 INFO - 'MOZ_NO_REMOTE': '1', 00:06:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:01 INFO - 'NO_EM_RESTART': '1', 00:06:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:01 INFO - 'PWD': '/builds/slave/test', 00:06:01 INFO - 'SHELL': '/bin/bash', 00:06:01 INFO - 'SHLVL': '1', 00:06:01 INFO - 'TERM': 'linux', 00:06:01 INFO - 'TMOUT': '86400', 00:06:01 INFO - 'USER': 'cltbld', 00:06:01 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:01 INFO - '_': '/tools/buildbot/bin/python'} 00:06:01 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:01 INFO - Downloading/unpacking mozsystemmonitor==0.3 00:06:01 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:01 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:01 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:01 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:02 INFO - Downloading mozsystemmonitor-0.3.tar.gz 00:06:02 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 00:06:02 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 00:06:02 INFO - Installing collected packages: mozsystemmonitor 00:06:02 INFO - Running setup.py install for mozsystemmonitor 00:06:03 INFO - Successfully installed mozsystemmonitor 00:06:03 INFO - Cleaning up... 00:06:03 INFO - Return code: 0 00:06:03 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 00:06:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:03 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:03 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:03 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:03 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 00:06:03 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 00:06:03 INFO - Using env: {'DISPLAY': ':0', 00:06:03 INFO - 'HOME': '/home/cltbld', 00:06:03 INFO - 'LANG': 'en_US.UTF-8', 00:06:03 INFO - 'LANGUAGE': 'en_US:en', 00:06:03 INFO - 'LOGNAME': 'cltbld', 00:06:03 INFO - 'MAIL': '/var/mail/cltbld', 00:06:03 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:03 INFO - 'MOZ_NO_REMOTE': '1', 00:06:03 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:03 INFO - 'NO_EM_RESTART': '1', 00:06:03 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:03 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:03 INFO - 'PWD': '/builds/slave/test', 00:06:03 INFO - 'SHELL': '/bin/bash', 00:06:03 INFO - 'SHLVL': '1', 00:06:03 INFO - 'TERM': 'linux', 00:06:03 INFO - 'TMOUT': '86400', 00:06:03 INFO - 'USER': 'cltbld', 00:06:03 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:03 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:03 INFO - '_': '/tools/buildbot/bin/python'} 00:06:04 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:05 INFO - Downloading/unpacking jsonschema==2.5.1 00:06:05 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 00:06:05 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 00:06:05 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 00:06:05 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 00:06:06 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 00:06:06 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 00:06:06 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 00:06:06 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 00:06:06 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 00:06:06 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 00:06:06 INFO - Downloading functools32-3.2.3-2.tar.gz 00:06:06 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 00:06:06 INFO - warning: no files found matching '*.txt' 00:06:06 INFO - no previously-included directories found matching 'build' 00:06:06 INFO - no previously-included directories found matching 'dist' 00:06:06 INFO - no previously-included directories found matching '.git*' 00:06:06 INFO - Installing collected packages: jsonschema, functools32 00:06:06 INFO - Running setup.py install for functools32 00:06:06 INFO - warning: no files found matching '*.txt' 00:06:06 INFO - no previously-included directories found matching 'build' 00:06:06 INFO - no previously-included directories found matching 'dist' 00:06:06 INFO - no previously-included directories found matching '.git*' 00:06:06 INFO - Successfully installed jsonschema functools32 00:06:06 INFO - Cleaning up... 00:06:06 INFO - Return code: 0 00:06:06 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 00:06:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:06 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:06 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:06 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:06 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 00:06:06 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 00:06:06 INFO - Using env: {'DISPLAY': ':0', 00:06:06 INFO - 'HOME': '/home/cltbld', 00:06:06 INFO - 'LANG': 'en_US.UTF-8', 00:06:06 INFO - 'LANGUAGE': 'en_US:en', 00:06:06 INFO - 'LOGNAME': 'cltbld', 00:06:06 INFO - 'MAIL': '/var/mail/cltbld', 00:06:06 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:06 INFO - 'MOZ_NO_REMOTE': '1', 00:06:06 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:06 INFO - 'NO_EM_RESTART': '1', 00:06:06 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:06 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:06 INFO - 'PWD': '/builds/slave/test', 00:06:06 INFO - 'SHELL': '/bin/bash', 00:06:06 INFO - 'SHLVL': '1', 00:06:06 INFO - 'TERM': 'linux', 00:06:06 INFO - 'TMOUT': '86400', 00:06:06 INFO - 'USER': 'cltbld', 00:06:06 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:06 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:06 INFO - '_': '/tools/buildbot/bin/python'} 00:06:07 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:07 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 00:06:07 INFO - Cleaning up... 00:06:07 INFO - Return code: 0 00:06:07 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 00:06:07 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')]} 00:06:07 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06:07 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')]} 00:06:07 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:07 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:07 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 00:06:07 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 00:06:07 INFO - Using env: {'DISPLAY': ':0', 00:06:07 INFO - 'HOME': '/home/cltbld', 00:06:07 INFO - 'LANG': 'en_US.UTF-8', 00:06:07 INFO - 'LANGUAGE': 'en_US:en', 00:06:07 INFO - 'LOGNAME': 'cltbld', 00:06:07 INFO - 'MAIL': '/var/mail/cltbld', 00:06:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:07 INFO - 'MOZ_NO_REMOTE': '1', 00:06:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:07 INFO - 'NO_EM_RESTART': '1', 00:06:07 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:07 INFO - 'PWD': '/builds/slave/test', 00:06:07 INFO - 'SHELL': '/bin/bash', 00:06:07 INFO - 'SHLVL': '1', 00:06:07 INFO - 'TERM': 'linux', 00:06:07 INFO - 'TMOUT': '86400', 00:06:07 INFO - 'USER': 'cltbld', 00:06:07 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:07 INFO - '_': '/tools/buildbot/bin/python'} 00:06:07 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:07 INFO - Downloading/unpacking blobuploader==1.2.4 00:06:07 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:07 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:07 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:07 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:08 INFO - Downloading blobuploader-1.2.4.tar.gz 00:06:08 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 00:06:08 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 00:06:08 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 00:06:08 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 00:06:08 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 00:06:08 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 00:06:08 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 00:06:08 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 00:06:08 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 00:06:08 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 00:06:08 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 00:06:08 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 00:06:08 INFO - Downloading docopt-0.6.1.tar.gz 00:06:08 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 00:06:09 INFO - Installing collected packages: blobuploader, requests, docopt 00:06:09 INFO - Running setup.py install for blobuploader 00:06:09 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 00:06:09 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 00:06:09 INFO - Running setup.py install for requests 00:06:09 INFO - Running setup.py install for docopt 00:06:09 INFO - Successfully installed blobuploader requests docopt 00:06:09 INFO - Cleaning up... 00:06:09 INFO - Return code: 0 00:06:09 INFO - Installing None into virtualenv /builds/slave/test/build/venv 00:06:09 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06:09 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:09 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:09 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 00:06:09 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 00:06:09 INFO - Using env: {'DISPLAY': ':0', 00:06:09 INFO - 'HOME': '/home/cltbld', 00:06:09 INFO - 'LANG': 'en_US.UTF-8', 00:06:09 INFO - 'LANGUAGE': 'en_US:en', 00:06:09 INFO - 'LOGNAME': 'cltbld', 00:06:09 INFO - 'MAIL': '/var/mail/cltbld', 00:06:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:09 INFO - 'MOZ_NO_REMOTE': '1', 00:06:09 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:09 INFO - 'NO_EM_RESTART': '1', 00:06:09 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:09 INFO - 'PWD': '/builds/slave/test', 00:06:09 INFO - 'SHELL': '/bin/bash', 00:06:09 INFO - 'SHLVL': '1', 00:06:09 INFO - 'TERM': 'linux', 00:06:09 INFO - 'TMOUT': '86400', 00:06:09 INFO - 'USER': 'cltbld', 00:06:09 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:09 INFO - '_': '/tools/buildbot/bin/python'} 00:06:09 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:09 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 00:06:09 INFO - Running setup.py (path:/tmp/pip-ZCuMlH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 00:06:09 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 00:06:09 INFO - Running setup.py (path:/tmp/pip-Kn5PT0-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 00:06:09 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 00:06:09 INFO - Running setup.py (path:/tmp/pip-BTGjw9-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 00:06:10 INFO - Running setup.py (path:/tmp/pip-tYQGOK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 00:06:10 INFO - Running setup.py (path:/tmp/pip-PX7vgd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 00:06:10 INFO - Running setup.py (path:/tmp/pip-CMYpSj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 00:06:10 INFO - Running setup.py (path:/tmp/pip-92ooao-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 00:06:10 INFO - Running setup.py (path:/tmp/pip-Lpx7_5-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 00:06:10 INFO - Running setup.py (path:/tmp/pip-YHBE8O-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 00:06:10 INFO - Running setup.py (path:/tmp/pip-2pmaqi-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 00:06:10 INFO - Running setup.py (path:/tmp/pip-h96xKd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 00:06:10 INFO - Running setup.py (path:/tmp/pip-rWIUUG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 00:06:10 INFO - Running setup.py (path:/tmp/pip-oipO61-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 00:06:10 INFO - Running setup.py (path:/tmp/pip-u1LTcl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 00:06:10 INFO - Running setup.py (path:/tmp/pip-l4yhPN-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 00:06:10 INFO - Running setup.py (path:/tmp/pip-Rz1UmE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 00:06:10 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 00:06:10 INFO - Running setup.py (path:/tmp/pip-JkMNCa-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 00:06:11 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 00:06:11 INFO - Running setup.py install for manifestparser 00:06:11 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Running setup.py install for mozcrash 00:06:11 INFO - Running setup.py install for mozdebug 00:06:11 INFO - Running setup.py install for mozdevice 00:06:11 INFO - Installing dm script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Running setup.py install for mozfile 00:06:11 INFO - Running setup.py install for mozhttpd 00:06:11 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Running setup.py install for mozinfo 00:06:11 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Running setup.py install for mozInstall 00:06:11 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 00:06:11 INFO - Running setup.py install for mozleak 00:06:11 INFO - Running setup.py install for mozlog 00:06:12 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 00:06:12 INFO - Running setup.py install for moznetwork 00:06:12 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 00:06:12 INFO - Running setup.py install for mozprocess 00:06:12 INFO - Running setup.py install for mozprofile 00:06:12 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 00:06:12 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 00:06:12 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 00:06:12 INFO - Running setup.py install for mozrunner 00:06:12 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 00:06:12 INFO - Running setup.py install for mozscreenshot 00:06:12 INFO - Running setup.py install for moztest 00:06:12 INFO - Running setup.py install for mozversion 00:06:12 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 00:06:12 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 00:06:12 INFO - Cleaning up... 00:06:12 INFO - Return code: 0 00:06:12 INFO - Installing None into virtualenv /builds/slave/test/build/venv 00:06:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:12 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:12 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 00:06:12 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 00:06:12 INFO - Using env: {'DISPLAY': ':0', 00:06:12 INFO - 'HOME': '/home/cltbld', 00:06:12 INFO - 'LANG': 'en_US.UTF-8', 00:06:12 INFO - 'LANGUAGE': 'en_US:en', 00:06:12 INFO - 'LOGNAME': 'cltbld', 00:06:12 INFO - 'MAIL': '/var/mail/cltbld', 00:06:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:12 INFO - 'MOZ_NO_REMOTE': '1', 00:06:12 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:12 INFO - 'NO_EM_RESTART': '1', 00:06:12 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:12 INFO - 'PWD': '/builds/slave/test', 00:06:12 INFO - 'SHELL': '/bin/bash', 00:06:12 INFO - 'SHLVL': '1', 00:06:12 INFO - 'TERM': 'linux', 00:06:12 INFO - 'TMOUT': '86400', 00:06:12 INFO - 'USER': 'cltbld', 00:06:12 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:12 INFO - '_': '/tools/buildbot/bin/python'} 00:06:13 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 00:06:13 INFO - Running setup.py (path:/tmp/pip-_g0oGp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 00:06:13 INFO - Running setup.py (path:/tmp/pip-Pek1cV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 00:06:13 INFO - Running setup.py (path:/tmp/pip-Q0k8SR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 00:06:13 INFO - Running setup.py (path:/tmp/pip-NzwO0i-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 00:06:13 INFO - Running setup.py (path:/tmp/pip-rpFhCS-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 00:06:13 INFO - Running setup.py (path:/tmp/pip-kSUNCG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 00:06:13 INFO - Running setup.py (path:/tmp/pip-ZXRe5D-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 00:06:13 INFO - Running setup.py (path:/tmp/pip-2Pz6O1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 00:06:13 INFO - Running setup.py (path:/tmp/pip-vfyeea-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 00:06:13 INFO - Running setup.py (path:/tmp/pip-YbRT0Y-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 00:06:13 INFO - Running setup.py (path:/tmp/pip-W0_QuP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 00:06:13 INFO - Running setup.py (path:/tmp/pip-z6Ctvq-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 00:06:13 INFO - Running setup.py (path:/tmp/pip-DWYqGe-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 00:06:13 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)) 00:06:13 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 00:06:13 INFO - Running setup.py (path:/tmp/pip-ygdkgQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 00:06:14 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)) 00:06:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 00:06:14 INFO - Running setup.py (path:/tmp/pip-vN4R0h-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 00:06:14 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)) 00:06:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 00:06:14 INFO - Running setup.py (path:/tmp/pip-roB0Bp-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 00:06:14 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)) 00:06:14 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 00:06:14 INFO - Running setup.py (path:/tmp/pip-ZbaQVx-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 00:06:14 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)) 00:06:14 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)) 00:06:14 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)) 00:06:14 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)) 00:06:14 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)) 00:06:14 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)) 00:06:14 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)) 00:06:14 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 00:06:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:15 INFO - Downloading blessings-1.6.tar.gz 00:06:15 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 00:06:15 INFO - Installing collected packages: blessings 00:06:15 INFO - Running setup.py install for blessings 00:06:15 INFO - Successfully installed blessings 00:06:15 INFO - Cleaning up... 00:06:15 INFO - Return code: 0 00:06:15 INFO - Done creating virtualenv /builds/slave/test/build/venv. 00:06:15 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 00:06:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 00:06:15 INFO - Reading from file tmpfile_stdout 00:06:15 INFO - Current package versions: 00:06:15 INFO - argparse == 1.2.1 00:06:15 INFO - blessings == 1.6 00:06:15 INFO - blobuploader == 1.2.4 00:06:15 INFO - docopt == 0.6.1 00:06:15 INFO - functools32 == 3.2.3-2 00:06:15 INFO - jsonschema == 2.5.1 00:06:15 INFO - manifestparser == 1.1 00:06:15 INFO - mozInstall == 1.13 00:06:15 INFO - mozcrash == 1.0 00:06:15 INFO - mozdebug == 0.1 00:06:15 INFO - mozdevice == 0.51 00:06:15 INFO - mozfile == 1.2 00:06:15 INFO - mozhttpd == 0.7 00:06:15 INFO - mozinfo == 0.10 00:06:15 INFO - mozleak == 0.1 00:06:15 INFO - mozlog == 3.5 00:06:15 INFO - moznetwork == 0.27 00:06:15 INFO - mozprocess == 0.25 00:06:15 INFO - mozprofile == 0.28 00:06:15 INFO - mozrunner == 6.13 00:06:15 INFO - mozscreenshot == 0.1 00:06:15 INFO - mozsystemmonitor == 0.3 00:06:15 INFO - moztest == 0.8 00:06:15 INFO - mozversion == 1.4 00:06:15 INFO - psutil == 3.1.1 00:06:15 INFO - requests == 1.2.3 00:06:15 INFO - wsgiref == 0.1.2 00:06:15 INFO - Installing None into virtualenv /builds/slave/test/build/venv 00:06: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')]} 00:06:15 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06: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')]} 00:06:15 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:15 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:15 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 00:06:15 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 00:06:15 INFO - Using env: {'DISPLAY': ':0', 00:06:15 INFO - 'HOME': '/home/cltbld', 00:06:15 INFO - 'LANG': 'en_US.UTF-8', 00:06:15 INFO - 'LANGUAGE': 'en_US:en', 00:06:15 INFO - 'LOGNAME': 'cltbld', 00:06:15 INFO - 'MAIL': '/var/mail/cltbld', 00:06:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:15 INFO - 'MOZ_NO_REMOTE': '1', 00:06:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:15 INFO - 'NO_EM_RESTART': '1', 00:06:15 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:15 INFO - 'PWD': '/builds/slave/test', 00:06:15 INFO - 'SHELL': '/bin/bash', 00:06:15 INFO - 'SHLVL': '1', 00:06:15 INFO - 'TERM': 'linux', 00:06:15 INFO - 'TMOUT': '86400', 00:06:15 INFO - 'USER': 'cltbld', 00:06:15 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:15 INFO - '_': '/tools/buildbot/bin/python'} 00:06:16 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:16 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)) 00:06:16 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)) 00:06:16 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)) 00:06:16 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)) 00:06:16 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)) 00:06:16 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)) 00:06:16 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)) 00:06:16 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)) 00:06:16 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)) 00:06:16 INFO - Downloading/unpacking simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 00:06:16 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:16 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:16 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:16 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:17 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/simplejson/setup.py) egg_info for package simplejson 00:06:17 INFO - Downloading/unpacking requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 00:06:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 00:06:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 00:06:17 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 00:06:17 INFO - warning: no files found matching 'test_requests.py' 00:06:17 INFO - warning: no files found matching 'requirements.txt' 00:06:17 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)) 00:06:17 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)) 00:06:17 INFO - Installing collected packages: simplejson, requests 00:06:17 INFO - Running setup.py install for simplejson 00:06:17 INFO - building 'simplejson._speedups' extension 00:06:17 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 00:06:18 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 00:06:18 INFO - Found existing installation: requests 1.2.3 00:06:18 INFO - Uninstalling requests: 00:06:18 INFO - Successfully uninstalled requests 00:06:18 INFO - Running setup.py install for requests 00:06:18 INFO - warning: no files found matching 'test_requests.py' 00:06:18 INFO - warning: no files found matching 'requirements.txt' 00:06:19 INFO - Successfully installed simplejson requests 00:06:19 INFO - Cleaning up... 00:06:19 INFO - Return code: 0 00:06:19 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 00:06:19 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:19 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 00:06:19 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 00:06:19 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 00:06:19 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 0xfe11f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x11a9b70>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x134e9c0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, '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': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', '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 00:06:19 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 00:06:19 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 00:06:19 INFO - Using env: {'DISPLAY': ':0', 00:06:19 INFO - 'HOME': '/home/cltbld', 00:06:19 INFO - 'LANG': 'en_US.UTF-8', 00:06:19 INFO - 'LANGUAGE': 'en_US:en', 00:06:19 INFO - 'LOGNAME': 'cltbld', 00:06:19 INFO - 'MAIL': '/var/mail/cltbld', 00:06:19 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:19 INFO - 'MOZ_NO_REMOTE': '1', 00:06:19 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:19 INFO - 'NO_EM_RESTART': '1', 00:06:19 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:19 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:19 INFO - 'PWD': '/builds/slave/test', 00:06:19 INFO - 'SHELL': '/bin/bash', 00:06:19 INFO - 'SHLVL': '1', 00:06:19 INFO - 'TERM': 'linux', 00:06:19 INFO - 'TMOUT': '86400', 00:06:19 INFO - 'USER': 'cltbld', 00:06:19 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:19 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:19 INFO - '_': '/tools/buildbot/bin/python'} 00:06:19 INFO - Ignoring indexes: https://pypi.python.org/simple/ 00:06:19 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 00:06:19 INFO - Cleaning up... 00:06:19 INFO - Return code: 0 00:06:19 INFO - Running post-action listener: _resource_record_post_action 00:06:19 INFO - Running post-action listener: _start_resource_monitoring 00:06:19 INFO - Starting resource monitoring. 00:06:19 INFO - [mozharness: 2017-10-08 07:06:19.316886Z] Finished create-virtualenv step (success) 00:06:19 INFO - [mozharness: 2017-10-08 07:06:19.317408Z] Running install step. 00:06:19 INFO - Running pre-action listener: _resource_record_pre_action 00:06:19 INFO - Running main action method: install 00:06:19 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 00:06:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 00:06:19 INFO - Reading from file tmpfile_stdout 00:06:19 INFO - Detecting whether we're running mozinstall >=1.0... 00:06:19 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 00:06:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 00:06:19 INFO - Reading from file tmpfile_stdout 00:06:19 INFO - Output received: 00:06:19 INFO - Usage: mozinstall [options] installer 00:06:19 INFO - Options: 00:06:19 INFO - -h, --help show this help message and exit 00:06:19 INFO - -d DEST, --destination=DEST 00:06:19 INFO - Directory to install application into. [default: 00:06:19 INFO - "/builds/slave/test"] 00:06:19 INFO - --app=APP Application being installed. [default: firefox] 00:06:19 INFO - mkdir: /builds/slave/test/build/application 00:06:19 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'] 00:06:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 00:06:37 INFO - Reading from file tmpfile_stdout 00:06:37 INFO - Output received: 00:06:37 INFO - /builds/slave/test/build/application/firefox/firefox 00:06:37 INFO - Running post-action listener: _resource_record_post_action 00:06:37 INFO - [mozharness: 2017-10-08 07:06:37.840690Z] Finished install step (success) 00:06:37 INFO - [mozharness: 2017-10-08 07:06:37.840837Z] Running setup-mitmproxy step. 00:06:37 INFO - Running pre-action listener: _resource_record_pre_action 00:06:37 INFO - Running main action method: setup_mitmproxy 00:06:37 INFO - Skipping: mitmproxy is not required 00:06:37 INFO - Running post-action listener: _resource_record_post_action 00:06:37 INFO - [mozharness: 2017-10-08 07:06:37.841367Z] Finished setup-mitmproxy step (success) 00:06:37 INFO - [mozharness: 2017-10-08 07:06:37.841471Z] Running run-tests step. 00:06:37 INFO - Running pre-action listener: _resource_record_pre_action 00:06:37 INFO - Running pre-action listener: _set_gcov_prefix 00:06:37 INFO - Running main action method: run_tests 00:06:37 WARNING - Try message not found. 00:06:37 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 00:06:37 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 00:06:37 INFO - Python 2.7.3 00:06:37 INFO - Return code: 0 00:06:37 INFO - grabbing minidump binary from tooltool 00:06: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')]} 00:06:37 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 0x134bd60>, '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 0x134ca60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x134cef0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 00:06:37 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 00:06:37 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 00:06:37 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 00:06:37 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 00:06:37 INFO - Return code: 0 00:06:37 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 00:06:37 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 00:06:37 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 00:06:37 INFO - ENV: RUST_BACKTRACE is now full 00:06:37 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 00:06:37 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 00:06:37 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/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-048', '--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 00:06:37 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/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-048 --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 00:06:37 INFO - Using env: {'DISPLAY': ':0', 00:06:37 INFO - 'HOME': '/home/cltbld', 00:06:37 INFO - 'LANG': 'en_US.UTF-8', 00:06:37 INFO - 'LANGUAGE': 'en_US:en', 00:06:37 INFO - 'LOGNAME': 'cltbld', 00:06:37 INFO - 'MAIL': '/var/mail/cltbld', 00:06:37 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 00:06:37 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 00:06:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:37 INFO - 'MOZ_NO_REMOTE': '1', 00:06:37 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 00:06:37 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:37 INFO - 'NO_EM_RESTART': '1', 00:06:37 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:37 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:37 INFO - 'PWD': '/builds/slave/test', 00:06:37 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 00:06:37 INFO - 'RUST_BACKTRACE': 'full', 00:06:37 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 00:06:37 INFO - 'SHELL': '/bin/bash', 00:06:37 INFO - 'SHLVL': '1', 00:06:37 INFO - 'TERM': 'linux', 00:06:37 INFO - 'TMOUT': '86400', 00:06:37 INFO - 'USER': 'cltbld', 00:06:37 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:37 INFO - '_': '/tools/buildbot/bin/python'} 00:06:37 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/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-048', '--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 00:06:38 INFO - mozversion application_buildid: 20171008060810 00:06:38 INFO - mozversion application_changeset: 5ff0d35d56cd79aa65d4017e1e285e2c5f7ec72a 00:06:38 INFO - mozversion application_display_name: Nightly 00:06:38 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 00:06:38 INFO - mozversion application_name: Firefox 00:06:38 INFO - mozversion application_remotingname: firefox 00:06:38 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 00:06:38 INFO - mozversion application_vendor: Mozilla 00:06:38 INFO - mozversion application_version: 58.0a1 00:06:38 INFO - mozversion platform_buildid: 20171008060810 00:06:38 INFO - mozversion platform_changeset: 5ff0d35d56cd79aa65d4017e1e285e2c5f7ec72a 00:06:38 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 00:06:38 INFO - mozversion platform_version: 58.0a1 00:06:38 INFO - using testdate: 1507446398 00:06:38 INFO - actual date: 1507446398 00:06:38 INFO - starting webserver on 'localhost:50958' 00:06:38 INFO - SUITE-START | Running 2 tests 00:06:38 INFO - TEST-START | basic_compositor_video 00:06:38 INFO - Initialising browser for basic_compositor_video test... 00:06:38 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:50958/getInfo.html -profile /tmp/tmpJnXZnS/profile 00:06:38 INFO - TEST-INFO | started process 16722 (/builds/slave/test/build/application/firefox/firefox http://localhost:50958/getInfo.html) 00:06:44 INFO - TEST-INFO | 16722: exit 0 00:06:45 INFO - Browser initialized. 00:06:45 INFO - Running cycle 1/1 for basic_compositor_video test... 00:06:45 INFO - Using env: {'DISPLAY': ':0', 00:06:45 INFO - 'HOME': '/home/cltbld', 00:06:45 INFO - 'JSGC_DISABLE_POISONING': '1', 00:06:45 INFO - 'LANG': 'en_US.UTF-8', 00:06:45 INFO - 'LANGUAGE': 'en_US:en', 00:06:45 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 00:06:45 INFO - 'LOGNAME': 'cltbld', 00:06:45 INFO - 'MAIL': '/var/mail/cltbld', 00:06:45 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 00:06:45 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 00:06:45 INFO - 'MOZ_CRASHREPORTER': '1', 00:06:45 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:06:45 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 00:06:45 INFO - 'MOZ_NO_REMOTE': '1', 00:06:45 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 00:06:45 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:06:45 INFO - 'NO_EM_RESTART': '1', 00:06:45 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:06:45 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:06:45 INFO - 'PWD': '/builds/slave/test', 00:06:45 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 00:06:45 INFO - 'RUST_BACKTRACE': 'full', 00:06:45 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 00:06:45 INFO - 'SHELL': '/bin/bash', 00:06:45 INFO - 'SHLVL': '1', 00:06:45 INFO - 'STYLO_FORCE_DISABLED': '1', 00:06:45 INFO - 'TERM': 'linux', 00:06:45 INFO - 'TMOUT': '86400', 00:06:45 INFO - 'USER': 'cltbld', 00:06:45 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:06:45 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:06:45 INFO - '_': '/tools/buildbot/bin/python'} 00:06:45 INFO - TEST-INFO | started process 16955 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpJnXZnS/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 00:06:45 INFO - PID 16955 | 00:06:45 INFO - PID 16955 | (/builds/slave/test/build/application/firefox/firefox:17003): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 00:06:45 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6850224592925322 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6671375 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.777535545023697 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.756479367866549 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.145110497237571 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.098616803278689 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.663968253968257 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3899915254237247 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.386867145421904 ms/frame 00:07:32 INFO - PID 16955 | 00:07:32 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.435108695652171 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.407445141065837 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.010945945945947 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.542269230769238 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.815810810810786 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.198353658536579 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.770294117647085 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.495038314176252 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.753279569892475 ms/frame 00:07:33 INFO - PID 16955 | 00:07:33 INFO - PID 16955 | Cycle 1(1): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:08:19 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6803247480403136 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6697078464106845 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7619994128009393 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7628458149779735 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.172753824756605 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.125597938144332 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.627805320435308 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5089912280701756 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.5353044280442845 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.667365439093479 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.96933554817276 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.663164251207737 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.196250000000004 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.875434782608666 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.396714876033077 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.835088757396434 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.720078124999986 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.990054945054958 ms/frame 00:08:19 INFO - PID 16955 | 00:08:19 INFO - PID 16955 | Cycle 1(2): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:09:05 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.680125979843225 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6712280701754387 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7892874180083485 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7533917616126204 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.043382749326144 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9697123015873026 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.4654214780600445 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3617058823529415 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.70504752851711 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.555666666666659 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 10.067634228187915 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.760829268292689 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.538942307692308 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.700187165775427 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.449771784232352 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.835443786982262 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.540096153846164 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.055552486187846 ms/frame 00:09:05 INFO - PID 16955 | 00:09:05 INFO - PID 16955 | Cycle 1(3): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:09:51 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6827397644419517 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6684778982485406 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7620551967116858 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.753229623137599 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.060392422192153 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.8555298651252383 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.4454707233065434 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3798479729729776 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.715 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.525082872928172 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.49458860759494 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.954975124378095 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.409391634980995 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.755 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.246612244897952 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.699678362573081 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.153531598513021 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.810648648648655 ms/frame 00:09:51 INFO - PID 16955 | 00:09:51 INFO - PID 16955 | Cycle 1(4): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:10:37 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6800755879059353 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6684945788156798 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.773191489361702 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.8071183378500448 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.093274215552523 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.176033402922759 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.4806960556844535 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4246832191780814 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.759433781190021 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.588966480446923 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 10.135777027027023 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.051380090497736 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.497279693486593 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.81264864864863 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.24665306122449 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.84118343195264 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.811771653543316 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.87144021739131 ms/frame 00:10:37 INFO - PID 16955 | 00:10:37 INFO - PID 16955 | Cycle 1(5): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:11:23 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6818357623318385 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6704841402337234 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.777716232227488 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7519395796847645 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9956990679094546 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.124536082474226 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.4694913294797693 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.426241438356163 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.727013358778622 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.4971291208791255 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.464905362776026 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.347266355140198 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.364393939393928 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.873695652173923 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.198821138211397 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.836568047337263 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.63158914728681 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.116250000000017 ms/frame 00:11:23 INFO - PID 16955 | 00:11:23 INFO - PID 16955 | Cycle 1(6): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:12:10 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6832192933258552 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6714076858813698 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.8074216867469877 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7347745013009537 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.043456873315365 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.185167364016737 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.488918604651162 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.385059221658206 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.715057142857141 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.572660167130917 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.616586538461538 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.572535885167463 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.539519230769237 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.872961956521738 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.246632653061237 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.629534883720924 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.407072243346027 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.932404371584685 ms/frame 00:12:10 INFO - PID 16955 | 00:12:10 INFO - PID 16955 | Cycle 1(7): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:12:56 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6897466216216215 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6734573578595318 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7868969624776652 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7673012367491174 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.196216783216784 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.141749482401656 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.663345543345542 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5589323843416416 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.747892720306516 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.6023109243697515 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.902310231023096 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.710558252427184 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.496609195402305 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.989505494505476 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.554811715481165 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.126636363636388 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.324226415094333 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.7558870967742 ms/frame 00:12:56 INFO - PID 16955 | 00:12:56 INFO - PID 16955 | Cycle 1(8): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:13:42 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6809299719887956 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6690992493744783 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.785163593099346 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7623259911894271 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.115589849108367 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.0837346938775525 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.4648094688221707 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3847461928933984 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.609140186915886 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.6670113314447645 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.526095238095241 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 10.005175 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.583629343629344 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 11.053342541436457 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.347654320987637 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.90925595238098 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.541846153846171 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.176983240223466 ms/frame 00:13:42 INFO - PID 16955 | 00:13:42 INFO - PID 16955 | Cycle 1(9): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:14:28 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.682099215246637 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6742468619246862 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7324711316397226 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7472794759825336 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.116275720164608 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.1497717842323665 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.4328546910755153 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3730775716694783 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.662056603773591 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.6348028169014075 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.740438311688312 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.134269406392706 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.237528089887634 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.698288770053486 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.34670781893004 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.836213017751477 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.49436781609195 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.754892473118298 ms/frame 00:14:28 INFO - PID 16955 | 00:14:28 INFO - PID 16955 | Cycle 1(10): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:15:14 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6839562289562289 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6711737677527154 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.783641498216409 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7715101860053144 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 3.8666430412371127 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.195146750524107 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.5134836065573785 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4369415807560126 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.747231800766284 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.4958791208791204 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.902046204620461 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 9.856773399014775 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.495287356321855 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.934153005464465 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.60722689075632 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.275797546012281 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.409885931558946 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.698903743315507 ms/frame 00:15:14 INFO - PID 16955 | 00:15:14 INFO - PID 16955 | Cycle 1(11): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:16:01 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_startup = 1.68010078387458 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6710944026733503 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7632579318448882 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7385230234578628 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_startup = 4.105328317373462 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.14307453416149 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_startup = 3.5260634547591074 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4370618556701014 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.672173913043482 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.682784090909092 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_startup = 9.464984227129342 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.480p.60fps.webm_scale_2_inclip = 10.154365482233501 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.45177480916031 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.871847826086947 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.24710204081633 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.1231818181818 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.454942748091602 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.696978609625663 ms/frame 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | Cycle 1(12): loaded http://localhost:50958/tests/video/video_playback.html (next: http://localhost:50958/tests/video/video_playback.html) 00:16:01 INFO - PID 16955 | __start_tp_report 00:16:01 INFO - PID 16955 | _x_x_mozilla_page_load 00:16:01 INFO - PID 16955 | _x_x_mozilla_page_load_details 00:16:01 INFO - PID 16955 | |i|pagename|runs| 00:16:01 INFO - PID 16955 | |0;240p.120fps.mp4_scale_1_startup;1.6850224592925322;1.6803247480403136;1.680125979843225;1.6827397644419517;1.6800755879059353;1.6818357623318385;1.6832192933258552;1.6897466216216215;1.6809299719887956;1.682099215246637;1.6839562289562289;1.68010078387458 00:16:01 INFO - PID 16955 | |1;240p.120fps.mp4_scale_1_inclip;1.6671375;1.6697078464106845;1.6712280701754387;1.6684778982485406;1.6684945788156798;1.6704841402337234;1.6714076858813698;1.6734573578595318;1.6690992493744783;1.6742468619246862;1.6711737677527154;1.6710944026733503 00:16:01 INFO - PID 16955 | |2;240p.120fps.mp4_scale_1.1_startup;1.777535545023697;1.7619994128009393;1.7892874180083485;1.7620551967116858;1.773191489361702;1.777716232227488;1.8074216867469877;1.7868969624776652;1.785163593099346;1.7324711316397226;1.783641498216409;1.7632579318448882 00:16:01 INFO - PID 16955 | |3;240p.120fps.mp4_scale_1.1_inclip;1.756479367866549;1.7628458149779735;1.7533917616126204;1.753229623137599;1.8071183378500448;1.7519395796847645;1.7347745013009537;1.7673012367491174;1.7623259911894271;1.7472794759825336;1.7715101860053144;1.7385230234578628 00:16:01 INFO - PID 16955 | |4;240p.120fps.mp4_scale_2_startup;4.145110497237571;4.172753824756605;4.043382749326144;4.060392422192153;4.093274215552523;3.9956990679094546;4.043456873315365;4.196216783216784;4.115589849108367;4.116275720164608;3.8666430412371127;4.105328317373462 00:16:01 INFO - PID 16955 | |5;240p.120fps.mp4_scale_2_inclip;4.098616803278689;4.125597938144332;3.9697123015873026;3.8555298651252383;4.176033402922759;4.124536082474226;4.185167364016737;4.141749482401656;4.0837346938775525;4.1497717842323665;4.195146750524107;4.14307453416149 00:16:01 INFO - PID 16955 | |6;480p.60fps.webm_scale_1_startup;3.663968253968257;3.627805320435308;3.4654214780600445;3.4454707233065434;3.4806960556844535;3.4694913294797693;3.488918604651162;3.663345543345542;3.4648094688221707;3.4328546910755153;3.5134836065573785;3.5260634547591074 00:16:01 INFO - PID 16955 | |7;480p.60fps.webm_scale_1_inclip;3.3899915254237247;3.5089912280701756;3.3617058823529415;3.3798479729729776;3.4246832191780814;3.426241438356163;3.385059221658206;3.5589323843416416;3.3847461928933984;3.3730775716694783;3.4369415807560126;3.4370618556701014 00:16:01 INFO - PID 16955 | |8;480p.60fps.webm_scale_1.1_startup;5.386867145421904;5.5353044280442845;5.70504752851711;5.715;5.759433781190021;5.727013358778622;5.715057142857141;5.747892720306516;5.609140186915886;5.662056603773591;5.747231800766284;5.672173913043482 00:16:01 INFO - PID 16955 | |9;480p.60fps.webm_scale_1.1_inclip;5.435108695652171;5.667365439093479;5.555666666666659;5.525082872928172;5.588966480446923;5.4971291208791255;5.572660167130917;5.6023109243697515;5.6670113314447645;5.6348028169014075;5.4958791208791204;5.682784090909092 00:16:01 INFO - PID 16955 | |10;480p.60fps.webm_scale_2_startup;9.407445141065837;9.96933554817276;10.067634228187915;9.49458860759494;10.135777027027023;9.464905362776026;9.616586538461538;9.902310231023096;9.526095238095241;9.740438311688312;9.902046204620461;9.464984227129342 00:16:01 INFO - PID 16955 | |11;480p.60fps.webm_scale_2_inclip;9.010945945945947;9.663164251207737;9.760829268292689;9.954975124378095;9.051380090497736;9.347266355140198;9.572535885167463;9.710558252427184;10.005175;9.134269406392706;9.856773399014775;10.154365482233501 00:16:01 INFO - PID 16955 | |12;1080p.60fps.mp4_scale_1_startup;11.542269230769238;11.196250000000004;11.538942307692308;11.409391634980995;11.497279693486593;11.364393939393928;11.539519230769237;11.496609195402305;11.583629343629344;11.237528089887634;11.495287356321855;11.45177480916031 00:16:01 INFO - PID 16955 | |13;1080p.60fps.mp4_scale_1_inclip;10.815810810810786;10.875434782608666;10.700187165775427;10.755;10.81264864864863;10.873695652173923;10.872961956521738;10.989505494505476;11.053342541436457;10.698288770053486;10.934153005464465;10.871847826086947 00:16:01 INFO - PID 16955 | |14;1080p.60fps.mp4_scale_1.1_startup;12.198353658536579;12.396714876033077;12.449771784232352;12.246612244897952;12.24665306122449;12.198821138211397;12.246632653061237;12.554811715481165;12.347654320987637;12.34670781893004;12.60722689075632;12.24710204081633 00:16:01 INFO - PID 16955 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.770294117647085;11.835088757396434;11.835443786982262;11.699678362573081;11.84118343195264;11.836568047337263;11.629534883720924;12.126636363636388;11.90925595238098;11.836213017751477;12.275797546012281;12.1231818181818 00:16:01 INFO - PID 16955 | |16;1080p.60fps.mp4_scale_2_startup;11.495038314176252;11.720078124999986;11.540096153846164;11.153531598513021;11.811771653543316;11.63158914728681;11.407072243346027;11.324226415094333;11.541846153846171;11.49436781609195;11.409885931558946;11.454942748091602 00:16:01 INFO - PID 16955 | |17;1080p.60fps.mp4_scale_2_inclip;10.753279569892475;10.990054945054958;11.055552486187846;10.810648648648655;10.87144021739131;11.116250000000017;10.932404371584685;10.7558870967742;11.176983240223466;10.754892473118298;10.698903743315507;10.696978609625663 00:16:01 INFO - PID 16955 | __end_tp_report 00:16:01 INFO - PID 16955 | __start_cc_report 00:16:01 INFO - PID 16955 | _x_x_mozilla_cycle_collect,612 00:16:01 INFO - PID 16955 | __end_cc_report 00:16:01 INFO - PID 16955 | __startTimestamp1507446961270__endTimestamp 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | ------- Summary: start ------- 00:16:01 INFO - PID 16955 | Number of tests: 18 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.00 (0.2%) stddev-sans-first:0.00 00:16:01 INFO - PID 16955 | 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 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:1.67 Median:1.67 stddev:0.00 (0.1%) stddev-sans-first:0.00 00:16:01 INFO - PID 16955 | 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 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.78 Median:1.78 stddev:0.02 (1.1%) stddev-sans-first:0.02 00:16:01 INFO - PID 16955 | Values: 1.8 1.8 1.8 1.8 1.8 1.8 1.8 1.8 1.8 1.7 1.8 1.8 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.76 Median:1.76 stddev:0.02 (1.1%) stddev-sans-first:0.02 00:16:01 INFO - PID 16955 | Values: 1.8 1.8 1.8 1.8 1.8 1.8 1.7 1.8 1.8 1.7 1.8 1.7 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.08 Median:4.11 stddev:0.09 (2.1%) stddev-sans-first:0.09 00:16:01 INFO - PID 16955 | Values: 4.1 4.2 4.0 4.1 4.1 4.0 4.0 4.2 4.1 4.1 3.9 4.1 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.10 Median:4.14 stddev:0.10 (2.4%) stddev-sans-first:0.10 00:16:01 INFO - PID 16955 | Values: 4.1 4.1 4.0 3.9 4.2 4.1 4.2 4.1 4.1 4.1 4.2 4.1 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.52 Median:3.50 stddev:0.08 (2.4%) stddev-sans-first:0.07 00:16:01 INFO - PID 16955 | Values: 3.7 3.6 3.5 3.4 3.5 3.5 3.5 3.7 3.5 3.4 3.5 3.5 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.42 Median:3.43 stddev:0.06 (1.7%) stddev-sans-first:0.06 00:16:01 INFO - PID 16955 | Values: 3.4 3.5 3.4 3.4 3.4 3.4 3.4 3.6 3.4 3.4 3.4 3.4 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.67 Median:5.72 stddev:0.11 (1.9%) stddev-sans-first:0.07 00:16:01 INFO - PID 16955 | Values: 5.4 5.5 5.7 5.7 5.8 5.7 5.7 5.7 5.6 5.7 5.7 5.7 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.58 Median:5.60 stddev:0.08 (1.4%) stddev-sans-first:0.07 00:16:01 INFO - PID 16955 | Values: 5.4 5.7 5.6 5.5 5.6 5.5 5.6 5.6 5.7 5.6 5.5 5.7 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:9.72 Median:9.57 stddev:0.26 (2.7%) stddev-sans-first:0.25 00:16:01 INFO - PID 16955 | Values: 9.4 10.0 10.1 9.5 10.1 9.5 9.6 9.9 9.5 9.7 9.9 9.5 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.60 Median:9.62 stddev:0.39 (4.0%) stddev-sans-first:0.35 00:16:01 INFO - PID 16955 | Values: 9.0 9.7 9.8 10.0 9.1 9.3 9.6 9.7 10.0 9.1 9.9 10.2 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.45 Median:11.50 stddev:0.12 (1.1%) stddev-sans-first:0.13 00:16:01 INFO - PID 16955 | Values: 11.5 11.2 11.5 11.4 11.5 11.4 11.5 11.5 11.6 11.2 11.5 11.5 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.85 Median:10.87 stddev:0.11 (1.0%) stddev-sans-first:0.11 00:16:01 INFO - PID 16955 | Values: 10.8 10.9 10.7 10.8 10.8 10.9 10.9 11.0 11.1 10.7 10.9 10.9 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.34 Median:12.35 stddev:0.14 (1.1%) stddev-sans-first:0.14 00:16:01 INFO - PID 16955 | Values: 12.2 12.4 12.4 12.2 12.2 12.2 12.2 12.6 12.3 12.3 12.6 12.2 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.89 Median:11.84 stddev:0.19 (1.6%) stddev-sans-first:0.19 00:16:01 INFO - PID 16955 | Values: 11.8 11.8 11.8 11.7 11.8 11.8 11.6 12.1 11.9 11.8 12.3 12.1 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.50 Median:11.52 stddev:0.17 (1.5%) stddev-sans-first:0.18 00:16:01 INFO - PID 16955 | Values: 11.5 11.7 11.5 11.2 11.8 11.6 11.4 11.3 11.5 11.5 11.4 11.5 00:16:01 INFO - PID 16955 | 00:16:01 INFO - PID 16955 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.88 Median:10.90 stddev:0.17 (1.5%) stddev-sans-first:0.17 00:16:01 INFO - PID 16955 | Values: 10.8 11.0 11.1 10.8 10.9 11.1 10.9 10.8 11.2 10.8 10.7 10.7 00:16:01 INFO - PID 16955 | -------- Summary: end -------- 00:16:01 INFO - PID 16955 | 00:16:01 INFO - TEST-INFO | 16955: exit 0 00:16:01 INFO - TEST-OK | basic_compositor_video | took 563601ms 00:16:01 INFO - TEST-START | glvideo 00:16:01 INFO - Initialising browser for glvideo test... 00:16:01 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:50958/getInfo.html -profile /tmp/tmpXNeWiS/profile 00:16:01 INFO - TEST-INFO | started process 18303 (/builds/slave/test/build/application/firefox/firefox http://localhost:50958/getInfo.html) 00:16:07 INFO - TEST-INFO | 18303: exit 0 00:16:07 INFO - Browser initialized. 00:16:07 INFO - Running cycle 1/1 for glvideo test... 00:16:07 INFO - Using env: {'DISPLAY': ':0', 00:16:07 INFO - 'HOME': '/home/cltbld', 00:16:07 INFO - 'JSGC_DISABLE_POISONING': '1', 00:16:07 INFO - 'LANG': 'en_US.UTF-8', 00:16:07 INFO - 'LANGUAGE': 'en_US:en', 00:16:07 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 00:16:07 INFO - 'LOGNAME': 'cltbld', 00:16:07 INFO - 'MAIL': '/var/mail/cltbld', 00:16:07 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 00:16:07 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 00:16:07 INFO - 'MOZ_CRASHREPORTER': '1', 00:16:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 00:16:07 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 00:16:07 INFO - 'MOZ_NO_REMOTE': '1', 00:16:07 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 00:16:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 00:16:07 INFO - 'NO_EM_RESTART': '1', 00:16:07 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 00:16:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 00:16:07 INFO - 'PWD': '/builds/slave/test', 00:16:07 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 00:16:07 INFO - 'RUST_BACKTRACE': 'full', 00:16:07 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 00:16:07 INFO - 'SHELL': '/bin/bash', 00:16:07 INFO - 'SHLVL': '1', 00:16:07 INFO - 'STYLO_FORCE_DISABLED': '1', 00:16:07 INFO - 'TERM': 'linux', 00:16:07 INFO - 'TMOUT': '86400', 00:16:07 INFO - 'USER': 'cltbld', 00:16:07 INFO - 'XDG_SESSION_COOKIE': 'fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865', 00:16:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 00:16:07 INFO - '_': '/tools/buildbot/bin/python'} 00:16:07 INFO - TEST-INFO | started process 18581 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpXNeWiS/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 00:16:08 INFO - PID 18581 | 00:16:08 INFO - PID 18581 | (/builds/slave/test/build/application/firefox/firefox:18631): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 00:16:08 INFO - PID 18581 | 00:16:10 INFO - PID 18581 | [talos glvideo result] Mean tick time across 100 ticks: 8.37255 ms 00:16:10 INFO - PID 18581 | Cycle 1(1): loaded http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html) 00:16:11 INFO - PID 18581 | [talos glvideo result] Mean tick time across 100 ticks: 6.5651 ms 00:16:11 INFO - PID 18581 | Cycle 1(2): loaded http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html) 00:16:12 INFO - PID 18581 | [talos glvideo result] Mean tick time across 100 ticks: 6.593999999999999 ms 00:16:12 INFO - PID 18581 | Cycle 1(3): loaded http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html) 00:16:14 INFO - PID 18581 | [talos glvideo result] Mean tick time across 100 ticks: 6.60735 ms 00:16:14 INFO - PID 18581 | Cycle 1(4): loaded http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html) 00:16:15 INFO - PID 18581 | [talos glvideo result] Mean tick time across 100 ticks: 6.566 ms 00:16:15 INFO - PID 18581 | Cycle 1(5): loaded http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:50958/tests/webgl/benchmarks/video/video_upload.html) 00:16:15 INFO - PID 18581 | __start_tp_report 00:16:15 INFO - PID 18581 | _x_x_mozilla_page_load 00:16:15 INFO - PID 18581 | _x_x_mozilla_page_load_details 00:16:15 INFO - PID 18581 | |i|pagename|runs| 00:16:15 INFO - PID 18581 | |0;Mean tick time across 100 ticks: ;8.37255;6.5651;6.593999999999999;6.60735;6.566 00:16:15 INFO - PID 18581 | __end_tp_report 00:16:15 INFO - PID 18581 | __start_cc_report 00:16:15 INFO - PID 18581 | _x_x_mozilla_cycle_collect,267 00:16:15 INFO - PID 18581 | __end_cc_report 00:16:15 INFO - PID 18581 | __startTimestamp1507446975644__endTimestamp 00:16:15 INFO - PID 18581 | 00:16:15 INFO - PID 18581 | ------- Summary: start ------- 00:16:15 INFO - PID 18581 | Number of tests: 1 00:16:15 INFO - PID 18581 | 00:16:15 INFO - PID 18581 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.94 Median:6.59 stddev:0.80 (12.1%) stddev-sans-first:0.02 00:16:15 INFO - PID 18581 | Values: 8.4 6.6 6.6 6.6 6.6 00:16:15 INFO - PID 18581 | -------- Summary: end -------- 00:16:15 INFO - PID 18581 | 00:16:16 INFO - PID 18581 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 00:16:16 INFO - TEST-INFO | 18581: exit 0 00:16:16 INFO - TEST-OK | glvideo | took 14451ms 00:16:16 INFO - SUITE-END | took 578s 00:16:16 INFO - Completed test suite (00:09:38) 00:16:16 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.587571764615555, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6850224592925322, 1.6803247480403136, 1.680125979843225, 1.6827397644419517, 1.6800755879059353, 1.6818357623318385, 1.6832192933258552, 1.6897466216216215, 1.6809299719887956, 1.682099215246637, 1.6839562289562289, 1.68010078387458], "value": 1.6818357623318385, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6671375, 1.6697078464106845, 1.6712280701754387, 1.6684778982485406, 1.6684945788156798, 1.6704841402337234, 1.6714076858813698, 1.6734573578595318, 1.6690992493744783, 1.6742468619246862, 1.6711737677527154, 1.6710944026733503], "value": 1.6710944026733503, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.777535545023697, 1.7619994128009393, 1.7892874180083485, 1.7620551967116858, 1.773191489361702, 1.777716232227488, 1.8074216867469877, 1.7868969624776652, 1.785163593099346, 1.7324711316397226, 1.783641498216409, 1.7632579318448882], "value": 1.777716232227488, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.756479367866549, 1.7628458149779735, 1.7533917616126204, 1.753229623137599, 1.8071183378500448, 1.7519395796847645, 1.7347745013009537, 1.7673012367491174, 1.7623259911894271, 1.7472794759825336, 1.7715101860053144, 1.7385230234578628], "value": 1.7533917616126204, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.145110497237571, 4.172753824756605, 4.043382749326144, 4.060392422192153, 4.093274215552523, 3.9956990679094546, 4.043456873315365, 4.196216783216784, 4.115589849108367, 4.116275720164608, 3.8666430412371127, 4.105328317373462], "value": 4.093274215552523, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.098616803278689, 4.125597938144332, 3.9697123015873026, 3.8555298651252383, 4.176033402922759, 4.124536082474226, 4.185167364016737, 4.141749482401656, 4.0837346938775525, 4.1497717842323665, 4.195146750524107, 4.14307453416149], "value": 4.141749482401656, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.663968253968257, 3.627805320435308, 3.4654214780600445, 3.4454707233065434, 3.4806960556844535, 3.4694913294797693, 3.488918604651162, 3.663345543345542, 3.4648094688221707, 3.4328546910755153, 3.5134836065573785, 3.5260634547591074], "value": 3.4806960556844535, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.3899915254237247, 3.5089912280701756, 3.3617058823529415, 3.3798479729729776, 3.4246832191780814, 3.426241438356163, 3.385059221658206, 3.5589323843416416, 3.3847461928933984, 3.3730775716694783, 3.4369415807560126, 3.4370618556701014], "value": 3.4246832191780814, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.386867145421904, 5.5353044280442845, 5.70504752851711, 5.715, 5.759433781190021, 5.727013358778622, 5.715057142857141, 5.747892720306516, 5.609140186915886, 5.662056603773591, 5.747231800766284, 5.672173913043482], "value": 5.715, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.435108695652171, 5.667365439093479, 5.555666666666659, 5.525082872928172, 5.588966480446923, 5.4971291208791255, 5.572660167130917, 5.6023109243697515, 5.6670113314447645, 5.6348028169014075, 5.4958791208791204, 5.682784090909092], "value": 5.588966480446923, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.407445141065837, 9.96933554817276, 10.067634228187915, 9.49458860759494, 10.135777027027023, 9.464905362776026, 9.616586538461538, 9.902310231023096, 9.526095238095241, 9.740438311688312, 9.902046204620461, 9.464984227129342], "value": 9.740438311688312, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.010945945945947, 9.663164251207737, 9.760829268292689, 9.954975124378095, 9.051380090497736, 9.347266355140198, 9.572535885167463, 9.710558252427184, 10.005175, 9.134269406392706, 9.856773399014775, 10.154365482233501], "value": 9.710558252427184, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.542269230769238, 11.196250000000004, 11.538942307692308, 11.409391634980995, 11.497279693486593, 11.364393939393928, 11.539519230769237, 11.496609195402305, 11.583629343629344, 11.237528089887634, 11.495287356321855, 11.45177480916031], "value": 11.495287356321855, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.815810810810786, 10.875434782608666, 10.700187165775427, 10.755, 10.81264864864863, 10.873695652173923, 10.872961956521738, 10.989505494505476, 11.053342541436457, 10.698288770053486, 10.934153005464465, 10.871847826086947], "value": 10.872961956521738, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.198353658536579, 12.396714876033077, 12.449771784232352, 12.246612244897952, 12.24665306122449, 12.198821138211397, 12.246632653061237, 12.554811715481165, 12.347654320987637, 12.34670781893004, 12.60722689075632, 12.24710204081633], "value": 12.34670781893004, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.770294117647085, 11.835088757396434, 11.835443786982262, 11.699678362573081, 11.84118343195264, 11.836568047337263, 11.629534883720924, 12.126636363636388, 11.90925595238098, 11.836213017751477, 12.275797546012281, 12.1231818181818], "value": 11.836568047337263, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.495038314176252, 11.720078124999986, 11.540096153846164, 11.153531598513021, 11.811771653543316, 11.63158914728681, 11.407072243346027, 11.324226415094333, 11.541846153846171, 11.49436781609195, 11.409885931558946, 11.454942748091602], "value": 11.49436781609195, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.753279569892475, 10.990054945054958, 11.055552486187846, 10.810648648648655, 10.87144021739131, 11.116250000000017, 10.932404371584685, 10.7558870967742, 11.176983240223466, 10.754892473118298, 10.698903743315507, 10.696978609625663], "value": 10.87144021739131, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [8.37255, 6.5651, 6.593999999999999, 6.60735, 6.566], "value": 6.58, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]} 00:16:16 INFO - Return code: 0 00:16:16 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 00:16:16 INFO - # TBPL SUCCESS # 00:16:16 INFO - Running post-action listener: _package_coverage_data 00:16:16 INFO - Running post-action listener: _resource_record_post_action 00:16:16 INFO - [mozharness: 2017-10-08 07:16:16.764495Z] Finished run-tests step (success) 00:16:16 INFO - Running post-run listener: _resource_record_post_run 00:16:16 INFO - Total resource usage - Wall time: 597s; CPU: 39.0%; Read bytes: 8912896; Write bytes: 336613376; Read time: 836; Write time: 334680 00:16:16 INFO - TinderboxPrint: CPU usage
38.5% 00:16:16 INFO - TinderboxPrint: I/O read bytes / time
8,912,896 / 836 00:16:16 INFO - TinderboxPrint: I/O write bytes / time
336,613,376 / 334,680 00:16:16 INFO - TinderboxPrint: CPU idle
2,879.2 (61.4%) 00:16:16 INFO - TinderboxPrint: CPU system
301.3 (6.4%) 00:16:16 INFO - TinderboxPrint: CPU user
1,488.5 (31.8%) 00:16:16 INFO - TinderboxPrint: Swap in / out
0 / 0 00:16:16 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 13152256; Read time: 0; Write time: 3292 00:16:16 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 00:16:16 INFO - run-tests - Wall time: 579s; CPU: 39.0%; Read bytes: 8908800; Write bytes: 323461120; Read time: 820; Write time: 331388 00:16:17 INFO - Running post-run listener: _upload_blobber_files 00:16:17 INFO - Blob upload gear active. 00:16:17 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 00:16:17 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 00:16:17 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'] 00:16:17 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 00:16:17 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 00:16:17 INFO - SNIMissingWarning 00:16:17 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 00:16:17 INFO - InsecurePlatformWarning 00:16:17 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.) 00:16:17 INFO - SubjectAltNameWarning 00:16:17 INFO - (blobuploader) - INFO - Open directory for files ... 00:16:17 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 00:16:17 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 00:16:17 INFO - (blobuploader) - INFO - Uploading, attempt #1. 00:16:17 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 00:16:17 INFO - InsecurePlatformWarning 00:16:17 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.) 00:16:17 INFO - SubjectAltNameWarning 00:16:19 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 00:16:19 INFO - InsecurePlatformWarning 00:16:20 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 00:16:20 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 00:16:20 INFO - (blobuploader) - INFO - Done attempting. 00:16:20 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log ... 00:16:20 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 00:16:20 INFO - (blobuploader) - INFO - Uploading, attempt #1. 00:16:20 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 00:16:20 INFO - InsecurePlatformWarning 00:16:20 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.) 00:16:20 INFO - SubjectAltNameWarning 00:16:20 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 00:16:20 INFO - InsecurePlatformWarning 00:16:20 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_errorsummary.log: uploaded 00:16:20 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 00:16:20 INFO - (blobuploader) - INFO - Done attempting. 00:16:20 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log ... 00:16:20 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 00:16:20 INFO - (blobuploader) - INFO - Uploading, attempt #1. 00:16:20 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 00:16:20 INFO - InsecurePlatformWarning 00:16:21 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.) 00:16:21 INFO - SubjectAltNameWarning 00:16:21 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 00:16:21 INFO - InsecurePlatformWarning 00:16:21 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_raw.log: uploaded 00:16:21 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 00:16:21 INFO - (blobuploader) - INFO - Done attempting. 00:16:21 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 00:16:21 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 00:16:21 INFO - (blobuploader) - INFO - Uploading, attempt #1. 00:16:21 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 00:16:21 INFO - InsecurePlatformWarning 00:16:21 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.) 00:16:21 INFO - SubjectAltNameWarning 00:16:22 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 00:16:22 INFO - InsecurePlatformWarning 00:16:22 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 00:16:22 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 00:16:22 INFO - (blobuploader) - INFO - Done attempting. 00:16:22 INFO - (blobuploader) - INFO - Iteration through files over. 00:16:22 INFO - Return code: 0 00:16:22 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 00:16:22 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 00:16:22 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/46760dea8c5b60266e75444fa1ad0be55d21ad7448ff40c817af4e0b1f369ab5c5202b074fe8581b3d446ea32369a2db9c943ad6dfdff00a1a420318f850ba5f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/55635bf11e0892c37a4a288a0c3ad8e1a14c3134e5d473b92ebec00730bdb821d122b234fd859deb44b53bd137769904f95086ac424addc1fa4d1de074609738", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3e021b21a04d6f3392e8f020ef8784b2fe8b1a2adc33a3bcaf0ac792ddc4f2b18bdcb560cfd0d66aa72e0a7292f0846302736ba377bf23d8c872d4574d34aff8", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/02eeb095b473fd05612da9cc94059f94d00628c664044ad46869168793237b2b61bbe4f5ed6e5914194379e7a2e852f9100f984d5f2e5e516f13a24baededdc2"} 00:16:22 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 00:16:22 INFO - Writing to file /builds/slave/test/properties/blobber_files 00:16:22 INFO - Contents: 00:16:22 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/46760dea8c5b60266e75444fa1ad0be55d21ad7448ff40c817af4e0b1f369ab5c5202b074fe8581b3d446ea32369a2db9c943ad6dfdff00a1a420318f850ba5f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/55635bf11e0892c37a4a288a0c3ad8e1a14c3134e5d473b92ebec00730bdb821d122b234fd859deb44b53bd137769904f95086ac424addc1fa4d1de074609738", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3e021b21a04d6f3392e8f020ef8784b2fe8b1a2adc33a3bcaf0ac792ddc4f2b18bdcb560cfd0d66aa72e0a7292f0846302736ba377bf23d8c872d4574d34aff8", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/02eeb095b473fd05612da9cc94059f94d00628c664044ad46869168793237b2b61bbe4f5ed6e5914194379e7a2e852f9100f984d5f2e5e516f13a24baededdc2"} 00:16:22 INFO - Running post-run listener: copy_logs_to_upload_dir 00:16:22 INFO - Copying logs to upload dir... 00:16:22 INFO - mkdir: /builds/slave/test/build/upload/logs 00:16:22 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=643.254423 ========= master_lag: 0.17 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 43 secs) (at 2017-10-08 00:16:22.864616) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-08 00:16:22.869205) ========= 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=fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/46760dea8c5b60266e75444fa1ad0be55d21ad7448ff40c817af4e0b1f369ab5c5202b074fe8581b3d446ea32369a2db9c943ad6dfdff00a1a420318f850ba5f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/55635bf11e0892c37a4a288a0c3ad8e1a14c3134e5d473b92ebec00730bdb821d122b234fd859deb44b53bd137769904f95086ac424addc1fa4d1de074609738", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3e021b21a04d6f3392e8f020ef8784b2fe8b1a2adc33a3bcaf0ac792ddc4f2b18bdcb560cfd0d66aa72e0a7292f0846302736ba377bf23d8c872d4574d34aff8", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/02eeb095b473fd05612da9cc94059f94d00628c664044ad46869168793237b2b61bbe4f5ed6e5914194379e7a2e852f9100f984d5f2e5e516f13a24baededdc2"} build_url:https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011402 build_url: 'https://queue.taskcluster.net/v1/task/BRtHMBD2T2aZzIPBWYVDdQ/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/46760dea8c5b60266e75444fa1ad0be55d21ad7448ff40c817af4e0b1f369ab5c5202b074fe8581b3d446ea32369a2db9c943ad6dfdff00a1a420318f850ba5f", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/55635bf11e0892c37a4a288a0c3ad8e1a14c3134e5d473b92ebec00730bdb821d122b234fd859deb44b53bd137769904f95086ac424addc1fa4d1de074609738", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3e021b21a04d6f3392e8f020ef8784b2fe8b1a2adc33a3bcaf0ac792ddc4f2b18bdcb560cfd0d66aa72e0a7292f0846302736ba377bf23d8c872d4574d34aff8", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/02eeb095b473fd05612da9cc94059f94d00628c664044ad46869168793237b2b61bbe4f5ed6e5914194379e7a2e852f9100f984d5f2e5e516f13a24baededdc2"}' ========= master_lag: 0.01 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-08 00:16:22.894733) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 00:16:22.895059) ========= 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=fa44defc139c4ba8574fe040000001db-1507422863.126609-485365865 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004520 ========= master_lag: 0.05 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-08 00:16:22.950827) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-08 00:16:22.951174) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-08 00:16:22.951489) ========= ========= Total master_lag: 0.35 =========