builder: mozilla-central_ubuntu64_hw_test-g4-e10s-pgo slave: talos-linux64-ix-086 starttime: 1510263809.32 results: success (0) revision: 277e2ae05f747e257eaa73e36f1bc31b98a21af9 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.317817) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.318243) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.318518) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.337193) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.337472) ========= 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=438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-11-09 13:43:29-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 46.3M=0s 2017-11-09 13:43:29 (46.3 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.100212 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.455995) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.456320) ========= 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=438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.020150 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:29.507094) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-11-09 13:43:29.507453) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 277e2ae05f747e257eaa73e36f1bc31b98a21af9 --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 277e2ae05f747e257eaa73e36f1bc31b98a21af9 --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=438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-11-09 13:43:29,458 truncating revision to first 12 chars 2017-11-09 13:43:29,458 Setting DEBUG logging. 2017-11-09 13:43:29,458 attempt 1/10 2017-11-09 13:43:29,458 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/277e2ae05f74?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-11-09 13:43:30,582 unpacking tar archive at: mozilla-central-277e2ae05f74/testing/mozharness/ program finished with exit code 0 elapsedTime=1.724238 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-11-09 13:43:31.249204) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:31.249540) ========= script_repo_revision: 277e2ae05f747e257eaa73e36f1bc31b98a21af9 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:31.249912) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:31.250175) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-09 13:43:31.264960) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 12 mins, 42 secs) (at 2017-11-09 13:43:31.265251) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 13:43:31 INFO - MultiFileLogger online at 20171109 13:43:31 in /builds/slave/test 13:43:31 INFO - Run as scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 13:43:31 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 13:43:31 INFO - {'append_to_log': False, 13:43:31 INFO - 'base_work_dir': '/builds/slave/test', 13:43:31 INFO - 'blob_upload_branch': 'Firefox', 13:43:31 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 13:43:31 INFO - 'branch': 'Firefox', 13:43:31 INFO - 'buildbot_json_path': 'buildprops.json', 13:43:31 INFO - 'code_coverage': False, 13:43:31 INFO - 'config_files': ('talos/linux_config.py',), 13:43:31 INFO - 'default_actions': ('clobber', 13:43:31 INFO - 'read-buildbot-config', 13:43:31 INFO - 'download-and-extract', 13:43:31 INFO - 'populate-webroot', 13:43:31 INFO - 'create-virtualenv', 13:43:31 INFO - 'install', 13:43:31 INFO - 'setup-mitmproxy', 13:43:31 INFO - 'run-tests'), 13:43:31 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 13:43:31 INFO - 'disable_ccov_upload': False, 13:43:31 INFO - 'disable_stylo': False, 13:43:31 INFO - 'download_minidump_stackwalk': True, 13:43:31 INFO - 'download_symbols': 'ondemand', 13:43:31 INFO - 'e10s': False, 13:43:31 INFO - 'enable_stylo': False, 13:43:31 INFO - 'enable_webrender': False, 13:43:31 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 13:43:31 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 13:43:31 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 13:43:31 INFO - 'gecko_profile': False, 13:43:31 INFO - 'gecko_profile_interval': 0, 13:43:31 INFO - 'installer_path': 'installer.exe', 13:43:31 INFO - 'jsd_code_coverage': False, 13:43:31 INFO - 'log_level': 'info', 13:43:31 INFO - 'log_name': 'talos', 13:43:31 INFO - 'log_to_console': True, 13:43:31 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 13:43:31 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 13:43:31 INFO - 'opt_config_files': (), 13:43:31 INFO - 'pip_index': False, 13:43:31 INFO - 'suite': 'g4-e10s', 13:43:31 INFO - 'system_bits': '32', 13:43:31 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 13:43:31 INFO - 'title': 'talos-linux64-ix-086', 13:43:31 INFO - 'tooltool_cache': '/builds/tooltool_cache', 13:43:31 INFO - 'use_talos_json': True, 13:43:31 INFO - 'verify': 'False', 13:43:31 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 13:43:31 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 13:43:31 INFO - 'work_dir': 'build'} 13:43:31 INFO - [mozharness: 2017-11-09 21:43:31.357903Z] Running clobber step. 13:43:31 INFO - Running pre-action listener: _resource_record_pre_action 13:43:31 INFO - Running main action method: clobber 13:43:31 INFO - rmtree: /builds/slave/test/build 13:43:31 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 13:43:32 INFO - Running post-action listener: _resource_record_post_action 13:43:32 INFO - [mozharness: 2017-11-09 21:43:32.451229Z] Finished clobber step (success) 13:43:32 INFO - [mozharness: 2017-11-09 21:43:32.451326Z] Running read-buildbot-config step. 13:43:32 INFO - Running pre-action listener: _resource_record_pre_action 13:43:32 INFO - Running main action method: read_buildbot_config 13:43:32 INFO - Using buildbot properties: 13:43:32 INFO - { 13:43:32 INFO - "project": "", 13:43:32 INFO - "product": "firefox", 13:43:32 INFO - "who": "apavel@mozilla.com", 13:43:32 INFO - "installer_path": "public/build/target.tar.bz2", 13:43:32 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-e10s", 13:43:32 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 13:43:32 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-e10s", 13:43:32 INFO - "stage_platform": "linux64-pgo", 13:43:32 INFO - "basedir": "/builds/slave/test", 13:43:32 INFO - "buildnumber": 271, 13:43:32 INFO - "platform": "ubuntu64_hw", 13:43:32 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 13:43:32 INFO - "slavebuilddir": "test", 13:43:32 INFO - "taskId": "eynXn8Y7SOO_IokQeuQLtw", 13:43:32 INFO - "branch": "mozilla-central", 13:43:32 INFO - "script_repo_revision": "production", 13:43:32 INFO - "revision": "277e2ae05f747e257eaa73e36f1bc31b98a21af9", 13:43:32 INFO - "slavename": "talos-linux64-ix-086", 13:43:32 INFO - "repo_path": "mozilla-central" 13:43:32 INFO - } 13:43:32 INFO - Finding installer, test and symbols from parent task. 13:43:32 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/eynXn8Y7SOO_IokQeuQLtw'}, attempt #1 13:43:32 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/eynXn8Y7SOO_IokQeuQLtw'}, attempt #1 13:43:33 INFO - Task dependencies: OOKTvOD1R1qhr3I1YZEfpA 13:43:33 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA'}, attempt #1 13:43:33 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2 13:43:33 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.test_packages.json 13:43:33 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.crashreporter-symbols.zip 13:43:33 INFO - Running post-action listener: _resource_record_post_action 13:43:33 INFO - [mozharness: 2017-11-09 21:43:33.935658Z] Finished read-buildbot-config step (success) 13:43:33 INFO - [mozharness: 2017-11-09 21:43:33.935876Z] Running download-and-extract step. 13:43:33 INFO - Running pre-action listener: _resource_record_pre_action 13:43:33 INFO - Running main action method: download_and_extract 13:43:33 INFO - mkdir: /builds/slave/test/build/tests 13:43: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')]} 13:43:33 INFO - trying https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.test_packages.json 13:43:33 INFO - Downloading https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 13:43:33 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 13:43:34 INFO - Downloaded 989 bytes. 13:43:34 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 13:43:34 INFO - Using the following test package requirements: 13:43:34 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 13:43:34 INFO - u'common': [u'target.common.tests.zip'], 13:43:34 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 13:43:34 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 13:43:34 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 13:43:34 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 13:43:34 INFO - u'mozbase': [u'target.common.tests.zip'], 13:43:34 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 13:43:34 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 13:43:34 INFO - u'web-platform': [u'target.common.tests.zip', 13:43:34 INFO - u'target.web-platform.tests.tar.gz'], 13:43:34 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 13:43:34 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 13:43:34 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.common.tests.zip 13:43:34 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.common.tests.zip'}, attempt #1 13:43:34 INFO - Fetch https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.common.tests.zip into memory 13:43:35 INFO - Content-Length response header: 58636720 13:43:35 INFO - Bytes received: 58636720 13:43:46 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.talos.tests.zip 13:43:46 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.talos.tests.zip'}, attempt #1 13:43:46 INFO - Fetch https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.talos.tests.zip into memory 13:43:47 INFO - Content-Length response header: 18771918 13:43:47 INFO - Bytes received: 18771918 13:43:48 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:43:48 INFO - trying https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2 13:43:48 INFO - Downloading https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 13:43:48 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 13:43:49 INFO - Downloaded 63188917 bytes. 13:43:49 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2 13:43:49 INFO - mkdir: /builds/slave/test/properties 13:43:49 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 13:43:49 INFO - Writing to file /builds/slave/test/properties/build_url 13:43:49 INFO - Contents: 13:43:49 INFO - build_url:https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2 13:43:49 INFO - Running post-action listener: _resource_record_post_action 13:43:49 INFO - Running post-action listener: find_tests_for_verification 13:43:49 INFO - Running post-action listener: set_extra_try_arguments 13:43:49 INFO - [mozharness: 2017-11-09 21:43:49.791656Z] Finished download-and-extract step (success) 13:43:49 INFO - [mozharness: 2017-11-09 21:43:49.791939Z] Running populate-webroot step. 13:43:49 INFO - Running pre-action listener: _resource_record_pre_action 13:43:49 INFO - Running main action method: populate_webroot 13:43:49 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 13:43:49 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['tresize', 13:43:49 INFO - 'tcanvasmark']}, 13:43:49 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 13:43:49 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['dromaeo_css', 13:43:49 INFO - 'kraken']}, 13:43:49 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:43:49 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 13:43:49 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'tests': ['damp', 'tps']}, 13:43:49 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['damp', 'tps']}, 13:43:49 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 13:43:49 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['dromaeo_dom']}, 13:43:49 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 13:43:49 INFO - 'glvideo', 13:43:49 INFO - 'displaylist_mutate']}, 13:43:49 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['basic_compositor_video', 13:43:49 INFO - 'glvideo']}, 13:43:49 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 13:43:49 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['ts_paint_webext', 13:43:49 INFO - 'tp5o_webext']}, 13:43:49 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 13:43:49 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:43:49 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:43:49 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:43:49 INFO - 'talos_options': ['--mitmproxy', 13:43:49 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:43:49 INFO - '--firstNonBlankPaint'], 13:43:49 INFO - 'tests': ['tp6_google_heavy', 13:43:49 INFO - 'tp6_youtube_heavy', 13:43:49 INFO - 'tp6_amazon_heavy', 13:43:49 INFO - 'tp6_facebook_heavy']}, 13:43:49 INFO - 'other-e10s': {'tests': ['a11yr', 13:43:49 INFO - 'ts_paint', 13:43:49 INFO - 'tpaint', 13:43:49 INFO - 'sessionrestore', 13:43:49 INFO - 'sessionrestore_many_windows', 13:43:49 INFO - 'sessionrestore_no_auto_restore', 13:43:49 INFO - 'tabpaint', 13:43:49 INFO - 'cpstartup']}, 13:43:49 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['a11yr', 13:43:49 INFO - 'ts_paint', 13:43:49 INFO - 'tpaint', 13:43:49 INFO - 'sessionrestore', 13:43:49 INFO - 'sessionrestore_many_windows', 13:43:49 INFO - 'sessionrestore_no_auto_restore', 13:43:49 INFO - 'tabpaint', 13:43:49 INFO - 'cpstartup']}, 13:43:49 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 13:43:49 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 13:43:49 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['perf_reftest_singletons']}, 13:43:49 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['perf_reftest']}, 13:43:49 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 13:43:49 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['speedometer']}, 13:43:49 INFO - 'svgr-e10s': {'tests': ['tsvgx', 13:43:49 INFO - 'tsvgr_opacity', 13:43:49 INFO - 'tart', 13:43:49 INFO - 'tscrollx', 13:43:49 INFO - 'tsvg_static']}, 13:43:49 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['tsvgx', 13:43:49 INFO - 'tsvgr_opacity', 13:43:49 INFO - 'tart', 13:43:49 INFO - 'tscrollx', 13:43:49 INFO - 'tsvg_static']}, 13:43:49 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 13:43:49 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'talos_options': ['--disable-stylo'], 13:43:49 INFO - 'tests': ['tp5o']}, 13:43:49 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:43:49 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:43:49 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:43:49 INFO - 'talos_options': ['--mitmproxy', 13:43:49 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:43:49 INFO - '--firstNonBlankPaint'], 13:43:49 INFO - 'tests': ['tp6_google', 13:43:49 INFO - 'tp6_youtube', 13:43:49 INFO - 'tp6_amazon', 13:43:49 INFO - 'tp6_facebook']}, 13:43:49 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:43:49 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:43:49 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:43:49 INFO - 'talos_options': ['--disable-stylo', 13:43:49 INFO - '--mitmproxy', 13:43:49 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:43:49 INFO - '--firstNonBlankPaint'], 13:43:49 INFO - 'tests': ['tp6_google', 13:43:49 INFO - 'tp6_youtube', 13:43:49 INFO - 'tp6_amazon', 13:43:49 INFO - 'tp6_facebook']}, 13:43:49 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 13:43:49 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 13:43:49 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 13:43:49 INFO - 'talos_options': ['--stylo-threads=1', 13:43:49 INFO - '--mitmproxy', 13:43:49 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 13:43:49 INFO - '--firstNonBlankPaint'], 13:43:49 INFO - 'tests': ['tp6_google', 13:43:49 INFO - 'tp6_youtube', 13:43:49 INFO - 'tp6_amazon', 13:43:49 INFO - 'tp6_facebook']}, 13:43:49 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'talos_options': ['--xperf_path', 13:43:49 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:43:49 INFO - 'tests': ['tp5n']}, 13:43:49 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 13:43:49 INFO - 'talos_options': ['--disable-stylo', 13:43:49 INFO - '--xperf_path', 13:43:49 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 13:43:49 INFO - 'tests': ['tp5n']}}} 13:43:49 INFO - Running post-action listener: _resource_record_post_action 13:43:49 INFO - [mozharness: 2017-11-09 21:43:49.821721Z] Finished populate-webroot step (success) 13:43:49 INFO - [mozharness: 2017-11-09 21:43:49.821841Z] Running create-virtualenv step. 13:43:49 INFO - Running pre-action listener: _resource_record_pre_action 13:43:49 INFO - Running main action method: create_virtualenv 13:43:49 INFO - Creating virtualenv /builds/slave/test/build/venv 13:43:49 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 13:43:49 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 13:43:49 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 13:43:50 INFO - Using real prefix '/usr' 13:43:50 INFO - New python executable in /builds/slave/test/build/venv/bin/python 13:43:50 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 13:43:52 INFO - Installing setuptools, pip, wheel...done. 13:43:52 INFO - Return code: 0 13:43:52 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 13:43: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')]} 13:43:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:43: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')]} 13:43:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:43:52 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:43:52 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 13:43:52 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 13:43:52 INFO - Using env: {'DISPLAY': ':0', 13:43:52 INFO - 'HOME': '/home/cltbld', 13:43:52 INFO - 'LANG': 'en_US.UTF-8', 13:43:52 INFO - 'LANGUAGE': 'en_US:en', 13:43:52 INFO - 'LOGNAME': 'cltbld', 13:43:52 INFO - 'MAIL': '/var/mail/cltbld', 13:43:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:43:52 INFO - 'MOZ_NO_REMOTE': '1', 13:43:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:43:52 INFO - 'NO_EM_RESTART': '1', 13:43:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:43:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:43:52 INFO - 'PWD': '/builds/slave/test', 13:43:52 INFO - 'SHELL': '/bin/bash', 13:43:52 INFO - 'SHLVL': '1', 13:43:52 INFO - 'TERM': 'linux', 13:43:52 INFO - 'TMOUT': '86400', 13:43:52 INFO - 'USER': 'cltbld', 13:43:52 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:43:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:43:52 INFO - '_': '/tools/buildbot/bin/python'} 13:43:52 INFO - Ignoring indexes: https://pypi.python.org/simple 13:43:52 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 13:43:52 INFO - Return code: 0 13:43:52 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 13:43: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')]} 13:43:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:43: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')]} 13:43:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:43:52 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:43:52 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 13:43:52 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 13:43:52 INFO - Using env: {'DISPLAY': ':0', 13:43:52 INFO - 'HOME': '/home/cltbld', 13:43:52 INFO - 'LANG': 'en_US.UTF-8', 13:43:52 INFO - 'LANGUAGE': 'en_US:en', 13:43:52 INFO - 'LOGNAME': 'cltbld', 13:43:52 INFO - 'MAIL': '/var/mail/cltbld', 13:43:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:43:52 INFO - 'MOZ_NO_REMOTE': '1', 13:43:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:43:52 INFO - 'NO_EM_RESTART': '1', 13:43:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:43:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:43:52 INFO - 'PWD': '/builds/slave/test', 13:43:52 INFO - 'SHELL': '/bin/bash', 13:43:52 INFO - 'SHLVL': '1', 13:43:52 INFO - 'TERM': 'linux', 13:43:52 INFO - 'TMOUT': '86400', 13:43:52 INFO - 'USER': 'cltbld', 13:43:52 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:43:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:43:52 INFO - '_': '/tools/buildbot/bin/python'} 13:43:53 INFO - Ignoring indexes: https://pypi.python.org/simple 13:43:53 INFO - Collecting psutil>=3.1.1 13:43:54 INFO - Installing collected packages: psutil 13:43:54 INFO - Successfully installed psutil-3.1.1 13:43:54 INFO - Return code: 0 13:43:54 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 13:43:54 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')]} 13:43:54 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:43:54 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')]} 13:43:54 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:43:54 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:43:54 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 13:43:54 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 13:43:54 INFO - Using env: {'DISPLAY': ':0', 13:43:54 INFO - 'HOME': '/home/cltbld', 13:43:54 INFO - 'LANG': 'en_US.UTF-8', 13:43:54 INFO - 'LANGUAGE': 'en_US:en', 13:43:54 INFO - 'LOGNAME': 'cltbld', 13:43:54 INFO - 'MAIL': '/var/mail/cltbld', 13:43:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:43:54 INFO - 'MOZ_NO_REMOTE': '1', 13:43:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:43:54 INFO - 'NO_EM_RESTART': '1', 13:43:54 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:43:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:43:54 INFO - 'PWD': '/builds/slave/test', 13:43:54 INFO - 'SHELL': '/bin/bash', 13:43:54 INFO - 'SHLVL': '1', 13:43:54 INFO - 'TERM': 'linux', 13:43:54 INFO - 'TMOUT': '86400', 13:43:54 INFO - 'USER': 'cltbld', 13:43:54 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:43:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:43:54 INFO - '_': '/tools/buildbot/bin/python'} 13:43:54 INFO - Ignoring indexes: https://pypi.python.org/simple 13:43:54 INFO - Collecting mozsystemmonitor==0.3 13:43:55 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 13:43:55 INFO - Installing collected packages: mozsystemmonitor 13:43:55 INFO - Successfully installed mozsystemmonitor-0.3 13:43:55 INFO - Return code: 0 13:43:55 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 13:43:55 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:43:55 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:43:55 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:43:55 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:43:55 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:43:55 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 13:43:55 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 13:43:55 INFO - Using env: {'DISPLAY': ':0', 13:43:55 INFO - 'HOME': '/home/cltbld', 13:43:55 INFO - 'LANG': 'en_US.UTF-8', 13:43:55 INFO - 'LANGUAGE': 'en_US:en', 13:43:55 INFO - 'LOGNAME': 'cltbld', 13:43:55 INFO - 'MAIL': '/var/mail/cltbld', 13:43:55 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:43:55 INFO - 'MOZ_NO_REMOTE': '1', 13:43:55 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:43:55 INFO - 'NO_EM_RESTART': '1', 13:43:55 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:43:55 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:43:55 INFO - 'PWD': '/builds/slave/test', 13:43:55 INFO - 'SHELL': '/bin/bash', 13:43:55 INFO - 'SHLVL': '1', 13:43:55 INFO - 'TERM': 'linux', 13:43:55 INFO - 'TMOUT': '86400', 13:43:55 INFO - 'USER': 'cltbld', 13:43:55 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:43:55 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:43:55 INFO - '_': '/tools/buildbot/bin/python'} 13:43:56 INFO - Ignoring indexes: https://pypi.python.org/simple 13:43:56 INFO - Collecting jsonschema==2.5.1 13:43:57 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 13:43:57 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 13:43:59 INFO - Installing collected packages: functools32, jsonschema 13:43:59 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 13:43:59 INFO - Return code: 0 13:43:59 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 13:43:59 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:43:59 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:43:59 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:43:59 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:43:59 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:43:59 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2'] in /builds/slave/test/build 13:43:59 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org functools32==3.2.3-2 13:43:59 INFO - Using env: {'DISPLAY': ':0', 13:43:59 INFO - 'HOME': '/home/cltbld', 13:43:59 INFO - 'LANG': 'en_US.UTF-8', 13:43:59 INFO - 'LANGUAGE': 'en_US:en', 13:43:59 INFO - 'LOGNAME': 'cltbld', 13:43:59 INFO - 'MAIL': '/var/mail/cltbld', 13:43:59 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:43:59 INFO - 'MOZ_NO_REMOTE': '1', 13:43:59 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:43:59 INFO - 'NO_EM_RESTART': '1', 13:43:59 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:43:59 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:43:59 INFO - 'PWD': '/builds/slave/test', 13:43:59 INFO - 'SHELL': '/bin/bash', 13:43:59 INFO - 'SHLVL': '1', 13:43:59 INFO - 'TERM': 'linux', 13:43:59 INFO - 'TMOUT': '86400', 13:43:59 INFO - 'USER': 'cltbld', 13:43:59 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:43:59 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:43:59 INFO - '_': '/tools/buildbot/bin/python'} 13:43:59 INFO - Ignoring indexes: https://pypi.python.org/simple 13:43:59 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 13:43:59 INFO - Return code: 0 13:43:59 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 13:43:59 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:43:59 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:43:59 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:43:59 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:43:59 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:43:59 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4'] in /builds/slave/test/build 13:43:59 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org blobuploader==1.2.4 13:43:59 INFO - Using env: {'DISPLAY': ':0', 13:43:59 INFO - 'HOME': '/home/cltbld', 13:43:59 INFO - 'LANG': 'en_US.UTF-8', 13:43:59 INFO - 'LANGUAGE': 'en_US:en', 13:43:59 INFO - 'LOGNAME': 'cltbld', 13:43:59 INFO - 'MAIL': '/var/mail/cltbld', 13:43:59 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:43:59 INFO - 'MOZ_NO_REMOTE': '1', 13:43:59 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:43:59 INFO - 'NO_EM_RESTART': '1', 13:43:59 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:43:59 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:43:59 INFO - 'PWD': '/builds/slave/test', 13:43:59 INFO - 'SHELL': '/bin/bash', 13:43:59 INFO - 'SHLVL': '1', 13:43:59 INFO - 'TERM': 'linux', 13:43:59 INFO - 'TMOUT': '86400', 13:43:59 INFO - 'USER': 'cltbld', 13:43:59 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:43:59 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:43:59 INFO - '_': '/tools/buildbot/bin/python'} 13:44:00 INFO - Ignoring indexes: https://pypi.python.org/simple 13:44:00 INFO - Collecting blobuploader==1.2.4 13:44:01 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 13:44:02 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 13:44:03 INFO - Installing collected packages: requests, docopt, blobuploader 13:44:03 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 13:44:03 INFO - Return code: 0 13:44:03 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:44:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:44:03 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:44:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:44:03 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:44:03 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:44:03 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 13:44:03 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 13:44:03 INFO - Using env: {'DISPLAY': ':0', 13:44:03 INFO - 'HOME': '/home/cltbld', 13:44:03 INFO - 'LANG': 'en_US.UTF-8', 13:44:03 INFO - 'LANGUAGE': 'en_US:en', 13:44:03 INFO - 'LOGNAME': 'cltbld', 13:44:03 INFO - 'MAIL': '/var/mail/cltbld', 13:44:03 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:44:03 INFO - 'MOZ_NO_REMOTE': '1', 13:44:03 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:44:03 INFO - 'NO_EM_RESTART': '1', 13:44:03 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:44:03 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:44:03 INFO - 'PWD': '/builds/slave/test', 13:44:03 INFO - 'SHELL': '/bin/bash', 13:44:03 INFO - 'SHLVL': '1', 13:44:03 INFO - 'TERM': 'linux', 13:44:03 INFO - 'TMOUT': '86400', 13:44:03 INFO - 'USER': 'cltbld', 13:44:03 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:44:03 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:44:03 INFO - '_': '/tools/buildbot/bin/python'} 13:44:03 INFO - Ignoring indexes: https://pypi.python.org/simple 13:44:03 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:44:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:44:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:44:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:44:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:44:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:44:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:44:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:44:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:44:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:44:05 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:44:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:44:06 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:44:06 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:44:06 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:44:06 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:44:06 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:44:07 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 13:44:07 INFO - Running setup.py install for manifestparser: started 13:44:07 INFO - Running setup.py install for manifestparser: finished with status 'done' 13:44:07 INFO - Running setup.py install for mozcrash: started 13:44:07 INFO - Running setup.py install for mozcrash: finished with status 'done' 13:44:07 INFO - Running setup.py install for mozdebug: started 13:44:07 INFO - Running setup.py install for mozdebug: finished with status 'done' 13:44:07 INFO - Running setup.py install for mozdevice: started 13:44:07 INFO - Running setup.py install for mozdevice: finished with status 'done' 13:44:07 INFO - Running setup.py install for mozfile: started 13:44:08 INFO - Running setup.py install for mozfile: finished with status 'done' 13:44:08 INFO - Running setup.py install for mozhttpd: started 13:44:08 INFO - Running setup.py install for mozhttpd: finished with status 'done' 13:44:08 INFO - Running setup.py install for mozinfo: started 13:44:08 INFO - Running setup.py install for mozinfo: finished with status 'done' 13:44:08 INFO - Running setup.py install for mozInstall: started 13:44:08 INFO - Running setup.py install for mozInstall: finished with status 'done' 13:44:08 INFO - Running setup.py install for mozleak: started 13:44:09 INFO - Running setup.py install for mozleak: finished with status 'done' 13:44:09 INFO - Running setup.py install for mozlog: started 13:44:09 INFO - Running setup.py install for mozlog: finished with status 'done' 13:44:09 INFO - Running setup.py install for moznetwork: started 13:44:09 INFO - Running setup.py install for moznetwork: finished with status 'done' 13:44:09 INFO - Running setup.py install for mozprocess: started 13:44:09 INFO - Running setup.py install for mozprocess: finished with status 'done' 13:44:09 INFO - Running setup.py install for mozprofile: started 13:44:09 INFO - Running setup.py install for mozprofile: finished with status 'done' 13:44:09 INFO - Running setup.py install for mozrunner: started 13:44:10 INFO - Running setup.py install for mozrunner: finished with status 'done' 13:44:10 INFO - Running setup.py install for mozscreenshot: started 13:44:10 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 13:44:10 INFO - Running setup.py install for moztest: started 13:44:10 INFO - Running setup.py install for moztest: finished with status 'done' 13:44:10 INFO - Running setup.py install for mozversion: started 13:44:10 INFO - Running setup.py install for mozversion: finished with status 'done' 13:44:11 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 13:44:11 INFO - Return code: 0 13:44:11 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:44:11 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')]} 13:44:11 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:44:11 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')]} 13:44:11 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:44:11 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:44:11 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 13:44:11 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 13:44:11 INFO - Using env: {'DISPLAY': ':0', 13:44:11 INFO - 'HOME': '/home/cltbld', 13:44:11 INFO - 'LANG': 'en_US.UTF-8', 13:44:11 INFO - 'LANGUAGE': 'en_US:en', 13:44:11 INFO - 'LOGNAME': 'cltbld', 13:44:11 INFO - 'MAIL': '/var/mail/cltbld', 13:44:11 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:44:11 INFO - 'MOZ_NO_REMOTE': '1', 13:44:11 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:44:11 INFO - 'NO_EM_RESTART': '1', 13:44:11 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:44:11 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:44:11 INFO - 'PWD': '/builds/slave/test', 13:44:11 INFO - 'SHELL': '/bin/bash', 13:44:11 INFO - 'SHLVL': '1', 13:44:11 INFO - 'TERM': 'linux', 13:44:11 INFO - 'TMOUT': '86400', 13:44:11 INFO - 'USER': 'cltbld', 13:44:11 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:44:11 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:44:11 INFO - '_': '/tools/buildbot/bin/python'} 13:44:11 INFO - Ignoring indexes: https://pypi.python.org/simple 13:44:11 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 13:44:11 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)) 13:44:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 13:44:12 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)) 13:44:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 13:44:12 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)) 13:44:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 13:44:12 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)) 13:44:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 13:44:12 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)) 13:44:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 13:44:12 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)) 13:44:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 13:44:13 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.10 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7)) 13:44:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 13:44:13 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)) 13:44:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 13:44:13 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9)) 13:44:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 13:44:13 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.5 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 13:44:13 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 13:44:13 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11)) 13:44:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 13:44:14 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)) 13:44:14 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 13:44:14 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)) 13:44:14 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 13:44:14 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.13 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 13:44:14 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 13:44:14 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15)) 13:44:14 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 13:44:14 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.8 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16)) 13:44:14 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 13:44:15 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)) 13:44:15 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 13:44:16 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl 13:44:16 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)) 13:44:16 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)) 13:44:16 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)) 13:44:16 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)) 13:44:16 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)) 13:44:16 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)) 13:44:16 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 13:44:17 INFO - Installing collected packages: six, blessings 13:44:17 INFO - Successfully installed blessings-1.6 six-1.10.0 13:44:17 INFO - Return code: 0 13:44:17 INFO - Done creating virtualenv /builds/slave/test/build/venv. 13:44:17 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:44:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:44:17 INFO - Reading from file tmpfile_stdout 13:44:17 INFO - Reading from file tmpfile_stderr 13:44:17 INFO - Current package versions: 13:44:17 INFO - blessings == 1.6 13:44:17 INFO - blobuploader == 1.2.4 13:44:17 INFO - docopt == 0.6.1 13:44:17 INFO - functools32 == 3.2.3.post2 13:44:17 INFO - jsonschema == 2.5.1 13:44:17 INFO - manifestparser == 1.2 13:44:17 INFO - mozInstall == 1.14 13:44:17 INFO - mozcrash == 1.0 13:44:17 INFO - mozdebug == 0.1 13:44:17 INFO - mozdevice == 0.51 13:44:17 INFO - mozfile == 1.2 13:44:17 INFO - mozhttpd == 0.7 13:44:17 INFO - mozinfo == 0.10 13:44:17 INFO - mozleak == 0.1 13:44:17 INFO - mozlog == 3.5 13:44:17 INFO - moznetwork == 0.27 13:44:17 INFO - mozprocess == 0.25 13:44:17 INFO - mozprofile == 0.29 13:44:17 INFO - mozrunner == 6.13 13:44:17 INFO - mozscreenshot == 0.1 13:44:17 INFO - mozsystemmonitor == 0.3 13:44:17 INFO - moztest == 0.8 13:44:17 INFO - mozversion == 1.4 13:44:17 INFO - psutil == 3.1.1 13:44:17 INFO - requests == 1.2.3 13:44:17 INFO - six == 1.10.0 13:44:17 INFO - Installing None into virtualenv /builds/slave/test/build/venv 13:44:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:44:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:44:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:44:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:44:17 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:44:17 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 13:44:17 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 13:44:17 INFO - Using env: {'DISPLAY': ':0', 13:44:17 INFO - 'HOME': '/home/cltbld', 13:44:17 INFO - 'LANG': 'en_US.UTF-8', 13:44:17 INFO - 'LANGUAGE': 'en_US:en', 13:44:17 INFO - 'LOGNAME': 'cltbld', 13:44:17 INFO - 'MAIL': '/var/mail/cltbld', 13:44:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:44:17 INFO - 'MOZ_NO_REMOTE': '1', 13:44:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:44:17 INFO - 'NO_EM_RESTART': '1', 13:44:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:44:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:44:17 INFO - 'PWD': '/builds/slave/test', 13:44:17 INFO - 'SHELL': '/bin/bash', 13:44:17 INFO - 'SHLVL': '1', 13:44:17 INFO - 'TERM': 'linux', 13:44:17 INFO - 'TMOUT': '86400', 13:44:17 INFO - 'USER': 'cltbld', 13:44:17 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:44:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:44:17 INFO - '_': '/tools/buildbot/bin/python'} 13:44:18 INFO - Ignoring indexes: https://pypi.python.org/simple 13:44:18 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)) 13:44:18 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)) 13:44:18 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)) 13:44:18 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)) 13:44:18 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)) 13:44:18 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)) 13:44:18 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)) 13:44:18 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)) 13:44:18 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)) 13:44:18 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 13:44:19 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:44:20 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/requests-2.18.3-py2.py3-none-any.whl (88kB) 13:44:20 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)) 13:44:20 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)) 13:44:20 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)) 13:44:20 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)) 13:44:21 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/chardet-3.0.4-py2.py3-none-any.whl (133kB) 13:44:21 INFO - Collecting urllib3<1.23,>=1.21.1 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:44:22 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/urllib3-1.22-py2.py3-none-any.whl (132kB) 13:44:22 INFO - Collecting certifi>=2017.4.17 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:44:23 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/certifi-2017.7.27.1-py2.py3-none-any.whl (349kB) 13:44:23 INFO - Collecting idna<2.6,>=2.5 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 13:44:24 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/idna-2.5-py2.py3-none-any.whl (55kB) 13:44:24 INFO - Installing collected packages: simplejson, chardet, urllib3, certifi, idna, requests 13:44:25 INFO - Found existing installation: requests 1.2.3 13:44:25 INFO - Uninstalling requests-1.2.3: 13:44:25 INFO - Successfully uninstalled requests-1.2.3 13:44:25 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 13:44:25 INFO - Return code: 0 13:44:25 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 13:44:25 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')]} 13:44:25 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 13:44:25 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')]} 13:44:25 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 13:44:25 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 0x28832d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2a5da80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2bfcd70>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, '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': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', '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 13:44:25 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 13:44:25 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 13:44:25 INFO - Using env: {'DISPLAY': ':0', 13:44:25 INFO - 'HOME': '/home/cltbld', 13:44:25 INFO - 'LANG': 'en_US.UTF-8', 13:44:25 INFO - 'LANGUAGE': 'en_US:en', 13:44:25 INFO - 'LOGNAME': 'cltbld', 13:44:25 INFO - 'MAIL': '/var/mail/cltbld', 13:44:25 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:44:25 INFO - 'MOZ_NO_REMOTE': '1', 13:44:25 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:44:25 INFO - 'NO_EM_RESTART': '1', 13:44:25 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:44:25 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:44:25 INFO - 'PWD': '/builds/slave/test', 13:44:25 INFO - 'SHELL': '/bin/bash', 13:44:25 INFO - 'SHLVL': '1', 13:44:25 INFO - 'TERM': 'linux', 13:44:25 INFO - 'TMOUT': '86400', 13:44:25 INFO - 'USER': 'cltbld', 13:44:25 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:44:25 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:44:25 INFO - '_': '/tools/buildbot/bin/python'} 13:44:25 INFO - Ignoring indexes: https://pypi.python.org/simple 13:44:25 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 13:44:25 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 13:44:25 INFO - Return code: 0 13:44:25 INFO - Running post-action listener: _resource_record_post_action 13:44:25 INFO - Running post-action listener: _start_resource_monitoring 13:44:25 INFO - Starting resource monitoring. 13:44:25 INFO - [mozharness: 2017-11-09 21:44:25.815015Z] Finished create-virtualenv step (success) 13:44:25 INFO - [mozharness: 2017-11-09 21:44:25.815546Z] Running install step. 13:44:25 INFO - Running pre-action listener: _resource_record_pre_action 13:44:25 INFO - Running main action method: install 13:44:25 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 13:44:25 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 13:44:26 INFO - Reading from file tmpfile_stdout 13:44:26 INFO - Reading from file tmpfile_stderr 13:44:26 INFO - Detecting whether we're running mozinstall >=1.0... 13:44:26 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 13:44:26 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 13:44:26 INFO - Reading from file tmpfile_stdout 13:44:26 INFO - Output received: 13:44:26 INFO - Usage: mozinstall [options] installer 13:44:26 INFO - Options: 13:44:26 INFO - -h, --help show this help message and exit 13:44:26 INFO - -d DEST, --destination=DEST 13:44:26 INFO - Directory to install application into. [default: 13:44:26 INFO - "/builds/slave/test"] 13:44:26 INFO - --app=APP Application being installed. [default: firefox] 13:44:26 INFO - mkdir: /builds/slave/test/build/application 13:44:26 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'] 13:44:26 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 13:44:44 INFO - Reading from file tmpfile_stdout 13:44:44 INFO - Output received: 13:44:44 INFO - /builds/slave/test/build/application/firefox/firefox 13:44:44 INFO - Running post-action listener: _resource_record_post_action 13:44:44 INFO - [mozharness: 2017-11-09 21:44:44.751565Z] Finished install step (success) 13:44:44 INFO - [mozharness: 2017-11-09 21:44:44.751812Z] Running setup-mitmproxy step. 13:44:44 INFO - Running pre-action listener: _resource_record_pre_action 13:44:44 INFO - Running main action method: setup_mitmproxy 13:44:44 INFO - Skipping: mitmproxy is not required 13:44:44 INFO - Running post-action listener: _resource_record_post_action 13:44:44 INFO - [mozharness: 2017-11-09 21:44:44.752907Z] Finished setup-mitmproxy step (success) 13:44:44 INFO - [mozharness: 2017-11-09 21:44:44.753123Z] Running run-tests step. 13:44:44 INFO - Running pre-action listener: _resource_record_pre_action 13:44:44 INFO - Running pre-action listener: _set_gcov_prefix 13:44:44 INFO - Running main action method: run_tests 13:44:44 WARNING - Try message not found. 13:44:44 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 13:44:44 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 13:44:44 INFO - Python 2.7.3 13:44:44 INFO - Return code: 0 13:44:44 INFO - grabbing minidump binary from tooltool 13:44:44 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 13:44:44 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 0x2c00070>, '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 0x2c01080>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2bfb2a0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 13:44:44 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 13:44:44 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 13:44:44 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 13:44:44 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 13:44:44 INFO - Return code: 0 13:44:44 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 13:44:44 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 13:44:44 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 13:44:44 INFO - ENV: RUST_BACKTRACE is now full 13:44:44 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 13:44:44 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 13:44:44 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-086', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] in /builds/slave/test/build 13:44:44 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite g4-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-086 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log 13:44:44 INFO - Using env: {'DISPLAY': ':0', 13:44:44 INFO - 'HOME': '/home/cltbld', 13:44:44 INFO - 'LANG': 'en_US.UTF-8', 13:44:44 INFO - 'LANGUAGE': 'en_US:en', 13:44:44 INFO - 'LOGNAME': 'cltbld', 13:44:44 INFO - 'MAIL': '/var/mail/cltbld', 13:44:44 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:44:44 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:44:44 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:44:44 INFO - 'MOZ_NO_REMOTE': '1', 13:44:44 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:44:44 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:44:44 INFO - 'NO_EM_RESTART': '1', 13:44:44 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:44:44 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:44:44 INFO - 'PWD': '/builds/slave/test', 13:44:44 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:44:44 INFO - 'RUST_BACKTRACE': 'full', 13:44:44 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:44:44 INFO - 'SHELL': '/bin/bash', 13:44:44 INFO - 'SHLVL': '1', 13:44:44 INFO - 'TERM': 'linux', 13:44:44 INFO - 'TMOUT': '86400', 13:44:44 INFO - 'USER': 'cltbld', 13:44:44 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:44:44 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:44:44 INFO - '_': '/tools/buildbot/bin/python'} 13:44:44 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-086', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] with output_timeout 3600 13:44:45 INFO - mozversion application_buildid: 20171109201218 13:44:45 INFO - mozversion application_changeset: 277e2ae05f747e257eaa73e36f1bc31b98a21af9 13:44:45 INFO - mozversion application_display_name: Nightly 13:44:45 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 13:44:45 INFO - mozversion application_name: Firefox 13:44:45 INFO - mozversion application_remotingname: firefox 13:44:45 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 13:44:45 INFO - mozversion application_vendor: Mozilla 13:44:45 INFO - mozversion application_version: 58.0a1 13:44:45 INFO - mozversion platform_buildid: 20171109201218 13:44:45 INFO - mozversion platform_changeset: 277e2ae05f747e257eaa73e36f1bc31b98a21af9 13:44:45 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 13:44:45 INFO - mozversion platform_version: 58.0a1 13:44:45 INFO - using testdate: 1510263885 13:44:45 INFO - actual date: 1510263885 13:44:45 INFO - starting webserver on 'localhost:52218' 13:44:45 INFO - SUITE-START | Running 3 tests 13:44:45 INFO - TEST-START | basic_compositor_video 13:44:45 INFO - Initialising browser for basic_compositor_video test... 13:44:45 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:52218/getInfo.html -profile /tmp/tmp2nUJI0/profile 13:44:45 INFO - TEST-INFO | started process 7571 (/builds/slave/test/build/application/firefox/firefox http://localhost:52218/getInfo.html) 13:44:50 INFO - TEST-INFO | 7571: exit 0 13:44:50 INFO - Browser initialized. 13:44:50 INFO - Running cycle 1/1 for basic_compositor_video test... 13:44:50 INFO - Using env: {'DISPLAY': ':0', 13:44:50 INFO - 'HOME': '/home/cltbld', 13:44:50 INFO - 'JSGC_DISABLE_POISONING': '1', 13:44:50 INFO - 'LANG': 'en_US.UTF-8', 13:44:50 INFO - 'LANGUAGE': 'en_US:en', 13:44:50 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:44:50 INFO - 'LOGNAME': 'cltbld', 13:44:50 INFO - 'MAIL': '/var/mail/cltbld', 13:44:50 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:44:50 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:44:50 INFO - 'MOZ_CRASHREPORTER': '1', 13:44:50 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:44:50 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:44:50 INFO - 'MOZ_NO_REMOTE': '1', 13:44:50 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:44:50 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:44:50 INFO - 'NO_EM_RESTART': '1', 13:44:50 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:44:50 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:44:50 INFO - 'PWD': '/builds/slave/test', 13:44:50 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:44:50 INFO - 'RUST_BACKTRACE': 'full', 13:44:50 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:44:50 INFO - 'SHELL': '/bin/bash', 13:44:50 INFO - 'SHLVL': '1', 13:44:50 INFO - 'TERM': 'linux', 13:44:50 INFO - 'TMOUT': '86400', 13:44:50 INFO - 'USER': 'cltbld', 13:44:50 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:44:50 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:44:50 INFO - '_': '/tools/buildbot/bin/python'} 13:44:50 INFO - TEST-INFO | started process 7850 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp2nUJI0/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 13:44:51 INFO - PID 7850 | 13:44:51 INFO - PID 7850 | (/builds/slave/test/build/application/firefox/firefox:7904): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:44:51 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6827481772293884 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.672704849498328 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7579906268306973 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7053708439897695 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9075195312500006 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9006335282651063 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.4810382830626456 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.391381355932205 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.5570462962962965 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.6350281690140775 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.067214765100667 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.152182741116748 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.111740740740734 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.81440540540541 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.147287449392701 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.630581395348832 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.72119140625 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.934453551912554 ms/frame 13:45:37 INFO - PID 7850 | 13:45:37 INFO - PID 7850 | Cycle 1(1): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:46:23 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.684957888826502 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6684361968306927 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7303719723183393 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.720120378331901 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.184811715481172 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.0487348178137665 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.5896889952153126 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5282275132275087 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.6622358490566045 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.60415966386555 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.204387755102042 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.104570707070698 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.949051094890528 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.41739583333333 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.504562500000004 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.196859756097538 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.323830188679226 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.81140540540541 ms/frame 13:46:23 INFO - PID 7850 | 13:46:23 INFO - PID 7850 | Cycle 1(2): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:47:09 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6821020179372197 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6682235195996662 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7620082207868466 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7271718480138174 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.028422818791945 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.066971544715448 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.6243840579710165 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5975269784172634 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.736443594646271 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.7146142857142905 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.13731418918919 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.474502617801052 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.156784386617112 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.527894736842082 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.398099173553705 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.840562130177517 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.154851301115237 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.816783783783801 ms/frame 13:47:09 INFO - PID 7850 | 13:47:09 INFO - PID 7850 | Cycle 1(3): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:47:56 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.694107848673066 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.670121035058431 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7355263157894738 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7124657534246581 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.055635135135136 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.7953700189753317 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.4692427745664745 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.401853741496594 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.609411214953271 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.4797808219178155 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.528947368421052 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.25661538461537 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.951678832116782 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.418932291666692 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.824145299145293 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.272546012269911 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.583359073359059 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.239887640449462 ms/frame 13:47:56 INFO - PID 7850 | 13:47:56 INFO - PID 7850 | Cycle 1(4): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:48:42 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6810168067226892 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.668177648040033 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.75459649122807 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7544605263157895 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 3.985444887118195 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.115442386831274 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.5469385342789588 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4608217993079577 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.672759924385632 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.604033613445386 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 9.772182410423445 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 9.857758620689655 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.991593406593399 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.641436170212787 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.661518987341767 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.274263803680991 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.540461538461555 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.052044198895018 ms/frame 13:48:42 INFO - PID 7850 | 13:48:42 INFO - PID 7850 | Cycle 1(5): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:49:28 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6792557358701734 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6683444537114265 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7701386430678467 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7274697754749566 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0879291553133505 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.1161316872428 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.4248573059360745 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.344690635451505 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.671909262759922 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.510688705234163 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.490524475524479 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.104722222222208 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.071439114391145 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.756747311827944 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.503312499999993 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.053192771084348 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.675933852140064 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.238174157303394 ms/frame 13:49:28 INFO - PID 7850 | 13:49:28 INFO - PID 7850 | Cycle 1(6): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:50:14 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.681956278026906 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6709690893901417 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7467840512223518 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.731580086580087 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.011510695187164 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.082867346938778 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.4326716247139597 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.345000000000002 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.608588785046731 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.571949860724229 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.871086956521745 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.472146596858622 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.115500000000004 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.697165775401045 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.714025423728792 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.195884146341463 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.496417624521081 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.98986263736263 ms/frame 13:50:14 INFO - PID 7850 | 13:50:14 INFO - PID 7850 | Cycle 1(7): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:51:00 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6893524774774775 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6675083333333331 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7495714285714288 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.740913838120104 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.049973009446695 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.065487804878048 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.6500729927007307 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5092105263157896 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.715152380952384 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.3624664879356585 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.490716783216786 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.052437185929655 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.11279629629629 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585449735449743 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.66185654008439 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.121757575757599 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.322415094339604 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.114583333333334 ms/frame 13:51:00 INFO - PID 7850 | 13:51:00 INFO - PID 7850 | Cycle 1(8): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:51:46 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6826247896803144 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6673458333333333 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7374406485234513 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.698136672325976 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.098825136612022 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.930992141453831 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.5983393285371674 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.534178445229684 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.66138679245283 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.683579545454543 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.601501766784446 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.363393782383412 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.991593406593399 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.531105263157913 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.712902542372893 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.126212121212104 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.454675572519085 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.240617977528059 ms/frame 13:51:46 INFO - PID 7850 | 13:51:46 INFO - PID 7850 | Cycle 1(9): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:52:33 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6799132138857782 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6699457429048417 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7414944863609985 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7301773356401384 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.1277579092159575 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9696626984126966 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.4528365937859604 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3783361486486525 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.714952380952378 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.450504087193468 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.171745762711854 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.417578125000015 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.158661710037189 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.528473684210507 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.662362869198295 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.696374269005858 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.28216165413534 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.050386740331506 ms/frame 13:52:33 INFO - PID 7850 | 13:52:33 INFO - PID 7850 | Cycle 1(10): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:53:19 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6801091825307952 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6689532944120098 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7271934369602764 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7012627551020403 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0665718157181585 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.00830661322645 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.5059228971962613 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4191965811965805 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.749281609195402 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.511170798898072 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 9.934850993377486 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 10.002150000000002 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.072435424354234 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.756424731182832 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.607352941176483 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.979670658682611 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.720800781250006 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.237443820224716 ms/frame 13:53:19 INFO - PID 7850 | 13:53:19 INFO - PID 7850 | Cycle 1(11): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:54:05 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6894313063063062 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6696076794657768 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7013123582766438 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7257679033649698 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_startup = 4.178447075208914 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.175553235908143 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_startup = 3.4332379862700244 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1_inclip = 3.396383701188451 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.567309833024116 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.4968543956043945 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_startup = 10.00375 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.480p.60fps.webm_scale_2_inclip = 9.953034825870635 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.282293233082708 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.698048128342265 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.5569037656904 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.905297619047598 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.541365384615375 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.173938547486046 ms/frame 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | Cycle 1(12): loaded http://localhost:52218/tests/video/video_playback.html (next: http://localhost:52218/tests/video/video_playback.html) 13:54:05 INFO - PID 7850 | __start_tp_report 13:54:05 INFO - PID 7850 | _x_x_mozilla_page_load 13:54:05 INFO - PID 7850 | _x_x_mozilla_page_load_details 13:54:05 INFO - PID 7850 | |i|pagename|runs| 13:54:05 INFO - PID 7850 | |0;240p.120fps.mp4_scale_1_startup;1.6827481772293884;1.684957888826502;1.6821020179372197;1.694107848673066;1.6810168067226892;1.6792557358701734;1.681956278026906;1.6893524774774775;1.6826247896803144;1.6799132138857782;1.6801091825307952;1.6894313063063062 13:54:05 INFO - PID 7850 | |1;240p.120fps.mp4_scale_1_inclip;1.672704849498328;1.6684361968306927;1.6682235195996662;1.670121035058431;1.668177648040033;1.6683444537114265;1.6709690893901417;1.6675083333333331;1.6673458333333333;1.6699457429048417;1.6689532944120098;1.6696076794657768 13:54:05 INFO - PID 7850 | |2;240p.120fps.mp4_scale_1.1_startup;1.7579906268306973;1.7303719723183393;1.7620082207868466;1.7355263157894738;1.75459649122807;1.7701386430678467;1.7467840512223518;1.7495714285714288;1.7374406485234513;1.7414944863609985;1.7271934369602764;1.7013123582766438 13:54:05 INFO - PID 7850 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7053708439897695;1.720120378331901;1.7271718480138174;1.7124657534246581;1.7544605263157895;1.7274697754749566;1.731580086580087;1.740913838120104;1.698136672325976;1.7301773356401384;1.7012627551020403;1.7257679033649698 13:54:05 INFO - PID 7850 | |4;240p.120fps.mp4_scale_2_startup;3.9075195312500006;4.184811715481172;4.028422818791945;4.055635135135136;3.985444887118195;4.0879291553133505;4.011510695187164;4.049973009446695;4.098825136612022;4.1277579092159575;4.0665718157181585;4.178447075208914 13:54:05 INFO - PID 7850 | |5;240p.120fps.mp4_scale_2_inclip;3.9006335282651063;4.0487348178137665;4.066971544715448;3.7953700189753317;4.115442386831274;4.1161316872428;4.082867346938778;4.065487804878048;3.930992141453831;3.9696626984126966;4.00830661322645;4.175553235908143 13:54:05 INFO - PID 7850 | |6;480p.60fps.webm_scale_1_startup;3.4810382830626456;3.5896889952153126;3.6243840579710165;3.4692427745664745;3.5469385342789588;3.4248573059360745;3.4326716247139597;3.6500729927007307;3.5983393285371674;3.4528365937859604;3.5059228971962613;3.4332379862700244 13:54:05 INFO - PID 7850 | |7;480p.60fps.webm_scale_1_inclip;3.391381355932205;3.5282275132275087;3.5975269784172634;3.401853741496594;3.4608217993079577;3.344690635451505;3.345000000000002;3.5092105263157896;3.534178445229684;3.3783361486486525;3.4191965811965805;3.396383701188451 13:54:05 INFO - PID 7850 | |8;480p.60fps.webm_scale_1.1_startup;5.5570462962962965;5.6622358490566045;5.736443594646271;5.609411214953271;5.672759924385632;5.671909262759922;5.608588785046731;5.715152380952384;5.66138679245283;5.714952380952378;5.749281609195402;5.567309833024116 13:54:05 INFO - PID 7850 | |9;480p.60fps.webm_scale_1.1_inclip;5.6350281690140775;5.60415966386555;5.7146142857142905;5.4797808219178155;5.604033613445386;5.510688705234163;5.571949860724229;5.3624664879356585;5.683579545454543;5.450504087193468;5.511170798898072;5.4968543956043945 13:54:05 INFO - PID 7850 | |10;480p.60fps.webm_scale_2_startup;10.067214765100667;10.204387755102042;10.13731418918919;10.528947368421052;9.772182410423445;10.490524475524479;10.871086956521745;10.490716783216786;10.601501766784446;10.171745762711854;9.934850993377486;10.00375 13:54:05 INFO - PID 7850 | |11;480p.60fps.webm_scale_2_inclip;10.152182741116748;10.104570707070698;10.474502617801052;10.25661538461537;9.857758620689655;10.104722222222208;10.472146596858622;10.052437185929655;10.363393782383412;10.417578125000015;10.002150000000002;9.953034825870635 13:54:05 INFO - PID 7850 | |12;1080p.60fps.mp4_scale_1_startup;11.111740740740734;10.949051094890528;11.156784386617112;10.951678832116782;10.991593406593399;11.071439114391145;11.115500000000004;11.11279629629629;10.991593406593399;11.158661710037189;11.072435424354234;11.282293233082708 13:54:05 INFO - PID 7850 | |13;1080p.60fps.mp4_scale_1_inclip;10.81440540540541;10.41739583333333;10.527894736842082;10.418932291666692;10.641436170212787;10.756747311827944;10.697165775401045;10.585449735449743;10.531105263157913;10.528473684210507;10.756424731182832;10.698048128342265 13:54:05 INFO - PID 7850 | |14;1080p.60fps.mp4_scale_1.1_startup;12.147287449392701;12.504562500000004;12.398099173553705;12.824145299145293;12.661518987341767;12.503312499999993;12.714025423728792;12.66185654008439;12.712902542372893;12.662362869198295;12.607352941176483;12.5569037656904 13:54:05 INFO - PID 7850 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.630581395348832;12.196859756097538;11.840562130177517;12.272546012269911;12.274263803680991;12.053192771084348;12.195884146341463;12.121757575757599;12.126212121212104;11.696374269005858;11.979670658682611;11.905297619047598 13:54:05 INFO - PID 7850 | |16;1080p.60fps.mp4_scale_2_startup;11.72119140625;11.323830188679226;11.154851301115237;11.583359073359059;11.540461538461555;11.675933852140064;11.496417624521081;11.322415094339604;11.454675572519085;11.28216165413534;11.720800781250006;11.541365384615375 13:54:05 INFO - PID 7850 | |17;1080p.60fps.mp4_scale_2_inclip;10.934453551912554;10.81140540540541;10.816783783783801;11.239887640449462;11.052044198895018;11.238174157303394;10.98986263736263;11.114583333333334;11.240617977528059;11.050386740331506;11.237443820224716;11.173938547486046 13:54:05 INFO - PID 7850 | __end_tp_report 13:54:05 INFO - PID 7850 | __start_cc_report 13:54:05 INFO - PID 7850 | _x_x_mozilla_cycle_collect,586 13:54:05 INFO - PID 7850 | __end_cc_report 13:54:05 INFO - PID 7850 | __startTimestamp1510264445626__endTimestamp 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | ------- Summary: start ------- 13:54:05 INFO - PID 7850 | Number of tests: 18 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.00 (0.3%) stddev-sans-first:0.00 13:54:05 INFO - PID 7850 | 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 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:1.67 Median:1.67 stddev:0.00 (0.1%) stddev-sans-first:0.00 13:54:05 INFO - PID 7850 | 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 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.74 Median:1.75 stddev:0.02 (1.1%) stddev-sans-first:0.02 13:54:05 INFO - PID 7850 | Values: 1.8 1.7 1.8 1.7 1.8 1.8 1.7 1.7 1.7 1.7 1.7 1.7 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.72 Median:1.73 stddev:0.02 (1.0%) stddev-sans-first:0.02 13:54:05 INFO - PID 7850 | Values: 1.7 1.7 1.7 1.7 1.8 1.7 1.7 1.7 1.7 1.7 1.7 1.7 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.07 Median:4.08 stddev:0.08 (1.9%) stddev-sans-first:0.06 13:54:05 INFO - PID 7850 | Values: 3.9 4.2 4.0 4.1 4.0 4.1 4.0 4.0 4.1 4.1 4.1 4.2 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.02 Median:4.07 stddev:0.11 (2.6%) stddev-sans-first:0.11 13:54:05 INFO - PID 7850 | Values: 3.9 4.0 4.1 3.8 4.1 4.1 4.1 4.1 3.9 4.0 4.0 4.2 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.52 Median:3.53 stddev:0.08 (2.3%) stddev-sans-first:0.08 13:54:05 INFO - PID 7850 | Values: 3.5 3.6 3.6 3.5 3.5 3.4 3.4 3.7 3.6 3.5 3.5 3.4 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.44 Median:3.44 stddev:0.08 (2.4%) stddev-sans-first:0.08 13:54:05 INFO - PID 7850 | Values: 3.4 3.5 3.6 3.4 3.5 3.3 3.3 3.5 3.5 3.4 3.4 3.4 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.66 Median:5.67 stddev:0.06 (1.1%) stddev-sans-first:0.06 13:54:05 INFO - PID 7850 | Values: 5.6 5.7 5.7 5.6 5.7 5.7 5.6 5.7 5.7 5.7 5.7 5.6 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.55 Median:5.59 stddev:0.10 (1.8%) stddev-sans-first:0.10 13:54:05 INFO - PID 7850 | Values: 5.6 5.6 5.7 5.5 5.6 5.5 5.6 5.4 5.7 5.5 5.5 5.5 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.27 Median:10.51 stddev:0.32 (3.1%) stddev-sans-first:0.33 13:54:05 INFO - PID 7850 | Values: 10.1 10.2 10.1 10.5 9.8 10.5 10.9 10.5 10.6 10.2 9.9 10.0 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:10.18 Median:10.39 stddev:0.21 (2.0%) stddev-sans-first:0.22 13:54:05 INFO - PID 7850 | Values: 10.2 10.1 10.5 10.3 9.9 10.1 10.5 10.1 10.4 10.4 10.0 10.0 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.08 Median:11.11 stddev:0.10 (0.9%) stddev-sans-first:0.10 13:54:05 INFO - PID 7850 | Values: 11.1 10.9 11.2 11.0 11.0 11.1 11.1 11.1 11.0 11.2 11.1 11.3 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.61 Median:10.67 stddev:0.13 (1.2%) stddev-sans-first:0.12 13:54:05 INFO - PID 7850 | Values: 10.8 10.4 10.5 10.4 10.6 10.8 10.7 10.6 10.5 10.5 10.8 10.7 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.58 Median:12.66 stddev:0.18 (1.4%) stddev-sans-first:0.12 13:54:05 INFO - PID 7850 | Values: 12.1 12.5 12.4 12.8 12.7 12.5 12.7 12.7 12.7 12.7 12.6 12.6 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:12.02 Median:12.12 stddev:0.22 (1.8%) stddev-sans-first:0.19 13:54:05 INFO - PID 7850 | Values: 11.6 12.2 11.8 12.3 12.3 12.1 12.2 12.1 12.1 11.7 12.0 11.9 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.48 Median:11.54 stddev:0.18 (1.6%) stddev-sans-first:0.18 13:54:05 INFO - PID 7850 | Values: 11.7 11.3 11.2 11.6 11.5 11.7 11.5 11.3 11.5 11.3 11.7 11.5 13:54:05 INFO - PID 7850 | 13:54:05 INFO - PID 7850 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:11.07 Median:11.14 stddev:0.16 (1.4%) stddev-sans-first:0.16 13:54:05 INFO - PID 7850 | Values: 10.9 10.8 10.8 11.2 11.1 11.2 11.0 11.1 11.2 11.1 11.2 11.2 13:54:05 INFO - PID 7850 | -------- Summary: end -------- 13:54:05 INFO - PID 7850 | 13:54:06 INFO - TEST-INFO | 7850: exit 0 13:54:06 INFO - TEST-OK | basic_compositor_video | took 560922ms 13:54:06 INFO - TEST-START | glvideo 13:54:06 INFO - Initialising browser for glvideo test... 13:54:06 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:52218/getInfo.html -profile /tmp/tmpkWjdr3/profile 13:54:06 INFO - TEST-INFO | started process 9096 (/builds/slave/test/build/application/firefox/firefox http://localhost:52218/getInfo.html) 13:54:11 INFO - TEST-INFO | 9096: exit 0 13:54:11 INFO - Browser initialized. 13:54:11 INFO - Running cycle 1/1 for glvideo test... 13:54:11 INFO - Using env: {'DISPLAY': ':0', 13:54:11 INFO - 'HOME': '/home/cltbld', 13:54:11 INFO - 'JSGC_DISABLE_POISONING': '1', 13:54:11 INFO - 'LANG': 'en_US.UTF-8', 13:54:11 INFO - 'LANGUAGE': 'en_US:en', 13:54:11 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:54:11 INFO - 'LOGNAME': 'cltbld', 13:54:11 INFO - 'MAIL': '/var/mail/cltbld', 13:54:11 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:54:11 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:54:11 INFO - 'MOZ_CRASHREPORTER': '1', 13:54:11 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:54:11 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:54:11 INFO - 'MOZ_NO_REMOTE': '1', 13:54:11 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:54:11 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:54:11 INFO - 'NO_EM_RESTART': '1', 13:54:11 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:54:11 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:54:11 INFO - 'PWD': '/builds/slave/test', 13:54:11 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:54:11 INFO - 'RUST_BACKTRACE': 'full', 13:54:11 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:54:11 INFO - 'SHELL': '/bin/bash', 13:54:11 INFO - 'SHLVL': '1', 13:54:11 INFO - 'TERM': 'linux', 13:54:11 INFO - 'TMOUT': '86400', 13:54:11 INFO - 'USER': 'cltbld', 13:54:11 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:54:11 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:54:11 INFO - '_': '/tools/buildbot/bin/python'} 13:54:11 INFO - TEST-INFO | started process 9380 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpkWjdr3/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 13:54:12 INFO - PID 9380 | 13:54:12 INFO - PID 9380 | (/builds/slave/test/build/application/firefox/firefox:9432): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:54:12 INFO - PID 9380 | 13:54:13 INFO - PID 9380 | [talos glvideo result] Mean tick time across 100 ticks: 6.9055 ms 13:54:13 INFO - PID 9380 | Cycle 1(1): loaded http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html) 13:54:14 INFO - PID 9380 | [talos glvideo result] Mean tick time across 100 ticks: 6.47375 ms 13:54:14 INFO - PID 9380 | Cycle 1(2): loaded http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html) 13:54:16 INFO - PID 9380 | [talos glvideo result] Mean tick time across 100 ticks: 6.499750000000001 ms 13:54:16 INFO - PID 9380 | Cycle 1(3): loaded http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html) 13:54:17 INFO - PID 9380 | [talos glvideo result] Mean tick time across 100 ticks: 6.7315000000000005 ms 13:54:17 INFO - PID 9380 | Cycle 1(4): loaded http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html) 13:54:18 INFO - PID 9380 | [talos glvideo result] Mean tick time across 100 ticks: 6.67145 ms 13:54:18 INFO - PID 9380 | Cycle 1(5): loaded http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52218/tests/webgl/benchmarks/video/video_upload.html) 13:54:19 INFO - PID 9380 | __start_tp_report 13:54:19 INFO - PID 9380 | _x_x_mozilla_page_load 13:54:19 INFO - PID 9380 | _x_x_mozilla_page_load_details 13:54:19 INFO - PID 9380 | |i|pagename|runs| 13:54:19 INFO - PID 9380 | |0;Mean tick time across 100 ticks: ;6.9055;6.47375;6.499750000000001;6.7315000000000005;6.67145 13:54:19 INFO - PID 9380 | __end_tp_report 13:54:19 INFO - PID 9380 | __start_cc_report 13:54:19 INFO - PID 9380 | _x_x_mozilla_cycle_collect,275 13:54:19 INFO - PID 9380 | __end_cc_report 13:54:19 INFO - PID 9380 | __startTimestamp1510264459207__endTimestamp 13:54:19 INFO - PID 9380 | 13:54:19 INFO - PID 9380 | ------- Summary: start ------- 13:54:19 INFO - PID 9380 | Number of tests: 1 13:54:19 INFO - PID 9380 | 13:54:19 INFO - PID 9380 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.66 Median:6.67 stddev:0.18 (2.7%) stddev-sans-first:0.13 13:54:19 INFO - PID 9380 | Values: 6.9 6.5 6.5 6.7 6.7 13:54:19 INFO - PID 9380 | -------- Summary: end -------- 13:54:19 INFO - PID 9380 | 13:54:19 INFO - PID 9380 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 13:54:19 INFO - TEST-INFO | 9380: exit 0 13:54:19 INFO - TEST-OK | glvideo | took 13654ms 13:54:19 INFO - TEST-START | displaylist_mutate 13:54:19 INFO - Initialising browser for displaylist_mutate test... 13:54:19 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:52218/getInfo.html -profile /tmp/tmp46C3J0/profile 13:54:19 INFO - TEST-INFO | started process 9604 (/builds/slave/test/build/application/firefox/firefox http://localhost:52218/getInfo.html) 13:54:24 INFO - TEST-INFO | 9604: exit 0 13:54:24 INFO - Browser initialized. 13:54:24 INFO - Running cycle 1/1 for displaylist_mutate test... 13:54:24 INFO - Using env: {'DISPLAY': ':0', 13:54:24 INFO - 'HOME': '/home/cltbld', 13:54:24 INFO - 'JSGC_DISABLE_POISONING': '1', 13:54:24 INFO - 'LANG': 'en_US.UTF-8', 13:54:24 INFO - 'LANGUAGE': 'en_US:en', 13:54:24 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 13:54:24 INFO - 'LOGNAME': 'cltbld', 13:54:24 INFO - 'MAIL': '/var/mail/cltbld', 13:54:24 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 13:54:24 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 13:54:24 INFO - 'MOZ_CRASHREPORTER': '1', 13:54:24 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 13:54:24 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 13:54:24 INFO - 'MOZ_NO_REMOTE': '1', 13:54:24 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 13:54:24 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 13:54:24 INFO - 'NO_EM_RESTART': '1', 13:54:24 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 13:54:24 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 13:54:24 INFO - 'PWD': '/builds/slave/test', 13:54:24 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 13:54:24 INFO - 'RUST_BACKTRACE': 'full', 13:54:24 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 13:54:24 INFO - 'SHELL': '/bin/bash', 13:54:24 INFO - 'SHLVL': '1', 13:54:24 INFO - 'TERM': 'linux', 13:54:24 INFO - 'TMOUT': '86400', 13:54:24 INFO - 'USER': 'cltbld', 13:54:24 INFO - 'XDG_SESSION_COOKIE': '438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505', 13:54:24 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 13:54:24 INFO - '_': '/tools/buildbot/bin/python'} 13:54:24 INFO - TEST-INFO | started process 9878 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp46C3J0/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/layout/displaylist_mutate.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 13:54:25 INFO - PID 9878 | 13:54:25 INFO - PID 9878 | (/builds/slave/test/build/application/firefox/firefox:9930): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 13:54:25 INFO - PID 9878 | 13:54:44 INFO - PID 9878 | Cycle 1(1): loaded http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html) 13:54:44 INFO - PID 9878 | Waiting for idle-callback 13:55:04 INFO - PID 9878 | Cycle 1(2): loaded http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html) 13:55:25 INFO - PID 9878 | Cycle 1(3): loaded http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html) 13:55:45 INFO - PID 9878 | Cycle 1(4): loaded http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html) 13:56:05 INFO - PID 9878 | Cycle 1(5): loaded http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html (next: http://localhost:52218/tests/layout/benchmarks/displaylist_mutate.html) 13:56:05 INFO - PID 9878 | __start_tp_report 13:56:05 INFO - PID 9878 | _x_x_mozilla_page_load 13:56:05 INFO - PID 9878 | _x_x_mozilla_page_load_details 13:56:05 INFO - PID 9878 | |i|pagename|runs| 13:56:05 INFO - PID 9878 | |0;/displaylist_mutate.html;18928.645;19312.41;19506.995;19289.789999999997;19256.595 13:56:05 INFO - PID 9878 | __end_tp_report 13:56:05 INFO - PID 9878 | __start_cc_report 13:56:05 INFO - PID 9878 | _x_x_mozilla_cycle_collect,213 13:56:05 INFO - PID 9878 | __end_cc_report 13:56:05 INFO - PID 9878 | __startTimestamp1510264565471__endTimestamp 13:56:05 INFO - PID 9878 | 13:56:05 INFO - PID 9878 | ------- Summary: start ------- 13:56:05 INFO - PID 9878 | Number of tests: 1 13:56:05 INFO - PID 9878 | 13:56:05 INFO - PID 9878 | [#0] /displaylist_mutate.html Cycles:5 Average:19258.89 Median:19289.79 stddev:208.83 (1.1%) stddev-sans-first:112.72 13:56:05 INFO - PID 9878 | Values: 18928.6 19312.4 19507.0 19289.8 19256.6 13:56:05 INFO - PID 9878 | -------- Summary: end -------- 13:56:05 INFO - PID 9878 | 13:56:06 INFO - TEST-INFO | 9878: exit 0 13:56:06 INFO - TEST-OK | displaylist_mutate | took 106249ms 13:56:06 INFO - SUITE-END | took 680s 13:56:06 INFO - Completed test suite (00:11:21) 13:56:06 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.5976377539271285, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6827481772293884, 1.684957888826502, 1.6821020179372197, 1.694107848673066, 1.6810168067226892, 1.6792557358701734, 1.681956278026906, 1.6893524774774775, 1.6826247896803144, 1.6799132138857782, 1.6801091825307952, 1.6894313063063062], "value": 1.6821020179372197, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.672704849498328, 1.6684361968306927, 1.6682235195996662, 1.670121035058431, 1.668177648040033, 1.6683444537114265, 1.6709690893901417, 1.6675083333333331, 1.6673458333333333, 1.6699457429048417, 1.6689532944120098, 1.6696076794657768], "value": 1.6684361968306927, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7579906268306973, 1.7303719723183393, 1.7620082207868466, 1.7355263157894738, 1.75459649122807, 1.7701386430678467, 1.7467840512223518, 1.7495714285714288, 1.7374406485234513, 1.7414944863609985, 1.7271934369602764, 1.7013123582766438], "value": 1.7414944863609985, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7053708439897695, 1.720120378331901, 1.7271718480138174, 1.7124657534246581, 1.7544605263157895, 1.7274697754749566, 1.731580086580087, 1.740913838120104, 1.698136672325976, 1.7301773356401384, 1.7012627551020403, 1.7257679033649698], "value": 1.7271718480138174, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.9075195312500006, 4.184811715481172, 4.028422818791945, 4.055635135135136, 3.985444887118195, 4.0879291553133505, 4.011510695187164, 4.049973009446695, 4.098825136612022, 4.1277579092159575, 4.0665718157181585, 4.178447075208914], "value": 4.0665718157181585, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.9006335282651063, 4.0487348178137665, 4.066971544715448, 3.7953700189753317, 4.115442386831274, 4.1161316872428, 4.082867346938778, 4.065487804878048, 3.930992141453831, 3.9696626984126966, 4.00830661322645, 4.175553235908143], "value": 4.065487804878048, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.4810382830626456, 3.5896889952153126, 3.6243840579710165, 3.4692427745664745, 3.5469385342789588, 3.4248573059360745, 3.4326716247139597, 3.6500729927007307, 3.5983393285371674, 3.4528365937859604, 3.5059228971962613, 3.4332379862700244], "value": 3.5059228971962613, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.391381355932205, 3.5282275132275087, 3.5975269784172634, 3.401853741496594, 3.4608217993079577, 3.344690635451505, 3.345000000000002, 3.5092105263157896, 3.534178445229684, 3.3783361486486525, 3.4191965811965805, 3.396383701188451], "value": 3.4191965811965805, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.5570462962962965, 5.6622358490566045, 5.736443594646271, 5.609411214953271, 5.672759924385632, 5.671909262759922, 5.608588785046731, 5.715152380952384, 5.66138679245283, 5.714952380952378, 5.749281609195402, 5.567309833024116], "value": 5.671909262759922, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.6350281690140775, 5.60415966386555, 5.7146142857142905, 5.4797808219178155, 5.604033613445386, 5.510688705234163, 5.571949860724229, 5.3624664879356585, 5.683579545454543, 5.450504087193468, 5.511170798898072, 5.4968543956043945], "value": 5.511170798898072, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.067214765100667, 10.204387755102042, 10.13731418918919, 10.528947368421052, 9.772182410423445, 10.490524475524479, 10.871086956521745, 10.490716783216786, 10.601501766784446, 10.171745762711854, 9.934850993377486, 10.00375], "value": 10.204387755102042, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.152182741116748, 10.104570707070698, 10.474502617801052, 10.25661538461537, 9.857758620689655, 10.104722222222208, 10.472146596858622, 10.052437185929655, 10.363393782383412, 10.417578125000015, 10.002150000000002, 9.953034825870635], "value": 10.104722222222208, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.111740740740734, 10.949051094890528, 11.156784386617112, 10.951678832116782, 10.991593406593399, 11.071439114391145, 11.115500000000004, 11.11279629629629, 10.991593406593399, 11.158661710037189, 11.072435424354234, 11.282293233082708], "value": 11.072435424354234, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.81440540540541, 10.41739583333333, 10.527894736842082, 10.418932291666692, 10.641436170212787, 10.756747311827944, 10.697165775401045, 10.585449735449743, 10.531105263157913, 10.528473684210507, 10.756424731182832, 10.698048128342265], "value": 10.585449735449743, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.147287449392701, 12.504562500000004, 12.398099173553705, 12.824145299145293, 12.661518987341767, 12.503312499999993, 12.714025423728792, 12.66185654008439, 12.712902542372893, 12.662362869198295, 12.607352941176483, 12.5569037656904], "value": 12.661518987341767, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.630581395348832, 12.196859756097538, 11.840562130177517, 12.272546012269911, 12.274263803680991, 12.053192771084348, 12.195884146341463, 12.121757575757599, 12.126212121212104, 11.696374269005858, 11.979670658682611, 11.905297619047598], "value": 12.121757575757599, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.72119140625, 11.323830188679226, 11.154851301115237, 11.583359073359059, 11.540461538461555, 11.675933852140064, 11.496417624521081, 11.322415094339604, 11.454675572519085, 11.28216165413534, 11.720800781250006, 11.541365384615375], "value": 11.496417624521081, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.934453551912554, 10.81140540540541, 10.816783783783801, 11.239887640449462, 11.052044198895018, 11.238174157303394, 10.98986263736263, 11.114583333333334, 11.240617977528059, 11.050386740331506, 11.237443820224716, 11.173938547486046], "value": 11.114583333333334, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.9055, 6.47375, 6.499750000000001, 6.7315000000000005, 6.67145], "value": 6.5856, "unit": "ms"}], "extraOptions": ["e10s"], "name": "glvideo", "alertThreshold": 2.0}, {"lowerIsBetter": true, "subtests": [{"name": "", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [18928.645, 19312.41, 19506.995, 19289.789999999997, 19256.595], "value": 19301.1, "unit": "ms"}], "extraOptions": ["e10s"], "name": "displaylist_mutate", "alertThreshold": 2.0}]} 13:56:06 INFO - Return code: 0 13:56:06 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 13:56:06 INFO - # TBPL SUCCESS # 13:56:06 INFO - Running post-action listener: _package_coverage_data 13:56:06 INFO - Running post-action listener: _resource_record_post_action 13:56:06 INFO - [mozharness: 2017-11-09 21:56:06.450159Z] Finished run-tests step (success) 13:56:06 INFO - Running post-run listener: _resource_record_post_run 13:56:06 INFO - Total resource usage - Wall time: 700s; CPU: 35.0%; Read bytes: 0; Write bytes: 344526848; Read time: 0; Write time: 170336 13:56:06 INFO - TinderboxPrint: CPU usage
35.0% 13:56:06 INFO - TinderboxPrint: I/O read bytes / time
0 / 0 13:56:06 INFO - TinderboxPrint: I/O write bytes / time
344,526,848 / 170,336 13:56:06 INFO - TinderboxPrint: CPU idle
3,580.2 (65.1%) 13:56:06 INFO - TinderboxPrint: CPU system
317.6 (5.8%) 13:56:06 INFO - TinderboxPrint: CPU user
1,587.4 (28.9%) 13:56:06 INFO - TinderboxPrint: Swap in / out
0 / 0 13:56:06 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 7127040; Read time: 0; Write time: 5156 13:56:06 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 13:56:06 INFO - run-tests - Wall time: 682s; CPU: 36.0%; Read bytes: 0; Write bytes: 337399808; Read time: 0; Write time: 165180 13:56:06 INFO - Running post-run listener: _upload_blobber_files 13:56:06 INFO - Blob upload gear active. 13:56:06 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 13:56:06 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 13:56:06 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'] 13:56:06 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 13:56:07 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 13:56:07 INFO - SNIMissingWarning 13:56:07 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 13:56:07 INFO - InsecurePlatformWarning 13:56:07 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.) 13:56:07 INFO - SubjectAltNameWarning 13:56:07 INFO - (blobuploader) - INFO - Open directory for files ... 13:56:07 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 13:56:07 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:56:07 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:56:07 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 13:56:07 INFO - InsecurePlatformWarning 13:56:07 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.) 13:56:07 INFO - SubjectAltNameWarning 13:56:10 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 13:56:10 INFO - InsecurePlatformWarning 13:56:10 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 13:56:10 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:56:10 INFO - (blobuploader) - INFO - Done attempting. 13:56:10 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 13:56:10 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:56:10 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:56:10 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 13:56:10 INFO - InsecurePlatformWarning 13:56:11 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.) 13:56:11 INFO - SubjectAltNameWarning 13:56:11 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 13:56:11 INFO - InsecurePlatformWarning 13:56:11 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 13:56:11 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:56:11 INFO - (blobuploader) - INFO - Done attempting. 13:56:11 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 13:56:11 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:56:11 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:56:11 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 13:56:11 INFO - InsecurePlatformWarning 13:56:11 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.) 13:56:11 INFO - SubjectAltNameWarning 13:56:12 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 13:56:12 INFO - InsecurePlatformWarning 13:56:12 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 13:56:12 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:56:12 INFO - (blobuploader) - INFO - Done attempting. 13:56:12 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 13:56:12 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 13:56:12 INFO - (blobuploader) - INFO - Uploading, attempt #1. 13:56:12 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 13:56:12 INFO - InsecurePlatformWarning 13:56:12 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.) 13:56:12 INFO - SubjectAltNameWarning 13:56:13 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 13:56:13 INFO - InsecurePlatformWarning 13:56:13 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 13:56:13 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 13:56:13 INFO - (blobuploader) - INFO - Done attempting. 13:56:13 INFO - (blobuploader) - INFO - Iteration through files over. 13:56:13 INFO - Return code: 0 13:56:13 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 13:56:13 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 13:56:13 INFO - Setting buildbot property blobber_files to {"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2534de66499bf590c4b40484f167c39ec08f22ffe2a59c492adcba0a73b89100893c8e77d09cc0b8e3653c1e3e2ae6c96c9e2c582bfc4370b9a0df990ecfaf5e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d7a5509825e89c2516a97a80218134731093d4a6f8171cbc7edbaec47c00da18fc1ba35c07f25f15050b4bf3fcb4b3044250f7c265011429a969ba96314a24ae", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7eecd66d244245f6240e58b220665a67f8f7d548d8fd1a11d0b37c7938dcf4d4c7ee68cdc94b4909b7401afd09445c5eed50666a706abb2af50cbd47c6072547", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a5d1dcce26010232eab727250d8964eed5479aa0f18a4619597d5ab206d38fbca0dce3e8a126f9f3beba5543c62df0939e9cad2ac71c484e1d2a4b4a97c4c8b8"} 13:56:13 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 13:56:13 INFO - Writing to file /builds/slave/test/properties/blobber_files 13:56:13 INFO - Contents: 13:56:13 INFO - blobber_files:{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2534de66499bf590c4b40484f167c39ec08f22ffe2a59c492adcba0a73b89100893c8e77d09cc0b8e3653c1e3e2ae6c96c9e2c582bfc4370b9a0df990ecfaf5e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d7a5509825e89c2516a97a80218134731093d4a6f8171cbc7edbaec47c00da18fc1ba35c07f25f15050b4bf3fcb4b3044250f7c265011429a969ba96314a24ae", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7eecd66d244245f6240e58b220665a67f8f7d548d8fd1a11d0b37c7938dcf4d4c7ee68cdc94b4909b7401afd09445c5eed50666a706abb2af50cbd47c6072547", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a5d1dcce26010232eab727250d8964eed5479aa0f18a4619597d5ab206d38fbca0dce3e8a126f9f3beba5543c62df0939e9cad2ac71c484e1d2a4b4a97c4c8b8"} 13:56:13 INFO - Running post-run listener: copy_logs_to_upload_dir 13:56:13 INFO - Copying logs to upload dir... 13:56:13 INFO - mkdir: /builds/slave/test/build/upload/logs 13:56:13 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=762.375704 ========= master_lag: 0.00 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 12 mins, 42 secs) (at 2017-11-09 13:56:13.645480) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-09 13:56:13.648689) ========= 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=438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2534de66499bf590c4b40484f167c39ec08f22ffe2a59c492adcba0a73b89100893c8e77d09cc0b8e3653c1e3e2ae6c96c9e2c582bfc4370b9a0df990ecfaf5e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d7a5509825e89c2516a97a80218134731093d4a6f8171cbc7edbaec47c00da18fc1ba35c07f25f15050b4bf3fcb4b3044250f7c265011429a969ba96314a24ae", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7eecd66d244245f6240e58b220665a67f8f7d548d8fd1a11d0b37c7938dcf4d4c7ee68cdc94b4909b7401afd09445c5eed50666a706abb2af50cbd47c6072547", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a5d1dcce26010232eab727250d8964eed5479aa0f18a4619597d5ab206d38fbca0dce3e8a126f9f3beba5543c62df0939e9cad2ac71c484e1d2a4b4a97c4c8b8"} build_url:https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011402 build_url: 'https://queue.taskcluster.net/v1/task/OOKTvOD1R1qhr3I1YZEfpA/artifacts/public/build/target.tar.bz2' blobber_files: '{"g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/2534de66499bf590c4b40484f167c39ec08f22ffe2a59c492adcba0a73b89100893c8e77d09cc0b8e3653c1e3e2ae6c96c9e2c582bfc4370b9a0df990ecfaf5e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d7a5509825e89c2516a97a80218134731093d4a6f8171cbc7edbaec47c00da18fc1ba35c07f25f15050b4bf3fcb4b3044250f7c265011429a969ba96314a24ae", "perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/7eecd66d244245f6240e58b220665a67f8f7d548d8fd1a11d0b37c7938dcf4d4c7ee68cdc94b4909b7401afd09445c5eed50666a706abb2af50cbd47c6072547", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a5d1dcce26010232eab727250d8964eed5479aa0f18a4619597d5ab206d38fbca0dce3e8a126f9f3beba5543c62df0939e9cad2ac71c484e1d2a4b4a97c4c8b8"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-09 13:56:13.681620) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:56:13.682129) ========= 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=438111f3d31ce799eff2119d000001bc-1510263808.292264-496030505 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004507 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-09 13:56:13.767273) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-09 13:56:13.767992) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-09 13:56:13.768732) ========= ========= Total master_lag: 0.17 =========