builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s-pgo slave: talos-linux64-ix-004 starttime: 1509969668.03 results: success (0) revision: 8b9167b8a937e09f6673d4d7d693c6ac1c25a3d7 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.032116) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.032562) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.032830) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.049099) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.049524) ========= 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=c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-11-06 04:01:08-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.102, 63.245.215.25 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 27.5M=0s 2017-11-06 04:01:08 (27.5 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.375573 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.442155) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.442490) ========= 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=c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.022184 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:08.492314) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-11-06 04:01:08.492620) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 8b9167b8a937e09f6673d4d7d693c6ac1c25a3d7 --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 8b9167b8a937e09f6673d4d7d693c6ac1c25a3d7 --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=c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-11-06 04:01:08,516 truncating revision to first 12 chars 2017-11-06 04:01:08,516 Setting DEBUG logging. 2017-11-06 04:01:08,516 attempt 1/10 2017-11-06 04:01:08,516 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/8b9167b8a937?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-11-06 04:01:08,794 unpacking tar archive at: mozilla-central-8b9167b8a937/testing/mozharness/ program finished with exit code 0 elapsedTime=1.134310 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-11-06 04:01:09.643132) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:09.643499) ========= script_repo_revision: 8b9167b8a937e09f6673d4d7d693c6ac1c25a3d7 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:09.643885) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:09.644165) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-06 04:01:09.660403) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 55 secs) (at 2017-11-06 04:01:09.660737) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-stylo-disabled-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 04:01:09 INFO - MultiFileLogger online at 20171106 04:01:09 in /builds/slave/test 04:01:09 INFO - Run as scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 04:01:09 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 04:01:09 INFO - {'append_to_log': False, 04:01:09 INFO - 'base_work_dir': '/builds/slave/test', 04:01:09 INFO - 'blob_upload_branch': 'Firefox', 04:01:09 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 04:01:09 INFO - 'branch': 'Firefox', 04:01:09 INFO - 'buildbot_json_path': 'buildprops.json', 04:01:09 INFO - 'code_coverage': False, 04:01:09 INFO - 'config_files': ('talos/linux_config.py',), 04:01:09 INFO - 'default_actions': ('clobber', 04:01:09 INFO - 'read-buildbot-config', 04:01:09 INFO - 'download-and-extract', 04:01:09 INFO - 'populate-webroot', 04:01:09 INFO - 'create-virtualenv', 04:01:09 INFO - 'install', 04:01:09 INFO - 'setup-mitmproxy', 04:01:09 INFO - 'run-tests'), 04:01:09 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 04:01:09 INFO - 'disable_ccov_upload': False, 04:01:09 INFO - 'disable_stylo': False, 04:01:09 INFO - 'download_minidump_stackwalk': True, 04:01:09 INFO - 'download_symbols': 'ondemand', 04:01:09 INFO - 'e10s': False, 04:01:09 INFO - 'enable_stylo': False, 04:01:09 INFO - 'enable_webrender': False, 04:01:09 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 04:01:09 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 04:01:09 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 04:01:09 INFO - 'gecko_profile': False, 04:01:09 INFO - 'gecko_profile_interval': 0, 04:01:09 INFO - 'installer_path': 'installer.exe', 04:01:09 INFO - 'jsd_code_coverage': False, 04:01:09 INFO - 'log_level': 'info', 04:01:09 INFO - 'log_name': 'talos', 04:01:09 INFO - 'log_to_console': True, 04:01:09 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 04:01:09 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 04:01:09 INFO - 'opt_config_files': (), 04:01:09 INFO - 'pip_index': False, 04:01:09 INFO - 'suite': 'g4-stylo-disabled-e10s', 04:01:09 INFO - 'system_bits': '32', 04:01:09 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 04:01:09 INFO - 'title': 'talos-linux64-ix-004', 04:01:09 INFO - 'tooltool_cache': '/builds/tooltool_cache', 04:01:09 INFO - 'use_talos_json': True, 04:01:09 INFO - 'verify': 'False', 04:01:09 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 04:01:09 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 04:01:09 INFO - 'work_dir': 'build'} 04:01:09 INFO - [mozharness: 2017-11-06 12:01:09.822834Z] Running clobber step. 04:01:09 INFO - Running pre-action listener: _resource_record_pre_action 04:01:09 INFO - Running main action method: clobber 04:01:09 INFO - rmtree: /builds/slave/test/build 04:01:09 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 04:01:11 INFO - Running post-action listener: _resource_record_post_action 04:01:11 INFO - [mozharness: 2017-11-06 12:01:11.470349Z] Finished clobber step (success) 04:01:11 INFO - [mozharness: 2017-11-06 12:01:11.470446Z] Running read-buildbot-config step. 04:01:11 INFO - Running pre-action listener: _resource_record_pre_action 04:01:11 INFO - Running main action method: read_buildbot_config 04:01:11 INFO - Using buildbot properties: 04:01:11 INFO - { 04:01:11 INFO - "project": "", 04:01:11 INFO - "product": "firefox", 04:01:11 INFO - "who": "ncsoregi@mozilla.com", 04:01:11 INFO - "installer_path": "public/build/target.tar.bz2", 04:01:11 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s", 04:01:11 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 04:01:11 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-stylo-disabled-e10s", 04:01:11 INFO - "stage_platform": "linux64-pgo", 04:01:11 INFO - "basedir": "/builds/slave/test", 04:01:11 INFO - "buildnumber": 110, 04:01:11 INFO - "platform": "ubuntu64_hw", 04:01:11 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 04:01:11 INFO - "slavebuilddir": "test", 04:01:11 INFO - "taskId": "MRHDiBxaT-SXRVEqwyeQnQ", 04:01:11 INFO - "branch": "mozilla-central", 04:01:11 INFO - "script_repo_revision": "production", 04:01:11 INFO - "revision": "8b9167b8a937e09f6673d4d7d693c6ac1c25a3d7", 04:01:11 INFO - "slavename": "talos-linux64-ix-004", 04:01:11 INFO - "repo_path": "mozilla-central" 04:01:11 INFO - } 04:01:11 INFO - Finding installer, test and symbols from parent task. 04:01:11 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/MRHDiBxaT-SXRVEqwyeQnQ'}, attempt #1 04:01:11 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/MRHDiBxaT-SXRVEqwyeQnQ'}, attempt #1 04:01:12 INFO - Task dependencies: L7hcqitnSHakEZCJN1QsWQ 04:01:12 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ'}, attempt #1 04:01:12 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2 04:01:12 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.test_packages.json 04:01:12 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.crashreporter-symbols.zip 04:01:12 INFO - Running post-action listener: _resource_record_post_action 04:01:12 INFO - [mozharness: 2017-11-06 12:01:12.796113Z] Finished read-buildbot-config step (success) 04:01:12 INFO - [mozharness: 2017-11-06 12:01:12.796330Z] Running download-and-extract step. 04:01:12 INFO - Running pre-action listener: _resource_record_pre_action 04:01:12 INFO - Running main action method: download_and_extract 04:01:12 INFO - mkdir: /builds/slave/test/build/tests 04:01: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')]} 04:01:12 INFO - trying https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.test_packages.json 04:01:12 INFO - Downloading https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 04:01:12 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 04:01:13 INFO - Downloaded 989 bytes. 04:01:13 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 04:01:13 INFO - Using the following test package requirements: 04:01:13 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 04:01:13 INFO - u'common': [u'target.common.tests.zip'], 04:01:13 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 04:01:13 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 04:01:13 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 04:01:13 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 04:01:13 INFO - u'mozbase': [u'target.common.tests.zip'], 04:01:13 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 04:01:13 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 04:01:13 INFO - u'web-platform': [u'target.common.tests.zip', 04:01:13 INFO - u'target.web-platform.tests.tar.gz'], 04:01:13 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 04:01:13 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 04:01:13 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.common.tests.zip 04:01:13 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.common.tests.zip'}, attempt #1 04:01:13 INFO - Fetch https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.common.tests.zip into memory 04:01:14 INFO - Content-Length response header: 58644020 04:01:14 INFO - Bytes received: 58644020 04:01:25 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.talos.tests.zip 04:01:25 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.talos.tests.zip'}, attempt #1 04:01:25 INFO - Fetch https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.talos.tests.zip into memory 04:01:26 INFO - Content-Length response header: 18771919 04:01:26 INFO - Bytes received: 18771919 04:01:26 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:26 INFO - trying https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2 04:01:26 INFO - Downloading https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 04:01:26 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 04:01:27 INFO - Downloaded 63267641 bytes. 04:01:27 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2 04:01:27 INFO - mkdir: /builds/slave/test/properties 04:01:27 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 04:01:27 INFO - Writing to file /builds/slave/test/properties/build_url 04:01:27 INFO - Contents: 04:01:27 INFO - build_url:https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2 04:01:27 INFO - Running post-action listener: _resource_record_post_action 04:01:27 INFO - Running post-action listener: find_tests_for_verification 04:01:27 INFO - Running post-action listener: set_extra_try_arguments 04:01:27 INFO - [mozharness: 2017-11-06 12:01:27.952405Z] Finished download-and-extract step (success) 04:01:27 INFO - [mozharness: 2017-11-06 12:01:27.952555Z] Running populate-webroot step. 04:01:27 INFO - Running pre-action listener: _resource_record_pre_action 04:01:27 INFO - Running main action method: populate_webroot 04:01:27 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 04:01:27 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['tresize', 04:01:27 INFO - 'tcanvasmark']}, 04:01:27 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 04:01:27 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['dromaeo_css', 04:01:27 INFO - 'kraken']}, 04:01:27 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:01:27 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:01:27 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'tests': ['damp', 'tps']}, 04:01:27 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['damp', 'tps']}, 04:01:27 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 04:01:27 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['dromaeo_dom']}, 04:01:27 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 04:01:27 INFO - 'glvideo', 04:01:27 INFO - 'displaylist_mutate']}, 04:01:27 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['basic_compositor_video', 04:01:27 INFO - 'glvideo']}, 04:01:27 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 04:01:27 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['ts_paint_webext', 04:01:27 INFO - 'tp5o_webext']}, 04:01:27 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 04:01:27 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:01:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:01:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:01:27 INFO - 'talos_options': ['--mitmproxy', 04:01:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:01:27 INFO - '--firstNonBlankPaint'], 04:01:27 INFO - 'tests': ['tp6_google_heavy', 04:01:27 INFO - 'tp6_youtube_heavy', 04:01:27 INFO - 'tp6_amazon_heavy', 04:01:27 INFO - 'tp6_facebook_heavy']}, 04:01:27 INFO - 'other-e10s': {'tests': ['a11yr', 04:01:27 INFO - 'ts_paint', 04:01:27 INFO - 'tpaint', 04:01:27 INFO - 'sessionrestore', 04:01:27 INFO - 'sessionrestore_many_windows', 04:01:27 INFO - 'sessionrestore_no_auto_restore', 04:01:27 INFO - 'tabpaint', 04:01:27 INFO - 'cpstartup']}, 04:01:27 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['a11yr', 04:01:27 INFO - 'ts_paint', 04:01:27 INFO - 'tpaint', 04:01:27 INFO - 'sessionrestore', 04:01:27 INFO - 'sessionrestore_many_windows', 04:01:27 INFO - 'sessionrestore_no_auto_restore', 04:01:27 INFO - 'tabpaint', 04:01:27 INFO - 'cpstartup']}, 04:01:27 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 04:01:27 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 04:01:27 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['perf_reftest_singletons']}, 04:01:27 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['perf_reftest']}, 04:01:27 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 04:01:27 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['speedometer']}, 04:01:27 INFO - 'svgr-e10s': {'tests': ['tsvgx', 04:01:27 INFO - 'tsvgr_opacity', 04:01:27 INFO - 'tart', 04:01:27 INFO - 'tscrollx', 04:01:27 INFO - 'tsvg_static']}, 04:01:27 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['tsvgx', 04:01:27 INFO - 'tsvgr_opacity', 04:01:27 INFO - 'tart', 04:01:27 INFO - 'tscrollx', 04:01:27 INFO - 'tsvg_static']}, 04:01:27 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 04:01:27 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'talos_options': ['--disable-stylo'], 04:01:27 INFO - 'tests': ['tp5o']}, 04:01:27 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:01:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:01:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:01:27 INFO - 'talos_options': ['--mitmproxy', 04:01:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:01:27 INFO - '--firstNonBlankPaint'], 04:01:27 INFO - 'tests': ['tp6_google', 04:01:27 INFO - 'tp6_youtube', 04:01:27 INFO - 'tp6_amazon', 04:01:27 INFO - 'tp6_facebook']}, 04:01:27 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:01:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:01:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:01:27 INFO - 'talos_options': ['--disable-stylo', 04:01:27 INFO - '--mitmproxy', 04:01:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:01:27 INFO - '--firstNonBlankPaint'], 04:01:27 INFO - 'tests': ['tp6_google', 04:01:27 INFO - 'tp6_youtube', 04:01:27 INFO - 'tp6_amazon', 04:01:27 INFO - 'tp6_facebook']}, 04:01:27 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:01:27 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:01:27 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:01:27 INFO - 'talos_options': ['--stylo-threads=1', 04:01:27 INFO - '--mitmproxy', 04:01:27 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:01:27 INFO - '--firstNonBlankPaint'], 04:01:27 INFO - 'tests': ['tp6_google', 04:01:27 INFO - 'tp6_youtube', 04:01:27 INFO - 'tp6_amazon', 04:01:27 INFO - 'tp6_facebook']}, 04:01:27 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'talos_options': ['--xperf_path', 04:01:27 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:01:27 INFO - 'tests': ['tp5n']}, 04:01:27 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:01:27 INFO - 'talos_options': ['--disable-stylo', 04:01:27 INFO - '--xperf_path', 04:01:27 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:01:27 INFO - 'tests': ['tp5n']}}} 04:01:27 INFO - Running post-action listener: _resource_record_post_action 04:01:27 INFO - [mozharness: 2017-11-06 12:01:27.977672Z] Finished populate-webroot step (success) 04:01:27 INFO - [mozharness: 2017-11-06 12:01:27.977782Z] Running create-virtualenv step. 04:01:27 INFO - Running pre-action listener: _resource_record_pre_action 04:01:27 INFO - Running main action method: create_virtualenv 04:01:27 INFO - Creating virtualenv /builds/slave/test/build/venv 04:01:27 INFO - Running command: ['/tools/buildbot/bin/python', '/builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py', '--always-copy', '/builds/slave/test/build/venv'] in /builds/slave/test/build 04:01:27 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 04:01:27 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 04:01:28 INFO - Using real prefix '/usr' 04:01:28 INFO - New python executable in /builds/slave/test/build/venv/bin/python 04:01:28 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 04:01:31 INFO - Installing setuptools, pip, wheel...done. 04:01:31 INFO - Return code: 0 04:01:31 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 04:01:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:31 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:31 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:31 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:31 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5'] in /builds/slave/test/build 04:01:31 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org pip>=1.5 04:01:31 INFO - Using env: {'DISPLAY': ':0', 04:01:31 INFO - 'HOME': '/home/cltbld', 04:01:31 INFO - 'LANG': 'en_US.UTF-8', 04:01:31 INFO - 'LANGUAGE': 'en_US:en', 04:01:31 INFO - 'LOGNAME': 'cltbld', 04:01:31 INFO - 'MAIL': '/var/mail/cltbld', 04:01:31 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:31 INFO - 'MOZ_NO_REMOTE': '1', 04:01:31 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:31 INFO - 'NO_EM_RESTART': '1', 04:01:31 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:31 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:31 INFO - 'PWD': '/builds/slave/test', 04:01:31 INFO - 'SHELL': '/bin/bash', 04:01:31 INFO - 'SHLVL': '1', 04:01:31 INFO - 'TERM': 'linux', 04:01:31 INFO - 'TMOUT': '86400', 04:01:31 INFO - 'USER': 'cltbld', 04:01:31 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:31 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:31 INFO - '_': '/tools/buildbot/bin/python'} 04:01:31 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:31 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 04:01:31 INFO - Return code: 0 04:01:31 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 04:01:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:31 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:31 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:31 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', '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 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:31 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'psutil>=3.1.1'] in /builds/slave/test/build 04:01:31 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org psutil>=3.1.1 04:01:31 INFO - Using env: {'DISPLAY': ':0', 04:01:31 INFO - 'HOME': '/home/cltbld', 04:01:31 INFO - 'LANG': 'en_US.UTF-8', 04:01:31 INFO - 'LANGUAGE': 'en_US:en', 04:01:31 INFO - 'LOGNAME': 'cltbld', 04:01:31 INFO - 'MAIL': '/var/mail/cltbld', 04:01:31 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:31 INFO - 'MOZ_NO_REMOTE': '1', 04:01:31 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:31 INFO - 'NO_EM_RESTART': '1', 04:01:31 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:31 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:31 INFO - 'PWD': '/builds/slave/test', 04:01:31 INFO - 'SHELL': '/bin/bash', 04:01:31 INFO - 'SHLVL': '1', 04:01:31 INFO - 'TERM': 'linux', 04:01:31 INFO - 'TMOUT': '86400', 04:01:31 INFO - 'USER': 'cltbld', 04:01:31 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:31 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:31 INFO - '_': '/tools/buildbot/bin/python'} 04:01:31 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:31 INFO - Collecting psutil>=3.1.1 04:01:32 INFO - Installing collected packages: psutil 04:01:32 INFO - Successfully installed psutil-3.1.1 04:01:32 INFO - Return code: 0 04:01:32 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 04:01:32 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')]} 04:01:32 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:32 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')]} 04:01:32 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:32 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:32 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 04:01:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org mozsystemmonitor==0.3 04:01:32 INFO - Using env: {'DISPLAY': ':0', 04:01:32 INFO - 'HOME': '/home/cltbld', 04:01:32 INFO - 'LANG': 'en_US.UTF-8', 04:01:32 INFO - 'LANGUAGE': 'en_US:en', 04:01:32 INFO - 'LOGNAME': 'cltbld', 04:01:32 INFO - 'MAIL': '/var/mail/cltbld', 04:01:32 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:32 INFO - 'MOZ_NO_REMOTE': '1', 04:01:32 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:32 INFO - 'NO_EM_RESTART': '1', 04:01:32 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:32 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:32 INFO - 'PWD': '/builds/slave/test', 04:01:32 INFO - 'SHELL': '/bin/bash', 04:01:32 INFO - 'SHLVL': '1', 04:01:32 INFO - 'TERM': 'linux', 04:01:32 INFO - 'TMOUT': '86400', 04:01:32 INFO - 'USER': 'cltbld', 04:01:32 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:32 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:32 INFO - '_': '/tools/buildbot/bin/python'} 04:01:33 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:33 INFO - Collecting mozsystemmonitor==0.3 04:01:33 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 04:01:33 INFO - Installing collected packages: mozsystemmonitor 04:01:33 INFO - Successfully installed mozsystemmonitor-0.3 04:01:33 INFO - Return code: 0 04:01:33 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 04:01:33 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:33 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:33 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:33 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:33 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:33 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1'] in /builds/slave/test/build 04:01:33 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema==2.5.1 04:01:33 INFO - Using env: {'DISPLAY': ':0', 04:01:33 INFO - 'HOME': '/home/cltbld', 04:01:33 INFO - 'LANG': 'en_US.UTF-8', 04:01:33 INFO - 'LANGUAGE': 'en_US:en', 04:01:33 INFO - 'LOGNAME': 'cltbld', 04:01:33 INFO - 'MAIL': '/var/mail/cltbld', 04:01:33 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:33 INFO - 'MOZ_NO_REMOTE': '1', 04:01:33 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:33 INFO - 'NO_EM_RESTART': '1', 04:01:33 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:33 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:33 INFO - 'PWD': '/builds/slave/test', 04:01:33 INFO - 'SHELL': '/bin/bash', 04:01:33 INFO - 'SHLVL': '1', 04:01:33 INFO - 'TERM': 'linux', 04:01:33 INFO - 'TMOUT': '86400', 04:01:33 INFO - 'USER': 'cltbld', 04:01:33 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:33 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:33 INFO - '_': '/tools/buildbot/bin/python'} 04:01:34 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:34 INFO - Collecting jsonschema==2.5.1 04:01:34 INFO - Downloading http://pypi.pub.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 04:01:34 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 04:01:35 INFO - Installing collected packages: functools32, jsonschema 04:01:35 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 04:01:35 INFO - Return code: 0 04:01:35 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 04:01:35 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')]} 04:01:35 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:35 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')]} 04:01:35 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:35 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:35 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2'] in /builds/slave/test/build 04:01:35 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org functools32==3.2.3-2 04:01:35 INFO - Using env: {'DISPLAY': ':0', 04:01:35 INFO - 'HOME': '/home/cltbld', 04:01:35 INFO - 'LANG': 'en_US.UTF-8', 04:01:35 INFO - 'LANGUAGE': 'en_US:en', 04:01:35 INFO - 'LOGNAME': 'cltbld', 04:01:35 INFO - 'MAIL': '/var/mail/cltbld', 04:01:35 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:35 INFO - 'MOZ_NO_REMOTE': '1', 04:01:35 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:35 INFO - 'NO_EM_RESTART': '1', 04:01:35 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:35 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:35 INFO - 'PWD': '/builds/slave/test', 04:01:35 INFO - 'SHELL': '/bin/bash', 04:01:35 INFO - 'SHLVL': '1', 04:01:35 INFO - 'TERM': 'linux', 04:01:35 INFO - 'TMOUT': '86400', 04:01:35 INFO - 'USER': 'cltbld', 04:01:35 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:35 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:35 INFO - '_': '/tools/buildbot/bin/python'} 04:01:35 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:35 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 04:01:35 INFO - Return code: 0 04:01:35 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 04:01:35 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')]} 04:01:35 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:35 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')]} 04:01:35 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:35 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:35 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4'] in /builds/slave/test/build 04:01:35 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org blobuploader==1.2.4 04:01:35 INFO - Using env: {'DISPLAY': ':0', 04:01:35 INFO - 'HOME': '/home/cltbld', 04:01:35 INFO - 'LANG': 'en_US.UTF-8', 04:01:35 INFO - 'LANGUAGE': 'en_US:en', 04:01:35 INFO - 'LOGNAME': 'cltbld', 04:01:35 INFO - 'MAIL': '/var/mail/cltbld', 04:01:35 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:35 INFO - 'MOZ_NO_REMOTE': '1', 04:01:35 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:35 INFO - 'NO_EM_RESTART': '1', 04:01:35 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:35 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:35 INFO - 'PWD': '/builds/slave/test', 04:01:35 INFO - 'SHELL': '/bin/bash', 04:01:35 INFO - 'SHLVL': '1', 04:01:35 INFO - 'TERM': 'linux', 04:01:35 INFO - 'TMOUT': '86400', 04:01:35 INFO - 'USER': 'cltbld', 04:01:35 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:35 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:35 INFO - '_': '/tools/buildbot/bin/python'} 04:01:36 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:36 INFO - Collecting blobuploader==1.2.4 04:01:37 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 04:01:37 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 04:01:38 INFO - Installing collected packages: requests, docopt, blobuploader 04:01:38 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 04:01:38 INFO - Return code: 0 04:01:38 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:01:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:38 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:38 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:01:38 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:38 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:38 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config 04:01:38 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 04:01:38 INFO - Using env: {'DISPLAY': ':0', 04:01:38 INFO - 'HOME': '/home/cltbld', 04:01:38 INFO - 'LANG': 'en_US.UTF-8', 04:01:38 INFO - 'LANGUAGE': 'en_US:en', 04:01:38 INFO - 'LOGNAME': 'cltbld', 04:01:38 INFO - 'MAIL': '/var/mail/cltbld', 04:01:38 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:38 INFO - 'MOZ_NO_REMOTE': '1', 04:01:38 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:38 INFO - 'NO_EM_RESTART': '1', 04:01:38 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:38 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:38 INFO - 'PWD': '/builds/slave/test', 04:01:38 INFO - 'SHELL': '/bin/bash', 04:01:38 INFO - 'SHLVL': '1', 04:01:38 INFO - 'TERM': 'linux', 04:01:38 INFO - 'TMOUT': '86400', 04:01:38 INFO - 'USER': 'cltbld', 04:01:38 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:38 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:38 INFO - '_': '/tools/buildbot/bin/python'} 04:01:39 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:39 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 04:01:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 04:01:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 04:01:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 04:01:39 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 04:01:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 04:01:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 04:01:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 04:01:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 04:01:40 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 04:01:41 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 04:01:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 04:01:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 04:01:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 04:01:41 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 04:01:42 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 04:01:42 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 04:01:42 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 04:01:42 INFO - Running setup.py install for manifestparser: started 04:01:42 INFO - Running setup.py install for manifestparser: finished with status 'done' 04:01:42 INFO - Running setup.py install for mozcrash: started 04:01:42 INFO - Running setup.py install for mozcrash: finished with status 'done' 04:01:42 INFO - Running setup.py install for mozdebug: started 04:01:43 INFO - Running setup.py install for mozdebug: finished with status 'done' 04:01:43 INFO - Running setup.py install for mozdevice: started 04:01:43 INFO - Running setup.py install for mozdevice: finished with status 'done' 04:01:43 INFO - Running setup.py install for mozfile: started 04:01:43 INFO - Running setup.py install for mozfile: finished with status 'done' 04:01:43 INFO - Running setup.py install for mozhttpd: started 04:01:43 INFO - Running setup.py install for mozhttpd: finished with status 'done' 04:01:43 INFO - Running setup.py install for mozinfo: started 04:01:43 INFO - Running setup.py install for mozinfo: finished with status 'done' 04:01:43 INFO - Running setup.py install for mozInstall: started 04:01:44 INFO - Running setup.py install for mozInstall: finished with status 'done' 04:01:44 INFO - Running setup.py install for mozleak: started 04:01:44 INFO - Running setup.py install for mozleak: finished with status 'done' 04:01:44 INFO - Running setup.py install for mozlog: started 04:01:44 INFO - Running setup.py install for mozlog: finished with status 'done' 04:01:44 INFO - Running setup.py install for moznetwork: started 04:01:44 INFO - Running setup.py install for moznetwork: finished with status 'done' 04:01:44 INFO - Running setup.py install for mozprocess: started 04:01:45 INFO - Running setup.py install for mozprocess: finished with status 'done' 04:01:45 INFO - Running setup.py install for mozprofile: started 04:01:45 INFO - Running setup.py install for mozprofile: finished with status 'done' 04:01:45 INFO - Running setup.py install for mozrunner: started 04:01:45 INFO - Running setup.py install for mozrunner: finished with status 'done' 04:01:45 INFO - Running setup.py install for mozscreenshot: started 04:01:45 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 04:01:45 INFO - Running setup.py install for moztest: started 04:01:46 INFO - Running setup.py install for moztest: finished with status 'done' 04:01:46 INFO - Running setup.py install for mozversion: started 04:01:46 INFO - Running setup.py install for mozversion: finished with status 'done' 04:01:46 INFO - Successfully installed manifestparser-1.2 mozInstall-1.14 mozcrash-1.0 mozdebug-0.1 mozdevice-0.51 mozfile-1.2 mozhttpd-0.7 mozinfo-0.10 mozleak-0.1 mozlog-3.5 moznetwork-0.27 mozprocess-0.25 mozprofile-0.29 mozrunner-6.13 mozscreenshot-0.1 moztest-0.8 mozversion-1.4 04:01:46 INFO - Return code: 0 04:01:46 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:01:46 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')]} 04:01:46 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:46 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')]} 04:01:46 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:46 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config 04:01:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 04:01:46 INFO - Using env: {'DISPLAY': ':0', 04:01:46 INFO - 'HOME': '/home/cltbld', 04:01:46 INFO - 'LANG': 'en_US.UTF-8', 04:01:46 INFO - 'LANGUAGE': 'en_US:en', 04:01:46 INFO - 'LOGNAME': 'cltbld', 04:01:46 INFO - 'MAIL': '/var/mail/cltbld', 04:01:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:46 INFO - 'MOZ_NO_REMOTE': '1', 04:01:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:46 INFO - 'NO_EM_RESTART': '1', 04:01:46 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:46 INFO - 'PWD': '/builds/slave/test', 04:01:46 INFO - 'SHELL': '/bin/bash', 04:01:46 INFO - 'SHLVL': '1', 04:01:46 INFO - 'TERM': 'linux', 04:01:46 INFO - 'TMOUT': '86400', 04:01:46 INFO - 'USER': 'cltbld', 04:01:46 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:46 INFO - '_': '/tools/buildbot/bin/python'} 04:01:46 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:46 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 04:01:47 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.2 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 04:01:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 04:01:47 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)) 04:01:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 04:01:47 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)) 04:01:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 04:01:47 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)) 04:01:47 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 04:01:48 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)) 04:01:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 04:01:48 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)) 04:01:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 04:01:48 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)) 04:01:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 04:01:48 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.14 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 04:01:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 04:01:48 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)) 04:01:48 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 04:01:49 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)) 04:01:49 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 04:01:49 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)) 04:01:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 04:01:49 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)) 04:01:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 04:01:49 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.29 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 04:01:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 04:01:49 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)) 04:01:49 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 04:01:50 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)) 04:01:50 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 04:01:50 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)) 04:01:50 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 04:01:50 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)) 04:01:50 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 04:01:51 INFO - Downloading http://pypi.pub.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl 04:01:51 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:01:51 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:01:51 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 04:01:51 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.51->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:01:51 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.51->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:01:51 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.14->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 04:01:51 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 04:01:52 INFO - Installing collected packages: six, blessings 04:01:52 INFO - Successfully installed blessings-1.6 six-1.10.0 04:01:52 INFO - Return code: 0 04:01:52 INFO - Done creating virtualenv /builds/slave/test/build/venv. 04:01:52 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:01:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:01:52 INFO - Reading from file tmpfile_stdout 04:01:52 INFO - Reading from file tmpfile_stderr 04:01:52 INFO - Current package versions: 04:01:52 INFO - blessings == 1.6 04:01:52 INFO - blobuploader == 1.2.4 04:01:52 INFO - docopt == 0.6.1 04:01:52 INFO - functools32 == 3.2.3.post2 04:01:52 INFO - jsonschema == 2.5.1 04:01:52 INFO - manifestparser == 1.2 04:01:52 INFO - mozInstall == 1.14 04:01:52 INFO - mozcrash == 1.0 04:01:52 INFO - mozdebug == 0.1 04:01:52 INFO - mozdevice == 0.51 04:01:52 INFO - mozfile == 1.2 04:01:52 INFO - mozhttpd == 0.7 04:01:52 INFO - mozinfo == 0.10 04:01:52 INFO - mozleak == 0.1 04:01:52 INFO - mozlog == 3.5 04:01:52 INFO - moznetwork == 0.27 04:01:52 INFO - mozprocess == 0.25 04:01:52 INFO - mozprofile == 0.29 04:01:52 INFO - mozrunner == 6.13 04:01:52 INFO - mozscreenshot == 0.1 04:01:52 INFO - mozsystemmonitor == 0.3 04:01:52 INFO - moztest == 0.8 04:01:52 INFO - mozversion == 1.4 04:01:52 INFO - psutil == 3.1.1 04:01:52 INFO - requests == 1.2.3 04:01:52 INFO - six == 1.10.0 04:01:52 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:01:52 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')]} 04:01:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:01:52 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')]} 04:01:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:01:52 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:01:52 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/talos 04:01:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 04:01:52 INFO - Using env: {'DISPLAY': ':0', 04:01:52 INFO - 'HOME': '/home/cltbld', 04:01:52 INFO - 'LANG': 'en_US.UTF-8', 04:01:52 INFO - 'LANGUAGE': 'en_US:en', 04:01:52 INFO - 'LOGNAME': 'cltbld', 04:01:52 INFO - 'MAIL': '/var/mail/cltbld', 04:01:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:01:52 INFO - 'MOZ_NO_REMOTE': '1', 04:01:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:01:52 INFO - 'NO_EM_RESTART': '1', 04:01:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:01:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:01:52 INFO - 'PWD': '/builds/slave/test', 04:01:52 INFO - 'SHELL': '/bin/bash', 04:01:52 INFO - 'SHLVL': '1', 04:01:52 INFO - 'TERM': 'linux', 04:01:52 INFO - 'TMOUT': '86400', 04:01:52 INFO - 'USER': 'cltbld', 04:01:52 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:01:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:01:52 INFO - '_': '/tools/buildbot/bin/python'} 04:01:53 INFO - Ignoring indexes: https://pypi.python.org/simple 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 04:01:53 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 9)) 04:01:53 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 04:01:54 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:01:55 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/requests-2.18.3-py2.py3-none-any.whl (88kB) 04:01:55 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:01:55 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:01:55 INFO - Requirement already satisfied (use --upgrade to upgrade): six>=1.10.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozprofile>=0.25->-r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 04:01:55 INFO - Collecting chardet<3.1.0,>=3.0.2 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:01:56 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/chardet-3.0.4-py2.py3-none-any.whl (133kB) 04:01:56 INFO - Collecting urllib3<1.23,>=1.21.1 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:01:57 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/urllib3-1.22-py2.py3-none-any.whl (132kB) 04:01:57 INFO - Collecting certifi>=2017.4.17 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:01:58 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/certifi-2017.7.27.1-py2.py3-none-any.whl (349kB) 04:01:58 INFO - Collecting idna<2.6,>=2.5 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:01:59 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/idna-2.5-py2.py3-none-any.whl (55kB) 04:01:59 INFO - Installing collected packages: simplejson, chardet, urllib3, certifi, idna, requests 04:02:00 INFO - Found existing installation: requests 1.2.3 04:02:00 INFO - Uninstalling requests-1.2.3: 04:02:00 INFO - Successfully uninstalled requests-1.2.3 04:02:00 INFO - Successfully installed certifi-2017.7.27.1 chardet-3.0.4 idna-2.5 requests-2.18.3 simplejson-3.3.0 urllib3-1.22 04:02:00 INFO - Return code: 0 04:02:00 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 04:02:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:02:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:02:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:02:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:02:00 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x26672d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x283fa80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29e2930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, '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': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', '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 04:02:00 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema'] in /builds/slave/test/build 04:02:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema 04:02:00 INFO - Using env: {'DISPLAY': ':0', 04:02:00 INFO - 'HOME': '/home/cltbld', 04:02:00 INFO - 'LANG': 'en_US.UTF-8', 04:02:00 INFO - 'LANGUAGE': 'en_US:en', 04:02:00 INFO - 'LOGNAME': 'cltbld', 04:02:00 INFO - 'MAIL': '/var/mail/cltbld', 04:02:00 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:02:00 INFO - 'MOZ_NO_REMOTE': '1', 04:02:00 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:02:00 INFO - 'NO_EM_RESTART': '1', 04:02:00 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:02:00 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:02:00 INFO - 'PWD': '/builds/slave/test', 04:02:00 INFO - 'SHELL': '/bin/bash', 04:02:00 INFO - 'SHLVL': '1', 04:02:00 INFO - 'TERM': 'linux', 04:02:00 INFO - 'TMOUT': '86400', 04:02:00 INFO - 'USER': 'cltbld', 04:02:00 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:02:00 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:02:00 INFO - '_': '/tools/buildbot/bin/python'} 04:02:00 INFO - Ignoring indexes: https://pypi.python.org/simple 04:02:00 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 04:02:00 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 04:02:00 INFO - Return code: 0 04:02:00 INFO - Running post-action listener: _resource_record_post_action 04:02:00 INFO - Running post-action listener: _start_resource_monitoring 04:02:00 INFO - Starting resource monitoring. 04:02:00 INFO - [mozharness: 2017-11-06 12:02:00.806433Z] Finished create-virtualenv step (success) 04:02:00 INFO - [mozharness: 2017-11-06 12:02:00.806945Z] Running install step. 04:02:00 INFO - Running pre-action listener: _resource_record_pre_action 04:02:00 INFO - Running main action method: install 04:02:00 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:02:00 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:02:01 INFO - Reading from file tmpfile_stdout 04:02:01 INFO - Reading from file tmpfile_stderr 04:02:01 INFO - Detecting whether we're running mozinstall >=1.0... 04:02:01 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 04:02:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 04:02:01 INFO - Reading from file tmpfile_stdout 04:02:01 INFO - Output received: 04:02:01 INFO - Usage: mozinstall [options] installer 04:02:01 INFO - Options: 04:02:01 INFO - -h, --help show this help message and exit 04:02:01 INFO - -d DEST, --destination=DEST 04:02:01 INFO - Directory to install application into. [default: 04:02:01 INFO - "/builds/slave/test"] 04:02:01 INFO - --app=APP Application being installed. [default: firefox] 04:02:01 INFO - mkdir: /builds/slave/test/build/application 04:02:01 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'] 04:02:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 04:02:19 INFO - Reading from file tmpfile_stdout 04:02:19 INFO - Output received: 04:02:19 INFO - /builds/slave/test/build/application/firefox/firefox 04:02:19 INFO - Running post-action listener: _resource_record_post_action 04:02:19 INFO - [mozharness: 2017-11-06 12:02:19.905393Z] Finished install step (success) 04:02:19 INFO - [mozharness: 2017-11-06 12:02:19.905637Z] Running setup-mitmproxy step. 04:02:19 INFO - Running pre-action listener: _resource_record_pre_action 04:02:19 INFO - Running main action method: setup_mitmproxy 04:02:19 INFO - Skipping: mitmproxy is not required 04:02:19 INFO - Running post-action listener: _resource_record_post_action 04:02:19 INFO - [mozharness: 2017-11-06 12:02:19.906744Z] Finished setup-mitmproxy step (success) 04:02:19 INFO - [mozharness: 2017-11-06 12:02:19.906961Z] Running run-tests step. 04:02:19 INFO - Running pre-action listener: _resource_record_pre_action 04:02:19 INFO - Running pre-action listener: _set_gcov_prefix 04:02:19 INFO - Running main action method: run_tests 04:02:19 WARNING - Try message not found. 04:02:19 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 04:02:19 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 04:02:19 INFO - Python 2.7.3 04:02:19 INFO - Return code: 0 04:02:19 INFO - grabbing minidump binary from tooltool 04:02: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')]} 04:02:19 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 0x29dfad0>, '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 0x29e09d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29e0e60>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 04:02:19 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 04:02:19 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 04:02:19 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 04:02:19 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 04:02:20 INFO - Return code: 0 04:02:20 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 04:02:20 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 04:02:20 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 04:02:20 INFO - ENV: RUST_BACKTRACE is now full 04:02:20 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 04:02:20 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 04:02:20 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-004', '--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 04:02:20 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite g4-stylo-disabled-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-004 --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 04:02:20 INFO - Using env: {'DISPLAY': ':0', 04:02:20 INFO - 'HOME': '/home/cltbld', 04:02:20 INFO - 'LANG': 'en_US.UTF-8', 04:02:20 INFO - 'LANGUAGE': 'en_US:en', 04:02:20 INFO - 'LOGNAME': 'cltbld', 04:02:20 INFO - 'MAIL': '/var/mail/cltbld', 04:02:20 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:02:20 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 04:02:20 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:02:20 INFO - 'MOZ_NO_REMOTE': '1', 04:02:20 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:02:20 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:02:20 INFO - 'NO_EM_RESTART': '1', 04:02:20 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:02:20 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:02:20 INFO - 'PWD': '/builds/slave/test', 04:02:20 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:02:20 INFO - 'RUST_BACKTRACE': 'full', 04:02:20 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 04:02:20 INFO - 'SHELL': '/bin/bash', 04:02:20 INFO - 'SHLVL': '1', 04:02:20 INFO - 'TERM': 'linux', 04:02:20 INFO - 'TMOUT': '86400', 04:02:20 INFO - 'USER': 'cltbld', 04:02:20 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:02:20 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:02:20 INFO - '_': '/tools/buildbot/bin/python'} 04:02:20 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-004', '--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 04:02:20 INFO - mozversion application_buildid: 20171106103428 04:02:20 INFO - mozversion application_changeset: 8b9167b8a937e09f6673d4d7d693c6ac1c25a3d7 04:02:20 INFO - mozversion application_display_name: Nightly 04:02:20 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 04:02:20 INFO - mozversion application_name: Firefox 04:02:20 INFO - mozversion application_remotingname: firefox 04:02:20 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 04:02:20 INFO - mozversion application_vendor: Mozilla 04:02:20 INFO - mozversion application_version: 58.0a1 04:02:20 INFO - mozversion platform_buildid: 20171106103428 04:02:20 INFO - mozversion platform_changeset: 8b9167b8a937e09f6673d4d7d693c6ac1c25a3d7 04:02:20 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 04:02:20 INFO - mozversion platform_version: 58.0a1 04:02:20 INFO - using testdate: 1509969740 04:02:20 INFO - actual date: 1509969740 04:02:20 INFO - starting webserver on 'localhost:45408' 04:02:20 INFO - SUITE-START | Running 2 tests 04:02:20 INFO - TEST-START | basic_compositor_video 04:02:20 INFO - Initialising browser for basic_compositor_video test... 04:02:20 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:45408/getInfo.html -profile /tmp/tmpMhtmPz/profile 04:02:20 INFO - TEST-INFO | started process 4655 (/builds/slave/test/build/application/firefox/firefox http://localhost:45408/getInfo.html) 04:02:25 INFO - TEST-INFO | 4655: exit 0 04:02:26 INFO - Browser initialized. 04:02:26 INFO - Running cycle 1/1 for basic_compositor_video test... 04:02:26 INFO - Using env: {'DISPLAY': ':0', 04:02:26 INFO - 'HOME': '/home/cltbld', 04:02:26 INFO - 'JSGC_DISABLE_POISONING': '1', 04:02:26 INFO - 'LANG': 'en_US.UTF-8', 04:02:26 INFO - 'LANGUAGE': 'en_US:en', 04:02:26 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 04:02:26 INFO - 'LOGNAME': 'cltbld', 04:02:26 INFO - 'MAIL': '/var/mail/cltbld', 04:02:26 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:02:26 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 04:02:26 INFO - 'MOZ_CRASHREPORTER': '1', 04:02:26 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:02:26 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 04:02:26 INFO - 'MOZ_NO_REMOTE': '1', 04:02:26 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:02:26 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:02:26 INFO - 'NO_EM_RESTART': '1', 04:02:26 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:02:26 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:02:26 INFO - 'PWD': '/builds/slave/test', 04:02:26 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:02:26 INFO - 'RUST_BACKTRACE': 'full', 04:02:26 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 04:02:26 INFO - 'SHELL': '/bin/bash', 04:02:26 INFO - 'SHLVL': '1', 04:02:26 INFO - 'STYLO_FORCE_DISABLED': '1', 04:02:26 INFO - 'TERM': 'linux', 04:02:26 INFO - 'TMOUT': '86400', 04:02:26 INFO - 'USER': 'cltbld', 04:02:26 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:02:26 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:02:26 INFO - '_': '/tools/buildbot/bin/python'} 04:02:26 INFO - TEST-INFO | started process 4930 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpMhtmPz/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 04:02:26 INFO - PID 4930 | 04:02:26 INFO - PID 4930 | (/builds/slave/test/build/application/firefox/firefox:4982): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 04:02:26 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.67991601343785 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6675666666666666 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7421660859465733 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7426829268292685 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 3.958040897097625 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.058123732251523 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.409357954545455 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.356778523489932 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.245769230769234 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.556152777777778 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.170966101694907 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 9.950895522388064 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.236629213483146 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585714285714309 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.605777310924381 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.69596491228067 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.367424242424242 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.175893854748606 ms/frame 04:03:13 INFO - PID 4930 | 04:03:13 INFO - PID 4930 | Cycle 1(1): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:03:59 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.680921568627451 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6711612364243944 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.745706806282723 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.8085126582278475 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.017228915662649 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.0670020325203255 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.425148401826484 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3566275167785222 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.7043250950570314 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.495549450549453 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 9.648424437299035 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 9.757463414634158 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.112296296296295 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.814459459459476 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.554121338912124 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.980449101796411 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.495938697317989 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.05500000000001 ms/frame 04:03:59 INFO - PID 4930 | 04:03:59 INFO - PID 4930 | Cycle 1(2): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:04:45 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.682309417040359 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6660199833472105 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7932785415421397 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7503193350831152 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.149930843706777 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.847192307692306 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.650468369829685 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.541548672566369 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.682575757575753 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.602240896358554 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.456149825783962 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 10.10368686868688 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.07101476014761 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.696283422459864 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.448879668049793 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.127030303030297 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.58698841698844 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.23834269662919 ms/frame 04:04:45 INFO - PID 4930 | 04:04:45 INFO - PID 4930 | Cycle 1(3): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:05:31 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6790766648013429 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6655370524562867 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7626410105757935 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7204901117798799 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.066382113821138 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.1079363449692 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.509263157894735 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4374914089347124 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.6711436672967865 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.525994475138122 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.71492857142856 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 10.209234693877562 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.153104089219323 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.753736559139822 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.6053151260504 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.834940828402386 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.238576779026205 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.93196721311477 ms/frame 04:05:31 INFO - PID 4930 | 04:05:31 INFO - PID 4930 | Cycle 1(4): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:06:17 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.681732062780269 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6709983291562243 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7777073459715638 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7956552962298031 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.066659891598915 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9940219560878227 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.6153795180722885 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.498312937062937 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.716209523809521 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.555736111111117 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 9.838032786885242 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 9.805563725490192 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.239194756554314 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.63909574468082 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.50395833333332 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.768588235294095 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.23734082397002 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.874673913043491 ms/frame 04:06:17 INFO - PID 4930 | 04:06:17 INFO - PID 4930 | Cycle 1(5): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:07:03 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.681732062780269 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6669916666666666 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7892337507453786 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7355073720728527 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 3.851784338896022 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9767097415506956 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.445080367393801 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.396417657045837 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.705399239543728 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.572144846796661 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.453902439024391 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 10.205867346938769 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.240074906367036 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.639122340425526 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.397107438016553 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.979011976047877 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.584440154440165 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.992005494505484 ms/frame 04:07:03 INFO - PID 4930 | 04:07:03 INFO - PID 4930 | Cycle 1(6): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:07:27 INFO - PID 4930 | 04:07:27 INFO - PID 4930 | (/builds/slave/test/build/application/firefox/firefox:5060): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 04:07:27 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6747572544642857 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6670541666666665 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7435444509006393 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.725854184641933 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.178781337047353 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.124309278350517 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.5094619883040914 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.449620689655177 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.348395721925135 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.348930481283422 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.529157894736846 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 10.051532663316587 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.239569288389527 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.63901595744678 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.197682926829257 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.9802994011976 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.36515151515152 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.052209944751365 ms/frame 04:07:50 INFO - PID 4930 | 04:07:50 INFO - PID 4930 | Cycle 1(7): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:08:36 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.678975937325126 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6682402001668055 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7816656769596197 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7385317115551695 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.1499377593361 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.177453027139875 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.6375818181818174 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.49789335664336 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.456036363636363 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.58814245810056 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.170101694915255 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 10.152715736040623 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.238258426966299 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.586084656084639 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.4486929460581 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.56294797687861 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.45272900763358 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.238792134831487 ms/frame 04:08:36 INFO - PID 4930 | 04:08:36 INFO - PID 4930 | Cycle 1(8): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:09:22 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6801679731243002 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6717042606516288 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7424099883855984 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7249353448275864 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.077078804347826 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.159646569646568 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.5426328217237337 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4544991364421396 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.726774809160302 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5101101928374705 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.5299298245614 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 10.207806122448977 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.322301886792452 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.70080213903741 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.556778242677822 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.05313253012048 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.451202290076322 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.991428571428584 ms/frame 04:09:22 INFO - PID 4930 | 04:09:22 INFO - PID 4930 | Cycle 1(9): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:10:08 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6819058295964124 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.671658312447786 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7453315881326354 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.739895652173913 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0166465863453835 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.167229166666663 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.429822857142854 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3513484087102197 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.577481412639408 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.699871794871791 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.56551056338028 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 10.476361256544505 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.155204460966557 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.753010752688159 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.504520833333329 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.770617647058808 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.675000000000022 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.112472222222197 ms/frame 04:10:08 INFO - PID 4930 | 04:10:08 INFO - PID 4930 | Cycle 1(10): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:10:54 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6798936170212768 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6696118530884805 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.771410861865407 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.737936576889661 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.11008904109589 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.0241951710261565 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.5178077373974213 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.419948717948715 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.599197761194033 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.496359890109888 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.382474048442907 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 9.479976303317542 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.11151851851852 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.528026315789496 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.605609243697456 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.276104294478555 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.586872586872587 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.11702777777779 ms/frame 04:10:54 INFO - PID 4930 | 04:10:54 INFO - PID 4930 | Cycle 1(11): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:11:41 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_startup = 1.690645070422535 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6729765886287626 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7326905311778293 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7287078651685384 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_startup = 4.049507422402159 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.083102040816325 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_startup = 3.42179589509692 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1_inclip = 3.368308080808083 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.6607075471698165 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.683494318181818 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_startup = 10.382543252595157 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.480p.60fps.webm_scale_2_inclip = 9.95564676616915 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.159479553903351 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.752715053763426 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.768000000000013 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.124424242424235 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.45162213740457 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.114333333333343 ms/frame 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | Cycle 1(12): loaded http://localhost:45408/tests/video/video_playback.html (next: http://localhost:45408/tests/video/video_playback.html) 04:11:41 INFO - PID 4930 | __start_tp_report 04:11:41 INFO - PID 4930 | _x_x_mozilla_page_load 04:11:41 INFO - PID 4930 | _x_x_mozilla_page_load_details 04:11:41 INFO - PID 4930 | |i|pagename|runs| 04:11:41 INFO - PID 4930 | |0;240p.120fps.mp4_scale_1_startup;1.67991601343785;1.680921568627451;1.682309417040359;1.6790766648013429;1.681732062780269;1.681732062780269;1.6747572544642857;1.678975937325126;1.6801679731243002;1.6819058295964124;1.6798936170212768;1.690645070422535 04:11:41 INFO - PID 4930 | |1;240p.120fps.mp4_scale_1_inclip;1.6675666666666666;1.6711612364243944;1.6660199833472105;1.6655370524562867;1.6709983291562243;1.6669916666666666;1.6670541666666665;1.6682402001668055;1.6717042606516288;1.671658312447786;1.6696118530884805;1.6729765886287626 04:11:41 INFO - PID 4930 | |2;240p.120fps.mp4_scale_1.1_startup;1.7421660859465733;1.745706806282723;1.7932785415421397;1.7626410105757935;1.7777073459715638;1.7892337507453786;1.7435444509006393;1.7816656769596197;1.7424099883855984;1.7453315881326354;1.771410861865407;1.7326905311778293 04:11:41 INFO - PID 4930 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7426829268292685;1.8085126582278475;1.7503193350831152;1.7204901117798799;1.7956552962298031;1.7355073720728527;1.725854184641933;1.7385317115551695;1.7249353448275864;1.739895652173913;1.737936576889661;1.7287078651685384 04:11:41 INFO - PID 4930 | |4;240p.120fps.mp4_scale_2_startup;3.958040897097625;4.017228915662649;4.149930843706777;4.066382113821138;4.066659891598915;3.851784338896022;4.178781337047353;4.1499377593361;4.077078804347826;4.0166465863453835;4.11008904109589;4.049507422402159 04:11:41 INFO - PID 4930 | |5;240p.120fps.mp4_scale_2_inclip;4.058123732251523;4.0670020325203255;3.847192307692306;4.1079363449692;3.9940219560878227;3.9767097415506956;4.124309278350517;4.177453027139875;4.159646569646568;4.167229166666663;4.0241951710261565;4.083102040816325 04:11:41 INFO - PID 4930 | |6;480p.60fps.webm_scale_1_startup;3.409357954545455;3.425148401826484;3.650468369829685;3.509263157894735;3.6153795180722885;3.445080367393801;3.5094619883040914;3.6375818181818174;3.5426328217237337;3.429822857142854;3.5178077373974213;3.42179589509692 04:11:41 INFO - PID 4930 | |7;480p.60fps.webm_scale_1_inclip;3.356778523489932;3.3566275167785222;3.541548672566369;3.4374914089347124;3.498312937062937;3.396417657045837;3.449620689655177;3.49789335664336;3.4544991364421396;3.3513484087102197;3.419948717948715;3.368308080808083 04:11:41 INFO - PID 4930 | |8;480p.60fps.webm_scale_1.1_startup;5.245769230769234;5.7043250950570314;5.682575757575753;5.6711436672967865;5.716209523809521;5.705399239543728;5.348395721925135;5.456036363636363;5.726774809160302;5.577481412639408;5.599197761194033;5.6607075471698165 04:11:41 INFO - PID 4930 | |9;480p.60fps.webm_scale_1.1_inclip;5.556152777777778;5.495549450549453;5.602240896358554;5.525994475138122;5.555736111111117;5.572144846796661;5.348930481283422;5.58814245810056;5.5101101928374705;5.699871794871791;5.496359890109888;5.683494318181818 04:11:41 INFO - PID 4930 | |10;480p.60fps.webm_scale_2_startup;10.170966101694907;9.648424437299035;10.456149825783962;10.71492857142856;9.838032786885242;10.453902439024391;10.529157894736846;10.170101694915255;10.5299298245614;10.56551056338028;10.382474048442907;10.382543252595157 04:11:41 INFO - PID 4930 | |11;480p.60fps.webm_scale_2_inclip;9.950895522388064;9.757463414634158;10.10368686868688;10.209234693877562;9.805563725490192;10.205867346938769;10.051532663316587;10.152715736040623;10.207806122448977;10.476361256544505;9.479976303317542;9.95564676616915 04:11:41 INFO - PID 4930 | |12;1080p.60fps.mp4_scale_1_startup;11.236629213483146;11.112296296296295;11.07101476014761;11.153104089219323;11.239194756554314;11.240074906367036;11.239569288389527;11.238258426966299;11.322301886792452;11.155204460966557;11.11151851851852;11.159479553903351 04:11:41 INFO - PID 4930 | |13;1080p.60fps.mp4_scale_1_inclip;10.585714285714309;10.814459459459476;10.696283422459864;10.753736559139822;10.63909574468082;10.639122340425526;10.63901595744678;10.586084656084639;10.70080213903741;10.753010752688159;10.528026315789496;10.752715053763426 04:11:41 INFO - PID 4930 | |14;1080p.60fps.mp4_scale_1.1_startup;12.605777310924381;12.554121338912124;12.448879668049793;12.6053151260504;12.50395833333332;12.397107438016553;12.197682926829257;12.4486929460581;12.556778242677822;12.504520833333329;12.605609243697456;12.768000000000013 04:11:41 INFO - PID 4930 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.69596491228067;11.980449101796411;12.127030303030297;11.834940828402386;11.768588235294095;11.979011976047877;11.9802994011976;11.56294797687861;12.05313253012048;11.770617647058808;12.276104294478555;12.124424242424235 04:11:41 INFO - PID 4930 | |16;1080p.60fps.mp4_scale_2_startup;11.367424242424242;11.495938697317989;11.58698841698844;11.238576779026205;11.23734082397002;11.584440154440165;11.36515151515152;11.45272900763358;11.451202290076322;11.675000000000022;11.586872586872587;11.45162213740457 04:11:41 INFO - PID 4930 | |17;1080p.60fps.mp4_scale_2_inclip;11.175893854748606;11.05500000000001;11.23834269662919;10.93196721311477;10.874673913043491;10.992005494505484;11.052209944751365;11.238792134831487;10.991428571428584;11.112472222222197;11.11702777777779;11.114333333333343 04:11:41 INFO - PID 4930 | __end_tp_report 04:11:41 INFO - PID 4930 | __start_cc_report 04:11:41 INFO - PID 4930 | _x_x_mozilla_cycle_collect,568 04:11:41 INFO - PID 4930 | __end_cc_report 04:11:41 INFO - PID 4930 | __startTimestamp1509970301375__endTimestamp 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | ------- Summary: start ------- 04:11:41 INFO - PID 4930 | Number of tests: 18 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#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 04:11:41 INFO - PID 4930 | 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 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:1.67 Median:1.67 stddev:0.00 (0.2%) stddev-sans-first:0.00 04:11:41 INFO - PID 4930 | 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 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.76 Median:1.77 stddev:0.02 (1.2%) stddev-sans-first:0.02 04:11:41 INFO - PID 4930 | Values: 1.7 1.7 1.8 1.8 1.8 1.8 1.7 1.8 1.7 1.7 1.8 1.7 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.75 Median:1.74 stddev:0.03 (1.6%) stddev-sans-first:0.03 04:11:41 INFO - PID 4930 | Values: 1.7 1.8 1.8 1.7 1.8 1.7 1.7 1.7 1.7 1.7 1.7 1.7 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.06 Median:4.07 stddev:0.09 (2.2%) stddev-sans-first:0.09 04:11:41 INFO - PID 4930 | Values: 4.0 4.0 4.1 4.1 4.1 3.9 4.2 4.1 4.1 4.0 4.1 4.0 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.07 Median:4.10 stddev:0.10 (2.3%) stddev-sans-first:0.10 04:11:41 INFO - PID 4930 | Values: 4.1 4.1 3.8 4.1 4.0 4.0 4.1 4.2 4.2 4.2 4.0 4.1 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.51 Median:3.51 stddev:0.09 (2.5%) stddev-sans-first:0.09 04:11:41 INFO - PID 4930 | Values: 3.4 3.4 3.7 3.5 3.6 3.4 3.5 3.6 3.5 3.4 3.5 3.4 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.43 Median:3.44 stddev:0.06 (1.9%) stddev-sans-first:0.06 04:11:41 INFO - PID 4930 | Values: 3.4 3.4 3.5 3.4 3.5 3.4 3.4 3.5 3.5 3.4 3.4 3.4 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.59 Median:5.68 stddev:0.16 (2.8%) stddev-sans-first:0.12 04:11:41 INFO - PID 4930 | Values: 5.2 5.7 5.7 5.7 5.7 5.7 5.3 5.5 5.7 5.6 5.6 5.7 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.55 Median:5.56 stddev:0.09 (1.7%) stddev-sans-first:0.10 04:11:41 INFO - PID 4930 | Values: 5.6 5.5 5.6 5.5 5.6 5.6 5.3 5.6 5.5 5.7 5.5 5.7 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.32 Median:10.53 stddev:0.31 (3.0%) stddev-sans-first:0.32 04:11:41 INFO - PID 4930 | Values: 10.2 9.6 10.5 10.7 9.8 10.5 10.5 10.2 10.5 10.6 10.4 10.4 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:10.03 Median:9.98 stddev:0.26 (2.6%) stddev-sans-first:0.27 04:11:41 INFO - PID 4930 | Values: 10.0 9.8 10.1 10.2 9.8 10.2 10.1 10.2 10.2 10.5 9.5 10.0 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.19 Median:11.24 stddev:0.07 (0.7%) stddev-sans-first:0.08 04:11:41 INFO - PID 4930 | Values: 11.2 11.1 11.1 11.2 11.2 11.2 11.2 11.2 11.3 11.2 11.1 11.2 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.67 Median:10.70 stddev:0.09 (0.8%) stddev-sans-first:0.08 04:11:41 INFO - PID 4930 | Values: 10.6 10.8 10.7 10.8 10.6 10.6 10.6 10.6 10.7 10.8 10.5 10.8 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.52 Median:12.56 stddev:0.14 (1.1%) stddev-sans-first:0.14 04:11:41 INFO - PID 4930 | Values: 12.6 12.6 12.4 12.6 12.5 12.4 12.2 12.4 12.6 12.5 12.6 12.8 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.93 Median:11.98 stddev:0.21 (1.7%) stddev-sans-first:0.20 04:11:41 INFO - PID 4930 | Values: 11.7 12.0 12.1 11.8 11.8 12.0 12.0 11.6 12.1 11.8 12.3 12.1 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.46 Median:11.47 stddev:0.14 (1.2%) stddev-sans-first:0.14 04:11:41 INFO - PID 4930 | Values: 11.4 11.5 11.6 11.2 11.2 11.6 11.4 11.5 11.5 11.7 11.6 11.5 04:11:41 INFO - PID 4930 | 04:11:41 INFO - PID 4930 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:11.07 Median:11.11 stddev:0.11 (1.0%) stddev-sans-first:0.12 04:11:41 INFO - PID 4930 | Values: 11.2 11.1 11.2 10.9 10.9 11.0 11.1 11.2 11.0 11.1 11.1 11.1 04:11:41 INFO - PID 4930 | -------- Summary: end -------- 04:11:41 INFO - PID 4930 | 04:11:41 INFO - TEST-INFO | 4930: exit 0 04:11:41 INFO - TEST-OK | basic_compositor_video | took 561574ms 04:11:41 INFO - TEST-START | glvideo 04:11:41 INFO - Initialising browser for glvideo test... 04:11:41 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:45408/getInfo.html -profile /tmp/tmp8WTzyr/profile 04:11:41 INFO - TEST-INFO | started process 6224 (/builds/slave/test/build/application/firefox/firefox http://localhost:45408/getInfo.html) 04:11:47 INFO - TEST-INFO | 6224: exit 0 04:11:47 INFO - Browser initialized. 04:11:47 INFO - Running cycle 1/1 for glvideo test... 04:11:47 INFO - Using env: {'DISPLAY': ':0', 04:11:47 INFO - 'HOME': '/home/cltbld', 04:11:47 INFO - 'JSGC_DISABLE_POISONING': '1', 04:11:47 INFO - 'LANG': 'en_US.UTF-8', 04:11:47 INFO - 'LANGUAGE': 'en_US:en', 04:11:47 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 04:11:47 INFO - 'LOGNAME': 'cltbld', 04:11:47 INFO - 'MAIL': '/var/mail/cltbld', 04:11:47 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:11:47 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 04:11:47 INFO - 'MOZ_CRASHREPORTER': '1', 04:11:47 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:11:47 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 04:11:47 INFO - 'MOZ_NO_REMOTE': '1', 04:11:47 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:11:47 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:11:47 INFO - 'NO_EM_RESTART': '1', 04:11:47 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:11:47 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:11:47 INFO - 'PWD': '/builds/slave/test', 04:11:47 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:11:47 INFO - 'RUST_BACKTRACE': 'full', 04:11:47 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 04:11:47 INFO - 'SHELL': '/bin/bash', 04:11:47 INFO - 'SHLVL': '1', 04:11:47 INFO - 'STYLO_FORCE_DISABLED': '1', 04:11:47 INFO - 'TERM': 'linux', 04:11:47 INFO - 'TMOUT': '86400', 04:11:47 INFO - 'USER': 'cltbld', 04:11:47 INFO - 'XDG_SESSION_COOKIE': 'c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688', 04:11:47 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:11:47 INFO - '_': '/tools/buildbot/bin/python'} 04:11:47 INFO - TEST-INFO | started process 6502 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp8WTzyr/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 04:11:48 INFO - PID 6502 | 04:11:48 INFO - PID 6502 | (/builds/slave/test/build/application/firefox/firefox:6554): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 04:11:48 INFO - PID 6502 | 04:11:49 INFO - PID 6502 | [talos glvideo result] Mean tick time across 100 ticks: 7.761499999999999 ms 04:11:49 INFO - PID 6502 | Cycle 1(1): loaded http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html) 04:11:51 INFO - PID 6502 | [talos glvideo result] Mean tick time across 100 ticks: 6.56095 ms 04:11:51 INFO - PID 6502 | Cycle 1(2): loaded http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html) 04:11:52 INFO - PID 6502 | [talos glvideo result] Mean tick time across 100 ticks: 6.656550000000001 ms 04:11:52 INFO - PID 6502 | Cycle 1(3): loaded http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html) 04:11:53 INFO - PID 6502 | [talos glvideo result] Mean tick time across 100 ticks: 6.5962 ms 04:11:53 INFO - PID 6502 | Cycle 1(4): loaded http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html) 04:11:55 INFO - PID 6502 | [talos glvideo result] Mean tick time across 100 ticks: 6.55745 ms 04:11:55 INFO - PID 6502 | Cycle 1(5): loaded http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:45408/tests/webgl/benchmarks/video/video_upload.html) 04:11:55 INFO - PID 6502 | __start_tp_report 04:11:55 INFO - PID 6502 | _x_x_mozilla_page_load 04:11:55 INFO - PID 6502 | _x_x_mozilla_page_load_details 04:11:55 INFO - PID 6502 | |i|pagename|runs| 04:11:55 INFO - PID 6502 | |0;Mean tick time across 100 ticks: ;7.761499999999999;6.56095;6.656550000000001;6.5962;6.55745 04:11:55 INFO - PID 6502 | __end_tp_report 04:11:55 INFO - PID 6502 | __start_cc_report 04:11:55 INFO - PID 6502 | _x_x_mozilla_cycle_collect,274 04:11:55 INFO - PID 6502 | __end_cc_report 04:11:55 INFO - PID 6502 | __startTimestamp1509970315524__endTimestamp 04:11:55 INFO - PID 6502 | 04:11:55 INFO - PID 6502 | ------- Summary: start ------- 04:11:55 INFO - PID 6502 | Number of tests: 1 04:11:55 INFO - PID 6502 | 04:11:55 INFO - PID 6502 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.83 Median:6.60 stddev:0.52 (7.9%) stddev-sans-first:0.05 04:11:55 INFO - PID 6502 | Values: 7.8 6.6 6.7 6.6 6.6 04:11:55 INFO - PID 6502 | -------- Summary: end -------- 04:11:55 INFO - PID 6502 | 04:11:55 INFO - PID 6502 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 04:11:56 INFO - TEST-INFO | 6502: exit 0 04:11:56 INFO - TEST-OK | glvideo | took 14219ms 04:11:56 INFO - SUITE-END | took 575s 04:11:56 INFO - Completed test suite (00:09:36) 04:11:56 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.610310825402953, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.67991601343785, 1.680921568627451, 1.682309417040359, 1.6790766648013429, 1.681732062780269, 1.681732062780269, 1.6747572544642857, 1.678975937325126, 1.6801679731243002, 1.6819058295964124, 1.6798936170212768, 1.690645070422535], "value": 1.680921568627451, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6675666666666666, 1.6711612364243944, 1.6660199833472105, 1.6655370524562867, 1.6709983291562243, 1.6669916666666666, 1.6670541666666665, 1.6682402001668055, 1.6717042606516288, 1.671658312447786, 1.6696118530884805, 1.6729765886287626], "value": 1.6696118530884805, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7421660859465733, 1.745706806282723, 1.7932785415421397, 1.7626410105757935, 1.7777073459715638, 1.7892337507453786, 1.7435444509006393, 1.7816656769596197, 1.7424099883855984, 1.7453315881326354, 1.771410861865407, 1.7326905311778293], "value": 1.7626410105757935, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7426829268292685, 1.8085126582278475, 1.7503193350831152, 1.7204901117798799, 1.7956552962298031, 1.7355073720728527, 1.725854184641933, 1.7385317115551695, 1.7249353448275864, 1.739895652173913, 1.737936576889661, 1.7287078651685384], "value": 1.737936576889661, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.958040897097625, 4.017228915662649, 4.149930843706777, 4.066382113821138, 4.066659891598915, 3.851784338896022, 4.178781337047353, 4.1499377593361, 4.077078804347826, 4.0166465863453835, 4.11008904109589, 4.049507422402159], "value": 4.066659891598915, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.058123732251523, 4.0670020325203255, 3.847192307692306, 4.1079363449692, 3.9940219560878227, 3.9767097415506956, 4.124309278350517, 4.177453027139875, 4.159646569646568, 4.167229166666663, 4.0241951710261565, 4.083102040816325], "value": 4.083102040816325, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.409357954545455, 3.425148401826484, 3.650468369829685, 3.509263157894735, 3.6153795180722885, 3.445080367393801, 3.5094619883040914, 3.6375818181818174, 3.5426328217237337, 3.429822857142854, 3.5178077373974213, 3.42179589509692], "value": 3.5094619883040914, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.356778523489932, 3.3566275167785222, 3.541548672566369, 3.4374914089347124, 3.498312937062937, 3.396417657045837, 3.449620689655177, 3.49789335664336, 3.4544991364421396, 3.3513484087102197, 3.419948717948715, 3.368308080808083], "value": 3.4374914089347124, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.245769230769234, 5.7043250950570314, 5.682575757575753, 5.6711436672967865, 5.716209523809521, 5.705399239543728, 5.348395721925135, 5.456036363636363, 5.726774809160302, 5.577481412639408, 5.599197761194033, 5.6607075471698165], "value": 5.6711436672967865, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.556152777777778, 5.495549450549453, 5.602240896358554, 5.525994475138122, 5.555736111111117, 5.572144846796661, 5.348930481283422, 5.58814245810056, 5.5101101928374705, 5.699871794871791, 5.496359890109888, 5.683494318181818], "value": 5.555736111111117, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.170966101694907, 9.648424437299035, 10.456149825783962, 10.71492857142856, 9.838032786885242, 10.453902439024391, 10.529157894736846, 10.170101694915255, 10.5299298245614, 10.56551056338028, 10.382474048442907, 10.382543252595157], "value": 10.453902439024391, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.950895522388064, 9.757463414634158, 10.10368686868688, 10.209234693877562, 9.805563725490192, 10.205867346938769, 10.051532663316587, 10.152715736040623, 10.207806122448977, 10.476361256544505, 9.479976303317542, 9.95564676616915], "value": 10.10368686868688, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.236629213483146, 11.112296296296295, 11.07101476014761, 11.153104089219323, 11.239194756554314, 11.240074906367036, 11.239569288389527, 11.238258426966299, 11.322301886792452, 11.155204460966557, 11.11151851851852, 11.159479553903351], "value": 11.159479553903351, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.585714285714309, 10.814459459459476, 10.696283422459864, 10.753736559139822, 10.63909574468082, 10.639122340425526, 10.63901595744678, 10.586084656084639, 10.70080213903741, 10.753010752688159, 10.528026315789496, 10.752715053763426], "value": 10.696283422459864, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.605777310924381, 12.554121338912124, 12.448879668049793, 12.6053151260504, 12.50395833333332, 12.397107438016553, 12.197682926829257, 12.4486929460581, 12.556778242677822, 12.504520833333329, 12.605609243697456, 12.768000000000013], "value": 12.504520833333329, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.69596491228067, 11.980449101796411, 12.127030303030297, 11.834940828402386, 11.768588235294095, 11.979011976047877, 11.9802994011976, 11.56294797687861, 12.05313253012048, 11.770617647058808, 12.276104294478555, 12.124424242424235], "value": 11.9802994011976, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.367424242424242, 11.495938697317989, 11.58698841698844, 11.238576779026205, 11.23734082397002, 11.584440154440165, 11.36515151515152, 11.45272900763358, 11.451202290076322, 11.675000000000022, 11.586872586872587, 11.45162213740457], "value": 11.45272900763358, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.175893854748606, 11.05500000000001, 11.23834269662919, 10.93196721311477, 10.874673913043491, 10.992005494505484, 11.052209944751365, 11.238792134831487, 10.991428571428584, 11.112472222222197, 11.11702777777779, 11.114333333333343], "value": 11.05500000000001, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [7.761499999999999, 6.56095, 6.656550000000001, 6.5962, 6.55745], "value": 6.578575, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]} 04:11:56 INFO - Return code: 0 04:11:56 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 04:11:56 INFO - # TBPL SUCCESS # 04:11:56 INFO - Running post-action listener: _package_coverage_data 04:11:56 INFO - Running post-action listener: _resource_record_post_action 04:11:56 INFO - [mozharness: 2017-11-06 12:11:56.695739Z] Finished run-tests step (success) 04:11:56 INFO - Running post-run listener: _resource_record_post_run 04:11:56 INFO - Total resource usage - Wall time: 596s; CPU: 38.0%; Read bytes: 8773632; Write bytes: 433438720; Read time: 508; Write time: 372456 04:11:56 INFO - TinderboxPrint: CPU usage
38.4% 04:11:56 INFO - TinderboxPrint: I/O read bytes / time
8,773,632 / 508 04:11:56 INFO - TinderboxPrint: I/O write bytes / time
433,438,720 / 372,456 04:11:56 INFO - TinderboxPrint: CPU idle
2,878.0 (61.6%) 04:11:56 INFO - TinderboxPrint: CPU system
302.3 (6.5%) 04:11:56 INFO - TinderboxPrint: CPU user
1,480.1 (31.7%) 04:11:56 INFO - TinderboxPrint: Swap in / out
0 / 0 04:11:56 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 130109440; Read time: 0; Write time: 159408 04:11:56 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 04:11:56 INFO - run-tests - Wall time: 577s; CPU: 39.0%; Read bytes: 8773632; Write bytes: 302161920; Read time: 508; Write time: 212728 04:11:57 INFO - Running post-run listener: _upload_blobber_files 04:11:57 INFO - Blob upload gear active. 04:11:57 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 04:11:57 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 04:11:57 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/test/oauth.txt', '-b', 'Firefox', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 04:11:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/test/oauth.txt -b Firefox -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 04:11:57 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:339: SNIMissingWarning: An HTTPS request has been made, but the SNI (Subject Name Indication) extension to TLS is not available on this platform. This may cause the server to present an incorrect TLS certificate, which can cause validation failures. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:57 INFO - SNIMissingWarning 04:11:57 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:57 INFO - InsecurePlatformWarning 04:11:57 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 04:11:57 INFO - SubjectAltNameWarning 04:11:57 INFO - (blobuploader) - INFO - Open directory for files ... 04:11:57 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log ... 04:11:57 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:11:57 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:11:57 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:57 INFO - InsecurePlatformWarning 04:11:57 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 04:11:57 INFO - SubjectAltNameWarning 04:11:58 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:58 INFO - InsecurePlatformWarning 04:11:58 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_raw.log: uploaded 04:11:58 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:11:58 INFO - (blobuploader) - INFO - Done attempting. 04:11:58 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 04:11:58 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:11:58 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:11:58 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:58 INFO - InsecurePlatformWarning 04:11:58 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 04:11:58 INFO - SubjectAltNameWarning 04:11:58 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:58 INFO - InsecurePlatformWarning 04:11:59 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 04:11:59 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:11:59 INFO - (blobuploader) - INFO - Done attempting. 04:11:59 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log ... 04:11:59 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:11:59 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:11:59 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:59 INFO - InsecurePlatformWarning 04:11:59 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 04:11:59 INFO - SubjectAltNameWarning 04:11:59 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:11:59 INFO - InsecurePlatformWarning 04:12:00 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_errorsummary.log: uploaded 04:12:00 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:12:00 INFO - (blobuploader) - INFO - Done attempting. 04:12:00 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 04:12:00 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:12:00 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:12:00 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:12:00 INFO - InsecurePlatformWarning 04:12:00 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 04:12:00 INFO - SubjectAltNameWarning 04:12:04 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:12:04 INFO - InsecurePlatformWarning 04:12:04 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 04:12:04 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:12:04 INFO - (blobuploader) - INFO - Done attempting. 04:12:04 INFO - (blobuploader) - INFO - Iteration through files over. 04:12:04 INFO - Return code: 0 04:12:04 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 04:12:04 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 04:12:04 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6d08396fc57af53379ed433f3b046fc1ae7962760e461dcfb7a0dcc4987fefe935f1f457ec90056a3682f684bab43d67cde05dcebde1d1c0344248d03aa1b98b", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a3ca99c5b213141ba5a58cb4a2a4f026ea91d8a73908d659922a8eb9d89b7f9a5c1e7c2151c2fa016341a7811c572aa3f9bb81b62281a509e6d9344a6518f7a9", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/19844da48e8efb113beb0d3691003ff4c662cc0816a8a21b66a624757f09dfbc8040624e072d310f352f6a9f26f9c383fbe2eb391bc232119232d172fa9617bc", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3c6a830b0eeeaffb9107cca3773d49cae7c796a42cceeb1b65321388327b761ef8d8676e757552a858862c26245ff3116ed35df420255d994b7816f163ba646c"} 04:12:04 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 04:12:04 INFO - Writing to file /builds/slave/test/properties/blobber_files 04:12:04 INFO - Contents: 04:12:04 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6d08396fc57af53379ed433f3b046fc1ae7962760e461dcfb7a0dcc4987fefe935f1f457ec90056a3682f684bab43d67cde05dcebde1d1c0344248d03aa1b98b", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a3ca99c5b213141ba5a58cb4a2a4f026ea91d8a73908d659922a8eb9d89b7f9a5c1e7c2151c2fa016341a7811c572aa3f9bb81b62281a509e6d9344a6518f7a9", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/19844da48e8efb113beb0d3691003ff4c662cc0816a8a21b66a624757f09dfbc8040624e072d310f352f6a9f26f9c383fbe2eb391bc232119232d172fa9617bc", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3c6a830b0eeeaffb9107cca3773d49cae7c796a42cceeb1b65321388327b761ef8d8676e757552a858862c26245ff3116ed35df420255d994b7816f163ba646c"} 04:12:04 INFO - Running post-run listener: copy_logs_to_upload_dir 04:12:04 INFO - Copying logs to upload dir... 04:12:04 INFO - mkdir: /builds/slave/test/build/upload/logs 04:12:04 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=655.325657 ========= master_lag: 0.03 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 55 secs) (at 2017-11-06 04:12:05.013292) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-06 04:12:05.016670) ========= 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=c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6d08396fc57af53379ed433f3b046fc1ae7962760e461dcfb7a0dcc4987fefe935f1f457ec90056a3682f684bab43d67cde05dcebde1d1c0344248d03aa1b98b", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a3ca99c5b213141ba5a58cb4a2a4f026ea91d8a73908d659922a8eb9d89b7f9a5c1e7c2151c2fa016341a7811c572aa3f9bb81b62281a509e6d9344a6518f7a9", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/19844da48e8efb113beb0d3691003ff4c662cc0816a8a21b66a624757f09dfbc8040624e072d310f352f6a9f26f9c383fbe2eb391bc232119232d172fa9617bc", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3c6a830b0eeeaffb9107cca3773d49cae7c796a42cceeb1b65321388327b761ef8d8676e757552a858862c26245ff3116ed35df420255d994b7816f163ba646c"} build_url:https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011522 build_url: 'https://queue.taskcluster.net/v1/task/L7hcqitnSHakEZCJN1QsWQ/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6d08396fc57af53379ed433f3b046fc1ae7962760e461dcfb7a0dcc4987fefe935f1f457ec90056a3682f684bab43d67cde05dcebde1d1c0344248d03aa1b98b", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a3ca99c5b213141ba5a58cb4a2a4f026ea91d8a73908d659922a8eb9d89b7f9a5c1e7c2151c2fa016341a7811c572aa3f9bb81b62281a509e6d9344a6518f7a9", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/19844da48e8efb113beb0d3691003ff4c662cc0816a8a21b66a624757f09dfbc8040624e072d310f352f6a9f26f9c383fbe2eb391bc232119232d172fa9617bc", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/3c6a830b0eeeaffb9107cca3773d49cae7c796a42cceeb1b65321388327b761ef8d8676e757552a858862c26245ff3116ed35df420255d994b7816f163ba646c"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-06 04:12:05.050605) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-06 04:12:05.050938) ========= 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=c6927cf182745ad25b1d38b9000001fe-1509969667.116535-2095738688 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004614 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-06 04:12:05.135054) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-06 04:12:05.135369) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-06 04:12:05.135643) ========= ========= Total master_lag: 0.19 =========