builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s-pgo slave: talos-linux64-ix-046 starttime: 1510143317.45 results: success (0) revision: f63559d7e6a570e4e73ba367964099394248e18d ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.448147) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.448566) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.448834) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.611249) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.611496) ========= 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=652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-11-08 04:15:17-- 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% 45.8M=0s 2017-11-08 04:15:17 (45.8 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.107269 ========= master_lag: 0.06 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.777195) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.780511) ========= 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=652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.015268 ========= master_lag: 0.06 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:17.851409) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-11-08 04:15:17.851697) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev f63559d7e6a570e4e73ba367964099394248e18d --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 f63559d7e6a570e4e73ba367964099394248e18d --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=652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-11-08 04:15:17,911 truncating revision to first 12 chars 2017-11-08 04:15:17,911 Setting DEBUG logging. 2017-11-08 04:15:17,911 attempt 1/10 2017-11-08 04:15:17,911 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/f63559d7e6a5?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-11-08 04:15:18,320 unpacking tar archive at: mozilla-central-f63559d7e6a5/testing/mozharness/ program finished with exit code 0 elapsedTime=1.010355 ========= master_lag: 0.03 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 1 secs) (at 2017-11-08 04:15:18.888144) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:18.888455) ========= script_repo_revision: f63559d7e6a570e4e73ba367964099394248e18d ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:18.888813) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:18.889121) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-08 04:15:18.903951) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 59 secs) (at 2017-11-08 04:15:18.904250) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-stylo-disabled-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 04:15:19 INFO - MultiFileLogger online at 20171108 04:15:19 in /builds/slave/test 04:15:19 INFO - Run as scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 04:15:19 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 04:15:19 INFO - {'append_to_log': False, 04:15:19 INFO - 'base_work_dir': '/builds/slave/test', 04:15:19 INFO - 'blob_upload_branch': 'Firefox', 04:15:19 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 04:15:19 INFO - 'branch': 'Firefox', 04:15:19 INFO - 'buildbot_json_path': 'buildprops.json', 04:15:19 INFO - 'code_coverage': False, 04:15:19 INFO - 'config_files': ('talos/linux_config.py',), 04:15:19 INFO - 'default_actions': ('clobber', 04:15:19 INFO - 'read-buildbot-config', 04:15:19 INFO - 'download-and-extract', 04:15:19 INFO - 'populate-webroot', 04:15:19 INFO - 'create-virtualenv', 04:15:19 INFO - 'install', 04:15:19 INFO - 'setup-mitmproxy', 04:15:19 INFO - 'run-tests'), 04:15:19 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 04:15:19 INFO - 'disable_ccov_upload': False, 04:15:19 INFO - 'disable_stylo': False, 04:15:19 INFO - 'download_minidump_stackwalk': True, 04:15:19 INFO - 'download_symbols': 'ondemand', 04:15:19 INFO - 'e10s': False, 04:15:19 INFO - 'enable_stylo': False, 04:15:19 INFO - 'enable_webrender': False, 04:15:19 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 04:15:19 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 04:15:19 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 04:15:19 INFO - 'gecko_profile': False, 04:15:19 INFO - 'gecko_profile_interval': 0, 04:15:19 INFO - 'installer_path': 'installer.exe', 04:15:19 INFO - 'jsd_code_coverage': False, 04:15:19 INFO - 'log_level': 'info', 04:15:19 INFO - 'log_name': 'talos', 04:15:19 INFO - 'log_to_console': True, 04:15:19 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 04:15:19 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 04:15:19 INFO - 'opt_config_files': (), 04:15:19 INFO - 'pip_index': False, 04:15:19 INFO - 'suite': 'g4-stylo-disabled-e10s', 04:15:19 INFO - 'system_bits': '32', 04:15:19 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 04:15:19 INFO - 'title': 'talos-linux64-ix-046', 04:15:19 INFO - 'tooltool_cache': '/builds/tooltool_cache', 04:15:19 INFO - 'use_talos_json': True, 04:15:19 INFO - 'verify': 'False', 04:15:19 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 04:15:19 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 04:15:19 INFO - 'work_dir': 'build'} 04:15:19 INFO - [mozharness: 2017-11-08 12:15:19.095184Z] Running clobber step. 04:15:19 INFO - Running pre-action listener: _resource_record_pre_action 04:15:19 INFO - Running main action method: clobber 04:15:19 INFO - rmtree: /builds/slave/test/build 04:15:19 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 04:15:20 INFO - Running post-action listener: _resource_record_post_action 04:15:20 INFO - [mozharness: 2017-11-08 12:15:20.177998Z] Finished clobber step (success) 04:15:20 INFO - [mozharness: 2017-11-08 12:15:20.178093Z] Running read-buildbot-config step. 04:15:20 INFO - Running pre-action listener: _resource_record_pre_action 04:15:20 INFO - Running main action method: read_buildbot_config 04:15:20 INFO - Using buildbot properties: 04:15:20 INFO - { 04:15:20 INFO - "project": "", 04:15:20 INFO - "product": "firefox", 04:15:20 INFO - "who": "nbeleuzu@mozilla.com", 04:15:20 INFO - "installer_path": "public/build/target.tar.bz2", 04:15:20 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s", 04:15:20 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 04:15:20 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos g4-stylo-disabled-e10s", 04:15:20 INFO - "stage_platform": "linux64-pgo", 04:15:20 INFO - "basedir": "/builds/slave/test", 04:15:20 INFO - "buildnumber": 116, 04:15:20 INFO - "platform": "ubuntu64_hw", 04:15:20 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 04:15:20 INFO - "slavebuilddir": "test", 04:15:20 INFO - "taskId": "I0l97s_WRA6LvEn-VW-G-g", 04:15:20 INFO - "branch": "mozilla-central", 04:15:20 INFO - "script_repo_revision": "production", 04:15:20 INFO - "revision": "f63559d7e6a570e4e73ba367964099394248e18d", 04:15:20 INFO - "slavename": "talos-linux64-ix-046", 04:15:20 INFO - "repo_path": "mozilla-central" 04:15:20 INFO - } 04:15:20 INFO - Finding installer, test and symbols from parent task. 04:15:20 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/I0l97s_WRA6LvEn-VW-G-g'}, attempt #1 04:15:20 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/I0l97s_WRA6LvEn-VW-G-g'}, attempt #1 04:15:21 INFO - Task dependencies: JWakzwr3TEe5iMKuEKFsxw 04:15:21 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw'}, attempt #1 04:15:21 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2 04:15:21 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.test_packages.json 04:15:21 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.crashreporter-symbols.zip 04:15:21 INFO - Running post-action listener: _resource_record_post_action 04:15:21 INFO - [mozharness: 2017-11-08 12:15:21.582232Z] Finished read-buildbot-config step (success) 04:15:21 INFO - [mozharness: 2017-11-08 12:15:21.582449Z] Running download-and-extract step. 04:15:21 INFO - Running pre-action listener: _resource_record_pre_action 04:15:21 INFO - Running main action method: download_and_extract 04:15:21 INFO - mkdir: /builds/slave/test/build/tests 04:15:21 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:21 INFO - trying https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.test_packages.json 04:15:21 INFO - Downloading https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 04:15:21 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 04:15:22 INFO - Downloaded 989 bytes. 04:15:22 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 04:15:22 INFO - Using the following test package requirements: 04:15:22 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 04:15:22 INFO - u'common': [u'target.common.tests.zip'], 04:15:22 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 04:15:22 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 04:15:22 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 04:15:22 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 04:15:22 INFO - u'mozbase': [u'target.common.tests.zip'], 04:15:22 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 04:15:22 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 04:15:22 INFO - u'web-platform': [u'target.common.tests.zip', 04:15:22 INFO - u'target.web-platform.tests.tar.gz'], 04:15:22 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 04:15:22 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 04:15:22 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.common.tests.zip 04:15:22 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.common.tests.zip'}, attempt #1 04:15:22 INFO - Fetch https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.common.tests.zip into memory 04:15:23 INFO - Content-Length response header: 58656615 04:15:23 INFO - Bytes received: 58656615 04:15:34 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.talos.tests.zip 04:15:34 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.talos.tests.zip'}, attempt #1 04:15:34 INFO - Fetch https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.talos.tests.zip into memory 04:15:35 INFO - Content-Length response header: 18771918 04:15:35 INFO - Bytes received: 18771918 04:15:35 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:35 INFO - trying https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2 04:15:35 INFO - Downloading https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 04:15:35 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 04:15:36 INFO - Downloaded 63161601 bytes. 04:15:36 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2 04:15:36 INFO - mkdir: /builds/slave/test/properties 04:15:36 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 04:15:36 INFO - Writing to file /builds/slave/test/properties/build_url 04:15:36 INFO - Contents: 04:15:36 INFO - build_url:https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2 04:15:36 INFO - Running post-action listener: _resource_record_post_action 04:15:36 INFO - Running post-action listener: find_tests_for_verification 04:15:36 INFO - Running post-action listener: set_extra_try_arguments 04:15:36 INFO - [mozharness: 2017-11-08 12:15:36.722732Z] Finished download-and-extract step (success) 04:15:36 INFO - [mozharness: 2017-11-08 12:15:36.722838Z] Running populate-webroot step. 04:15:36 INFO - Running pre-action listener: _resource_record_pre_action 04:15:36 INFO - Running main action method: populate_webroot 04:15:36 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 04:15:36 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['tresize', 04:15:36 INFO - 'tcanvasmark']}, 04:15:36 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 04:15:36 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['dromaeo_css', 04:15:36 INFO - 'kraken']}, 04:15:36 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:15:36 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:15:36 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'tests': ['damp', 'tps']}, 04:15:36 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['damp', 'tps']}, 04:15:36 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 04:15:36 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['dromaeo_dom']}, 04:15:36 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 04:15:36 INFO - 'glvideo', 04:15:36 INFO - 'displaylist_mutate']}, 04:15:36 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['basic_compositor_video', 04:15:36 INFO - 'glvideo']}, 04:15:36 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 04:15:36 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['ts_paint_webext', 04:15:36 INFO - 'tp5o_webext']}, 04:15:36 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']}, 04:15:36 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:15:36 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:15:36 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:15:36 INFO - 'talos_options': ['--mitmproxy', 04:15:36 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:15:36 INFO - '--firstNonBlankPaint'], 04:15:36 INFO - 'tests': ['tp6_google_heavy', 04:15:36 INFO - 'tp6_youtube_heavy', 04:15:36 INFO - 'tp6_amazon_heavy', 04:15:36 INFO - 'tp6_facebook_heavy']}, 04:15:36 INFO - 'other-e10s': {'tests': ['a11yr', 04:15:36 INFO - 'ts_paint', 04:15:36 INFO - 'tpaint', 04:15:36 INFO - 'sessionrestore', 04:15:36 INFO - 'sessionrestore_many_windows', 04:15:36 INFO - 'sessionrestore_no_auto_restore', 04:15:36 INFO - 'tabpaint', 04:15:36 INFO - 'cpstartup']}, 04:15:36 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['a11yr', 04:15:36 INFO - 'ts_paint', 04:15:36 INFO - 'tpaint', 04:15:36 INFO - 'sessionrestore', 04:15:36 INFO - 'sessionrestore_many_windows', 04:15:36 INFO - 'sessionrestore_no_auto_restore', 04:15:36 INFO - 'tabpaint', 04:15:36 INFO - 'cpstartup']}, 04:15:36 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 04:15:36 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 04:15:36 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['perf_reftest_singletons']}, 04:15:36 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['perf_reftest']}, 04:15:36 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 04:15:36 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['speedometer']}, 04:15:36 INFO - 'svgr-e10s': {'tests': ['tsvgx', 04:15:36 INFO - 'tsvgr_opacity', 04:15:36 INFO - 'tart', 04:15:36 INFO - 'tscrollx', 04:15:36 INFO - 'tsvg_static']}, 04:15:36 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['tsvgx', 04:15:36 INFO - 'tsvgr_opacity', 04:15:36 INFO - 'tart', 04:15:36 INFO - 'tscrollx', 04:15:36 INFO - 'tsvg_static']}, 04:15:36 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 04:15:36 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'talos_options': ['--disable-stylo'], 04:15:36 INFO - 'tests': ['tp5o']}, 04:15:36 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:15:36 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:15:36 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:15:36 INFO - 'talos_options': ['--mitmproxy', 04:15:36 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:15:36 INFO - '--firstNonBlankPaint'], 04:15:36 INFO - 'tests': ['tp6_google', 04:15:36 INFO - 'tp6_youtube', 04:15:36 INFO - 'tp6_amazon', 04:15:36 INFO - 'tp6_facebook']}, 04:15:36 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:15:36 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:15:36 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:15:36 INFO - 'talos_options': ['--disable-stylo', 04:15:36 INFO - '--mitmproxy', 04:15:36 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:15:36 INFO - '--firstNonBlankPaint'], 04:15:36 INFO - 'tests': ['tp6_google', 04:15:36 INFO - 'tp6_youtube', 04:15:36 INFO - 'tp6_amazon', 04:15:36 INFO - 'tp6_facebook']}, 04:15:36 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 04:15:36 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 04:15:36 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 04:15:36 INFO - 'talos_options': ['--stylo-threads=1', 04:15:36 INFO - '--mitmproxy', 04:15:36 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 04:15:36 INFO - '--firstNonBlankPaint'], 04:15:36 INFO - 'tests': ['tp6_google', 04:15:36 INFO - 'tp6_youtube', 04:15:36 INFO - 'tp6_amazon', 04:15:36 INFO - 'tp6_facebook']}, 04:15:36 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'talos_options': ['--xperf_path', 04:15:36 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:15:36 INFO - 'tests': ['tp5n']}, 04:15:36 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 04:15:36 INFO - 'talos_options': ['--disable-stylo', 04:15:36 INFO - '--xperf_path', 04:15:36 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:15:36 INFO - 'tests': ['tp5n']}}} 04:15:36 INFO - Running post-action listener: _resource_record_post_action 04:15:36 INFO - [mozharness: 2017-11-08 12:15:36.742647Z] Finished populate-webroot step (success) 04:15:36 INFO - [mozharness: 2017-11-08 12:15:36.742761Z] Running create-virtualenv step. 04:15:36 INFO - Running pre-action listener: _resource_record_pre_action 04:15:36 INFO - Running main action method: create_virtualenv 04:15:36 INFO - Creating virtualenv /builds/slave/test/build/venv 04:15:36 INFO - Running command: ['/tools/buildbot/bin/python', '/builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py', '--always-copy', '/builds/slave/test/build/venv'] in /builds/slave/test/build 04:15:36 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv 04:15:36 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 04:15:37 INFO - Using real prefix '/usr' 04:15:37 INFO - New python executable in /builds/slave/test/build/venv/bin/python 04:15:37 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content 04:15:40 INFO - Installing setuptools, pip, wheel...done. 04:15:40 INFO - Return code: 0 04:15:40 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 04:15:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:40 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:15:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:40 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:15:40 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:15:40 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5'] in /builds/slave/test/build 04:15:40 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org pip>=1.5 04:15:40 INFO - Using env: {'DISPLAY': ':0', 04:15:40 INFO - 'HOME': '/home/cltbld', 04:15:40 INFO - 'LANG': 'en_US.UTF-8', 04:15:40 INFO - 'LANGUAGE': 'en_US:en', 04:15:40 INFO - 'LOGNAME': 'cltbld', 04:15:40 INFO - 'MAIL': '/var/mail/cltbld', 04:15:40 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:15:40 INFO - 'MOZ_NO_REMOTE': '1', 04:15:40 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:15:40 INFO - 'NO_EM_RESTART': '1', 04:15:40 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:15:40 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:15:40 INFO - 'PWD': '/builds/slave/test', 04:15:40 INFO - 'SHELL': '/bin/bash', 04:15:40 INFO - 'SHLVL': '1', 04:15:40 INFO - 'TERM': 'linux', 04:15:40 INFO - 'TMOUT': '86400', 04:15:40 INFO - 'USER': 'cltbld', 04:15:40 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:15:40 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:15:40 INFO - '_': '/tools/buildbot/bin/python'} 04:15:41 INFO - Ignoring indexes: https://pypi.python.org/simple 04:15:41 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages 04:15:41 INFO - Return code: 0 04:15:41 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 04:15:41 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:41 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:15:41 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:41 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:15:41 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:15:41 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'psutil>=3.1.1'] in /builds/slave/test/build 04:15:41 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org psutil>=3.1.1 04:15:41 INFO - Using env: {'DISPLAY': ':0', 04:15:41 INFO - 'HOME': '/home/cltbld', 04:15:41 INFO - 'LANG': 'en_US.UTF-8', 04:15:41 INFO - 'LANGUAGE': 'en_US:en', 04:15:41 INFO - 'LOGNAME': 'cltbld', 04:15:41 INFO - 'MAIL': '/var/mail/cltbld', 04:15:41 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:15:41 INFO - 'MOZ_NO_REMOTE': '1', 04:15:41 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:15:41 INFO - 'NO_EM_RESTART': '1', 04:15:41 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:15:41 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:15:41 INFO - 'PWD': '/builds/slave/test', 04:15:41 INFO - 'SHELL': '/bin/bash', 04:15:41 INFO - 'SHLVL': '1', 04:15:41 INFO - 'TERM': 'linux', 04:15:41 INFO - 'TMOUT': '86400', 04:15:41 INFO - 'USER': 'cltbld', 04:15:41 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:15:41 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:15:41 INFO - '_': '/tools/buildbot/bin/python'} 04:15:42 INFO - Ignoring indexes: https://pypi.python.org/simple 04:15:42 INFO - Collecting psutil>=3.1.1 04:15:43 INFO - Installing collected packages: psutil 04:15:43 INFO - Successfully installed psutil-3.1.1 04:15:43 INFO - Return code: 0 04:15:43 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 04:15:43 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:43 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:15:43 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:15:43 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:15:43 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:15:43 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 04:15:43 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org mozsystemmonitor==0.3 04:15:43 INFO - Using env: {'DISPLAY': ':0', 04:15:43 INFO - 'HOME': '/home/cltbld', 04:15:43 INFO - 'LANG': 'en_US.UTF-8', 04:15:43 INFO - 'LANGUAGE': 'en_US:en', 04:15:43 INFO - 'LOGNAME': 'cltbld', 04:15:43 INFO - 'MAIL': '/var/mail/cltbld', 04:15:43 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:15:43 INFO - 'MOZ_NO_REMOTE': '1', 04:15:43 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:15:43 INFO - 'NO_EM_RESTART': '1', 04:15:43 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:15:43 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:15:43 INFO - 'PWD': '/builds/slave/test', 04:15:43 INFO - 'SHELL': '/bin/bash', 04:15:43 INFO - 'SHLVL': '1', 04:15:43 INFO - 'TERM': 'linux', 04:15:43 INFO - 'TMOUT': '86400', 04:15:43 INFO - 'USER': 'cltbld', 04:15:43 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:15:43 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:15:43 INFO - '_': '/tools/buildbot/bin/python'} 04:15:43 INFO - Ignoring indexes: https://pypi.python.org/simple 04:15:43 INFO - Collecting mozsystemmonitor==0.3 04:15:44 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 04:15:44 INFO - Installing collected packages: mozsystemmonitor 04:15:44 INFO - Successfully installed mozsystemmonitor-0.3 04:15:44 INFO - Return code: 0 04:15:44 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 04:15: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')]} 04:15:44 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:15: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')]} 04:15:44 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:15:44 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:15:44 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1'] in /builds/slave/test/build 04:15:44 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema==2.5.1 04:15:44 INFO - Using env: {'DISPLAY': ':0', 04:15:44 INFO - 'HOME': '/home/cltbld', 04:15:44 INFO - 'LANG': 'en_US.UTF-8', 04:15:44 INFO - 'LANGUAGE': 'en_US:en', 04:15:44 INFO - 'LOGNAME': 'cltbld', 04:15:44 INFO - 'MAIL': '/var/mail/cltbld', 04:15:44 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:15:44 INFO - 'MOZ_NO_REMOTE': '1', 04:15:44 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:15:44 INFO - 'NO_EM_RESTART': '1', 04:15:44 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:15:44 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:15:44 INFO - 'PWD': '/builds/slave/test', 04:15:44 INFO - 'SHELL': '/bin/bash', 04:15:44 INFO - 'SHLVL': '1', 04:15:44 INFO - 'TERM': 'linux', 04:15:44 INFO - 'TMOUT': '86400', 04:15:44 INFO - 'USER': 'cltbld', 04:15:44 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:15:44 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:15:44 INFO - '_': '/tools/buildbot/bin/python'} 04:15:45 INFO - Ignoring indexes: https://pypi.python.org/simple 04:15:45 INFO - Collecting jsonschema==2.5.1 04:15:46 INFO - HTTP error 403 while getting http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl (from http://pypi.pvt.build.mozilla.org/pub/) 04:15:46 INFO - Could not install requirement jsonschema==2.5.1 from http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl because of error 403 Client Error: Forbidden for url: http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 04:15:46 INFO - Could not install requirement jsonschema==2.5.1 from http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl because of HTTP error 403 Client Error: Forbidden for url: http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl for URL http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl (from http://pypi.pvt.build.mozilla.org/pub/) 04:15:46 WARNING - Return code: 1 04:15:46 INFO - retry: Failed, sleeping 60 seconds before retrying 04:16:46 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', '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 #2 04:16:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1'] in /builds/slave/test/build 04:16:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema==2.5.1 04:16:46 INFO - Using env: {'DISPLAY': ':0', 04:16:46 INFO - 'HOME': '/home/cltbld', 04:16:46 INFO - 'LANG': 'en_US.UTF-8', 04:16:46 INFO - 'LANGUAGE': 'en_US:en', 04:16:46 INFO - 'LOGNAME': 'cltbld', 04:16:46 INFO - 'MAIL': '/var/mail/cltbld', 04:16:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:16:46 INFO - 'MOZ_NO_REMOTE': '1', 04:16:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:16:46 INFO - 'NO_EM_RESTART': '1', 04:16:46 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:16:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:16:46 INFO - 'PWD': '/builds/slave/test', 04:16:46 INFO - 'SHELL': '/bin/bash', 04:16:46 INFO - 'SHLVL': '1', 04:16:46 INFO - 'TERM': 'linux', 04:16:46 INFO - 'TMOUT': '86400', 04:16:46 INFO - 'USER': 'cltbld', 04:16:46 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:16:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:16:46 INFO - '_': '/tools/buildbot/bin/python'} 04:16:46 INFO - Ignoring indexes: https://pypi.python.org/simple 04:16:46 INFO - Collecting jsonschema==2.5.1 04:16:47 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl 04:16:47 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1) 04:16:48 INFO - Installing collected packages: functools32, jsonschema 04:16:48 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1 04:16:48 INFO - Return code: 0 04:16:48 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 04:16: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')]} 04:16:48 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:16: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')]} 04:16:48 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:16:48 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:16:48 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2'] in /builds/slave/test/build 04:16:48 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org functools32==3.2.3-2 04:16:49 INFO - Using env: {'DISPLAY': ':0', 04:16:49 INFO - 'HOME': '/home/cltbld', 04:16:49 INFO - 'LANG': 'en_US.UTF-8', 04:16:49 INFO - 'LANGUAGE': 'en_US:en', 04:16:49 INFO - 'LOGNAME': 'cltbld', 04:16:49 INFO - 'MAIL': '/var/mail/cltbld', 04:16:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:16:49 INFO - 'MOZ_NO_REMOTE': '1', 04:16:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:16:49 INFO - 'NO_EM_RESTART': '1', 04:16:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:16:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:16:49 INFO - 'PWD': '/builds/slave/test', 04:16:49 INFO - 'SHELL': '/bin/bash', 04:16:49 INFO - 'SHLVL': '1', 04:16:49 INFO - 'TERM': 'linux', 04:16:49 INFO - 'TMOUT': '86400', 04:16:49 INFO - 'USER': 'cltbld', 04:16:49 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:16:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:16:49 INFO - '_': '/tools/buildbot/bin/python'} 04:16:49 INFO - Ignoring indexes: https://pypi.python.org/simple 04:16:49 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 04:16:49 INFO - Return code: 0 04:16:49 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 04:16:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:16:49 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:16:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:16:49 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:16:49 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:16:49 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4'] in /builds/slave/test/build 04:16:49 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org blobuploader==1.2.4 04:16:49 INFO - Using env: {'DISPLAY': ':0', 04:16:49 INFO - 'HOME': '/home/cltbld', 04:16:49 INFO - 'LANG': 'en_US.UTF-8', 04:16:49 INFO - 'LANGUAGE': 'en_US:en', 04:16:49 INFO - 'LOGNAME': 'cltbld', 04:16:49 INFO - 'MAIL': '/var/mail/cltbld', 04:16:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:16:49 INFO - 'MOZ_NO_REMOTE': '1', 04:16:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:16:49 INFO - 'NO_EM_RESTART': '1', 04:16:49 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:16:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:16:49 INFO - 'PWD': '/builds/slave/test', 04:16:49 INFO - 'SHELL': '/bin/bash', 04:16:49 INFO - 'SHLVL': '1', 04:16:49 INFO - 'TERM': 'linux', 04:16:49 INFO - 'TMOUT': '86400', 04:16:49 INFO - 'USER': 'cltbld', 04:16:49 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:16:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:16:49 INFO - '_': '/tools/buildbot/bin/python'} 04:16:49 INFO - Ignoring indexes: https://pypi.python.org/simple 04:16:49 INFO - Collecting blobuploader==1.2.4 04:16:50 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4) 04:16:51 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4) 04:16:52 INFO - Installing collected packages: requests, docopt, blobuploader 04:16:53 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3 04:16:53 INFO - Return code: 0 04:16:53 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:16:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:16:53 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:16:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:16:53 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:16:53 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:16:53 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config 04:16:53 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 04:16:53 INFO - Using env: {'DISPLAY': ':0', 04:16:53 INFO - 'HOME': '/home/cltbld', 04:16:53 INFO - 'LANG': 'en_US.UTF-8', 04:16:53 INFO - 'LANGUAGE': 'en_US:en', 04:16:53 INFO - 'LOGNAME': 'cltbld', 04:16:53 INFO - 'MAIL': '/var/mail/cltbld', 04:16:53 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:16:53 INFO - 'MOZ_NO_REMOTE': '1', 04:16:53 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:16:53 INFO - 'NO_EM_RESTART': '1', 04:16:53 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:16:53 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:16:53 INFO - 'PWD': '/builds/slave/test', 04:16:53 INFO - 'SHELL': '/bin/bash', 04:16:53 INFO - 'SHLVL': '1', 04:16:53 INFO - 'TERM': 'linux', 04:16:53 INFO - 'TMOUT': '86400', 04:16:53 INFO - 'USER': 'cltbld', 04:16:53 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:16:53 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:16:53 INFO - '_': '/tools/buildbot/bin/python'} 04:16:53 INFO - Ignoring indexes: https://pypi.python.org/simple 04:16:53 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 04:16:53 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 04:16:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 04:16:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 04:16:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 04:16:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 04:16:54 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 04:16:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 04:16:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 04:16:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 04:16:55 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 04:16:55 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 04:16:56 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 04:16:56 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 04:16:56 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 04:16:56 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 04:16:56 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 04:16:56 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 04:16:56 INFO - Running setup.py install for manifestparser: started 04:16:57 INFO - Running setup.py install for manifestparser: finished with status 'done' 04:16:57 INFO - Running setup.py install for mozcrash: started 04:16:57 INFO - Running setup.py install for mozcrash: finished with status 'done' 04:16:57 INFO - Running setup.py install for mozdebug: started 04:16:57 INFO - Running setup.py install for mozdebug: finished with status 'done' 04:16:57 INFO - Running setup.py install for mozdevice: started 04:16:57 INFO - Running setup.py install for mozdevice: finished with status 'done' 04:16:57 INFO - Running setup.py install for mozfile: started 04:16:58 INFO - Running setup.py install for mozfile: finished with status 'done' 04:16:58 INFO - Running setup.py install for mozhttpd: started 04:16:58 INFO - Running setup.py install for mozhttpd: finished with status 'done' 04:16:58 INFO - Running setup.py install for mozinfo: started 04:16:58 INFO - Running setup.py install for mozinfo: finished with status 'done' 04:16:58 INFO - Running setup.py install for mozInstall: started 04:16:58 INFO - Running setup.py install for mozInstall: finished with status 'done' 04:16:58 INFO - Running setup.py install for mozleak: started 04:16:58 INFO - Running setup.py install for mozleak: finished with status 'done' 04:16:58 INFO - Running setup.py install for mozlog: started 04:16:59 INFO - Running setup.py install for mozlog: finished with status 'done' 04:16:59 INFO - Running setup.py install for moznetwork: started 04:16:59 INFO - Running setup.py install for moznetwork: finished with status 'done' 04:16:59 INFO - Running setup.py install for mozprocess: started 04:16:59 INFO - Running setup.py install for mozprocess: finished with status 'done' 04:16:59 INFO - Running setup.py install for mozprofile: started 04:16:59 INFO - Running setup.py install for mozprofile: finished with status 'done' 04:16:59 INFO - Running setup.py install for mozrunner: started 04:17:00 INFO - Running setup.py install for mozrunner: finished with status 'done' 04:17:00 INFO - Running setup.py install for mozscreenshot: started 04:17:00 INFO - Running setup.py install for mozscreenshot: finished with status 'done' 04:17:00 INFO - Running setup.py install for moztest: started 04:17:00 INFO - Running setup.py install for moztest: finished with status 'done' 04:17:00 INFO - Running setup.py install for mozversion: started 04:17:00 INFO - Running setup.py install for mozversion: finished with status 'done' 04:17:00 INFO - Successfully installed manifestparser-1.2 mozInstall-1.14 mozcrash-1.0 mozdebug-0.1 mozdevice-0.51 mozfile-1.2 mozhttpd-0.7 mozinfo-0.10 mozleak-0.1 mozlog-3.5 moznetwork-0.27 mozprocess-0.25 mozprofile-0.29 mozrunner-6.13 mozscreenshot-0.1 moztest-0.8 mozversion-1.4 04:17:00 INFO - Return code: 0 04:17:00 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:17:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:17:00 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:17:00 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:17:00 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:17:01 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:17:01 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config 04:17:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 04:17:01 INFO - Using env: {'DISPLAY': ':0', 04:17:01 INFO - 'HOME': '/home/cltbld', 04:17:01 INFO - 'LANG': 'en_US.UTF-8', 04:17:01 INFO - 'LANGUAGE': 'en_US:en', 04:17:01 INFO - 'LOGNAME': 'cltbld', 04:17:01 INFO - 'MAIL': '/var/mail/cltbld', 04:17:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:17:01 INFO - 'MOZ_NO_REMOTE': '1', 04:17:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:17:01 INFO - 'NO_EM_RESTART': '1', 04:17:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:17:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:17:01 INFO - 'PWD': '/builds/slave/test', 04:17:01 INFO - 'SHELL': '/bin/bash', 04:17:01 INFO - 'SHLVL': '1', 04:17:01 INFO - 'TERM': 'linux', 04:17:01 INFO - 'TMOUT': '86400', 04:17:01 INFO - 'USER': 'cltbld', 04:17:01 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:17:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:17:01 INFO - '_': '/tools/buildbot/bin/python'} 04:17:01 INFO - Ignoring indexes: https://pypi.python.org/simple 04:17:01 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser 04:17:01 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.2 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 04:17:01 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash 04:17:01 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==1.0 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:17:01 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug 04:17:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 04:17:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice 04:17:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.51 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:17:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile 04:17:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5)) 04:17:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd 04:17:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6)) 04:17:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo 04:17:02 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.10 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7)) 04:17:02 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall 04:17:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.14 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 04:17:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak 04:17:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9)) 04:17:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog 04:17:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.5 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 04:17:03 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork 04:17:03 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11)) 04:17:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess 04:17:03 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.25 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12)) 04:17:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile 04:17:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.29 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 04:17:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner 04:17:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.13 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 04:17:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot 04:17:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15)) 04:17:04 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest 04:17:04 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.8 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16)) 04:17:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion 04:17:04 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17)) 04:17:04 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 04:17:06 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl 04:17:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:17:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:17:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 04:17:06 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.51->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:17:06 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.19 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdevice==0.51->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:17:06 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.14->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 04:17:06 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 04:17:07 INFO - Installing collected packages: six, blessings 04:17:07 INFO - Successfully installed blessings-1.6 six-1.10.0 04:17:07 INFO - Return code: 0 04:17:07 INFO - Done creating virtualenv /builds/slave/test/build/venv. 04:17:07 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:17:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:17:07 INFO - Reading from file tmpfile_stdout 04:17:07 INFO - Reading from file tmpfile_stderr 04:17:07 INFO - Current package versions: 04:17:07 INFO - blessings == 1.6 04:17:07 INFO - blobuploader == 1.2.4 04:17:07 INFO - docopt == 0.6.1 04:17:07 INFO - functools32 == 3.2.3.post2 04:17:07 INFO - jsonschema == 2.5.1 04:17:07 INFO - manifestparser == 1.2 04:17:07 INFO - mozInstall == 1.14 04:17:07 INFO - mozcrash == 1.0 04:17:07 INFO - mozdebug == 0.1 04:17:07 INFO - mozdevice == 0.51 04:17:07 INFO - mozfile == 1.2 04:17:07 INFO - mozhttpd == 0.7 04:17:07 INFO - mozinfo == 0.10 04:17:07 INFO - mozleak == 0.1 04:17:07 INFO - mozlog == 3.5 04:17:07 INFO - moznetwork == 0.27 04:17:07 INFO - mozprocess == 0.25 04:17:07 INFO - mozprofile == 0.29 04:17:07 INFO - mozrunner == 6.13 04:17:07 INFO - mozscreenshot == 0.1 04:17:07 INFO - mozsystemmonitor == 0.3 04:17:07 INFO - moztest == 0.8 04:17:07 INFO - mozversion == 1.4 04:17:07 INFO - psutil == 3.1.1 04:17:07 INFO - requests == 1.2.3 04:17:07 INFO - six == 1.10.0 04:17:07 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:17:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:17:07 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:17:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:17:07 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:17:07 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:17:07 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/talos 04:17:07 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org 04:17:07 INFO - Using env: {'DISPLAY': ':0', 04:17:07 INFO - 'HOME': '/home/cltbld', 04:17:07 INFO - 'LANG': 'en_US.UTF-8', 04:17:07 INFO - 'LANGUAGE': 'en_US:en', 04:17:07 INFO - 'LOGNAME': 'cltbld', 04:17:07 INFO - 'MAIL': '/var/mail/cltbld', 04:17:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:17:07 INFO - 'MOZ_NO_REMOTE': '1', 04:17:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:17:07 INFO - 'NO_EM_RESTART': '1', 04:17:07 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:17:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:17:07 INFO - 'PWD': '/builds/slave/test', 04:17:07 INFO - 'SHELL': '/bin/bash', 04:17:07 INFO - 'SHLVL': '1', 04:17:07 INFO - 'TERM': 'linux', 04:17:07 INFO - 'TMOUT': '86400', 04:17:07 INFO - 'USER': 'cltbld', 04:17:07 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:17:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:17:07 INFO - '_': '/tools/buildbot/bin/python'} 04:17:08 INFO - Ignoring indexes: https://pypi.python.org/simple 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 04:17:08 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 9)) 04:17:08 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 04:17:09 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:17:10 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/requests-2.18.3-py2.py3-none-any.whl (88kB) 04:17:10 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:17:10 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:17:10 INFO - Requirement already satisfied (use --upgrade to upgrade): six>=1.10.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozprofile>=0.25->-r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 04:17:10 INFO - Collecting chardet<3.1.0,>=3.0.2 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:17:11 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/chardet-3.0.4-py2.py3-none-any.whl (133kB) 04:17:11 INFO - Collecting urllib3<1.23,>=1.21.1 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:17:12 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/urllib3-1.22-py2.py3-none-any.whl (132kB) 04:17:12 INFO - Collecting certifi>=2017.4.17 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:17:13 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/certifi-2017.7.27.1-py2.py3-none-any.whl (349kB) 04:17:13 INFO - Collecting idna<2.6,>=2.5 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 04:17:14 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/idna-2.5-py2.py3-none-any.whl (55kB) 04:17:14 INFO - Installing collected packages: simplejson, chardet, urllib3, certifi, idna, requests 04:17:14 INFO - Found existing installation: requests 1.2.3 04:17:14 INFO - Uninstalling requests-1.2.3: 04:17:14 INFO - Successfully uninstalled requests-1.2.3 04:17:15 INFO - Successfully installed certifi-2017.7.27.1 chardet-3.0.4 idna-2.5 requests-2.18.3 simplejson-3.3.0 urllib3-1.22 04:17:15 INFO - Return code: 0 04:17:15 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 04:17:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:17:15 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:17:15 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:17:15 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:17:15 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 0x25882d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2760a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2903930>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, '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': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:17:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema'] in /builds/slave/test/build 04:17:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema 04:17:15 INFO - Using env: {'DISPLAY': ':0', 04:17:15 INFO - 'HOME': '/home/cltbld', 04:17:15 INFO - 'LANG': 'en_US.UTF-8', 04:17:15 INFO - 'LANGUAGE': 'en_US:en', 04:17:15 INFO - 'LOGNAME': 'cltbld', 04:17:15 INFO - 'MAIL': '/var/mail/cltbld', 04:17:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:17:15 INFO - 'MOZ_NO_REMOTE': '1', 04:17:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:17:15 INFO - 'NO_EM_RESTART': '1', 04:17:15 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:17:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:17:15 INFO - 'PWD': '/builds/slave/test', 04:17:15 INFO - 'SHELL': '/bin/bash', 04:17:15 INFO - 'SHLVL': '1', 04:17:15 INFO - 'TERM': 'linux', 04:17:15 INFO - 'TMOUT': '86400', 04:17:15 INFO - 'USER': 'cltbld', 04:17:15 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:17:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:17:15 INFO - '_': '/tools/buildbot/bin/python'} 04:17:15 INFO - Ignoring indexes: https://pypi.python.org/simple 04:17:15 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 04:17:15 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema) 04:17:15 INFO - Return code: 0 04:17:15 INFO - Running post-action listener: _resource_record_post_action 04:17:15 INFO - Running post-action listener: _start_resource_monitoring 04:17:15 INFO - Starting resource monitoring. 04:17:15 INFO - [mozharness: 2017-11-08 12:17:15.649631Z] Finished create-virtualenv step (success) 04:17:15 INFO - [mozharness: 2017-11-08 12:17:15.650147Z] Running install step. 04:17:15 INFO - Running pre-action listener: _resource_record_pre_action 04:17:15 INFO - Running main action method: install 04:17:15 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:17:15 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:17:16 INFO - Reading from file tmpfile_stdout 04:17:16 INFO - Reading from file tmpfile_stderr 04:17:16 INFO - Detecting whether we're running mozinstall >=1.0... 04:17:16 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 04:17:16 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 04:17:16 INFO - Reading from file tmpfile_stdout 04:17:16 INFO - Output received: 04:17:16 INFO - Usage: mozinstall [options] installer 04:17:16 INFO - Options: 04:17:16 INFO - -h, --help show this help message and exit 04:17:16 INFO - -d DEST, --destination=DEST 04:17:16 INFO - Directory to install application into. [default: 04:17:16 INFO - "/builds/slave/test"] 04:17:16 INFO - --app=APP Application being installed. [default: firefox] 04:17:16 INFO - mkdir: /builds/slave/test/build/application 04:17:16 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/target.tar.bz2', '--destination', '/builds/slave/test/build/application'] 04:17:16 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 04:17:34 INFO - Reading from file tmpfile_stdout 04:17:34 INFO - Output received: 04:17:34 INFO - /builds/slave/test/build/application/firefox/firefox 04:17:34 INFO - Running post-action listener: _resource_record_post_action 04:17:34 INFO - [mozharness: 2017-11-08 12:17:34.508011Z] Finished install step (success) 04:17:34 INFO - [mozharness: 2017-11-08 12:17:34.508156Z] Running setup-mitmproxy step. 04:17:34 INFO - Running pre-action listener: _resource_record_pre_action 04:17:34 INFO - Running main action method: setup_mitmproxy 04:17:34 INFO - Skipping: mitmproxy is not required 04:17:34 INFO - Running post-action listener: _resource_record_post_action 04:17:34 INFO - [mozharness: 2017-11-08 12:17:34.508676Z] Finished setup-mitmproxy step (success) 04:17:34 INFO - [mozharness: 2017-11-08 12:17:34.508824Z] Running run-tests step. 04:17:34 INFO - Running pre-action listener: _resource_record_pre_action 04:17:34 INFO - Running pre-action listener: _set_gcov_prefix 04:17:34 INFO - Running main action method: run_tests 04:17:34 WARNING - Try message not found. 04:17:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 04:17:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 04:17:34 INFO - Python 2.7.3 04:17:34 INFO - Return code: 0 04:17:34 INFO - grabbing minidump binary from tooltool 04:17:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:17:34 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 0x2900ad0>, '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 0x29019d0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2901e60>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 04:17:34 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://tooltool.mozilla-releng.net/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build 04:17:34 INFO - Copy/paste: /tools/tooltool.py --url https://tooltool.mozilla-releng.net/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache 04:17:34 INFO - Calling ['/tools/tooltool.py', '--url', 'https://tooltool.mozilla-releng.net/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] with output_timeout 600 04:17:34 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 04:17:34 INFO - Return code: 0 04:17:34 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 04:17:34 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 04:17:34 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 04:17:34 INFO - ENV: RUST_BACKTRACE is now full 04:17:34 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 04:17:34 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 04:17:34 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-046', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] in /builds/slave/test/build 04:17:34 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite g4-stylo-disabled-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-046 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log 04:17:34 INFO - Using env: {'DISPLAY': ':0', 04:17:34 INFO - 'HOME': '/home/cltbld', 04:17:34 INFO - 'LANG': 'en_US.UTF-8', 04:17:34 INFO - 'LANGUAGE': 'en_US:en', 04:17:34 INFO - 'LOGNAME': 'cltbld', 04:17:34 INFO - 'MAIL': '/var/mail/cltbld', 04:17:34 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:17:34 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 04:17:34 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:17:34 INFO - 'MOZ_NO_REMOTE': '1', 04:17:34 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:17:34 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:17:34 INFO - 'NO_EM_RESTART': '1', 04:17:34 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:17:34 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:17:34 INFO - 'PWD': '/builds/slave/test', 04:17:34 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:17:34 INFO - 'RUST_BACKTRACE': 'full', 04:17:34 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 04:17:34 INFO - 'SHELL': '/bin/bash', 04:17:34 INFO - 'SHLVL': '1', 04:17:34 INFO - 'TERM': 'linux', 04:17:34 INFO - 'TMOUT': '86400', 04:17:34 INFO - 'USER': 'cltbld', 04:17:34 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:17:34 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:17:34 INFO - '_': '/tools/buildbot/bin/python'} 04:17:34 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-046', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] with output_timeout 3600 04:17:34 INFO - mozversion application_buildid: 20171108105156 04:17:34 INFO - mozversion application_changeset: f63559d7e6a570e4e73ba367964099394248e18d 04:17:34 INFO - mozversion application_display_name: Nightly 04:17:34 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 04:17:34 INFO - mozversion application_name: Firefox 04:17:34 INFO - mozversion application_remotingname: firefox 04:17:34 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 04:17:34 INFO - mozversion application_vendor: Mozilla 04:17:34 INFO - mozversion application_version: 58.0a1 04:17:34 INFO - mozversion platform_buildid: 20171108105156 04:17:34 INFO - mozversion platform_changeset: f63559d7e6a570e4e73ba367964099394248e18d 04:17:34 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 04:17:34 INFO - mozversion platform_version: 58.0a1 04:17:34 INFO - using testdate: 1510143454 04:17:34 INFO - actual date: 1510143454 04:17:34 INFO - starting webserver on 'localhost:32965' 04:17:34 INFO - SUITE-START | Running 2 tests 04:17:34 INFO - TEST-START | basic_compositor_video 04:17:34 INFO - Initialising browser for basic_compositor_video test... 04:17:34 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:32965/getInfo.html -profile /tmp/tmpx7fuib/profile 04:17:34 INFO - TEST-INFO | started process 21354 (/builds/slave/test/build/application/firefox/firefox http://localhost:32965/getInfo.html) 04:17:40 INFO - TEST-INFO | 21354: exit 0 04:17:40 INFO - Browser initialized. 04:17:40 INFO - Running cycle 1/1 for basic_compositor_video test... 04:17:40 INFO - Using env: {'DISPLAY': ':0', 04:17:40 INFO - 'HOME': '/home/cltbld', 04:17:40 INFO - 'JSGC_DISABLE_POISONING': '1', 04:17:40 INFO - 'LANG': 'en_US.UTF-8', 04:17:40 INFO - 'LANGUAGE': 'en_US:en', 04:17:40 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 04:17:40 INFO - 'LOGNAME': 'cltbld', 04:17:40 INFO - 'MAIL': '/var/mail/cltbld', 04:17:40 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:17:40 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 04:17:40 INFO - 'MOZ_CRASHREPORTER': '1', 04:17:40 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:17:40 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 04:17:40 INFO - 'MOZ_NO_REMOTE': '1', 04:17:40 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:17:40 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:17:40 INFO - 'NO_EM_RESTART': '1', 04:17:40 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:17:40 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:17:40 INFO - 'PWD': '/builds/slave/test', 04:17:40 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:17:40 INFO - 'RUST_BACKTRACE': 'full', 04:17:40 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 04:17:40 INFO - 'SHELL': '/bin/bash', 04:17:40 INFO - 'SHLVL': '1', 04:17:40 INFO - 'STYLO_FORCE_DISABLED': '1', 04:17:40 INFO - 'TERM': 'linux', 04:17:40 INFO - 'TMOUT': '86400', 04:17:40 INFO - 'USER': 'cltbld', 04:17:40 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:17:40 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:17:40 INFO - '_': '/tools/buildbot/bin/python'} 04:17:40 INFO - TEST-INFO | started process 21625 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpx7fuib/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 04:17:41 INFO - PID 21625 | 04:17:41 INFO - PID 21625 | (/builds/slave/test/build/application/firefox/firefox:21676): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 04:17:41 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6810700280112045 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6698121869782971 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7304065743944634 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7037052810902902 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.049662618083672 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.1336570247933855 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.62021712907117 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.572660714285712 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.209852430555555 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.634760563380282 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.527561403508782 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 10.257923076923069 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.949434306569332 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.472748691099506 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.296086065573782 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.97709580838325 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.322075471698108 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.582089947089944 ms/frame 04:18:27 INFO - PID 21625 | 04:18:27 INFO - PID 21625 | Cycle 1(1): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:19:13 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.684023569023569 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6700417362270452 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7335413056036975 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6956949152542373 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.110554794520548 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.961009900990098 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.489255813953491 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.414470989761088 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.640009398496241 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.602661064425774 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.171305084745763 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 10.417838541666677 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.156245353159846 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.642260638297886 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.349032921810679 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.906726190476201 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.45194656488551 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.992005494505484 ms/frame 04:19:13 INFO - PID 21625 | 04:19:13 INFO - PID 21625 | Cycle 1(2): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:19:59 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6821889013452915 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6716708437761072 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7292708933717578 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.713916023993145 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.179505571030641 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.158721413721416 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.686554054054051 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.6105505415162504 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.618511235955056 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.452479564032701 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.1360472972973 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 10.58232804232803 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.112277777777773 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.58240740740743 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.297725409836083 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.049939759036105 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.583918918918922 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.175949720670406 ms/frame 04:19:59 INFO - PID 21625 | 04:19:59 INFO - PID 21625 | Cycle 1(3): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:20:45 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6817180493273542 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6682860717264387 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7361979166666666 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.70997435897436 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.001286666666667 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.09891393442623 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.4484022988505756 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.351524288107204 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.673119092627596 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.450272479564033 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 9.678387096774191 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 10.206122448979599 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.071826568265683 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.584100529100512 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.55504184100421 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.76726470588234 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.451526717557263 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.050055248618772 ms/frame 04:20:45 INFO - PID 21625 | 04:20:45 INFO - PID 21625 | Cycle 1(4): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:21:32 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.680125979843225 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6684070058381981 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.737298784018529 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7039054514480403 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.059763193504735 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.1495539419087155 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.481525522041764 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.3902457627118627 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.49575091575091 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.652062146892661 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.642145390070919 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 9.526761904761917 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.03191176470587 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.471753926701588 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.450601659751012 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.195640243902478 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.279586466165396 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.930546448087437 ms/frame 04:21:32 INFO - PID 21625 | 04:21:32 INFO - PID 21625 | Cycle 1(5): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:22:18 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.680243561030235 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6668708333333333 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7188201603665518 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6979286926994905 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.138455172413792 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.167333333333333 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.4486264367816095 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.362268907563024 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.682774621212123 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.525994475138122 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.45304878048781 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 9.662777777777777 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.196044776119393 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.75362903225808 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.659894514767918 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.125909090909099 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.539288461538447 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.86994565217391 ms/frame 04:22:18 INFO - PID 21625 | 04:22:18 INFO - PID 21625 | Cycle 1(6): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:22:41 INFO - PID 21625 | 04:22:41 INFO - PID 21625 | (/builds/slave/test/build/application/firefox/firefox:21755): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 04:22:41 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6788248461108004 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6681651376146787 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7275302245250428 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6909509721048186 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.049089068825911 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.0327016129032245 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.5301411764705892 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.442710843373494 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.515496323529412 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.391805929919139 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.067919463087254 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 10.261820512820515 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.036066176470593 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.472198952879593 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.767617021276592 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.123393939393942 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.719667968750002 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.111361111111142 ms/frame 04:23:04 INFO - PID 21625 | 04:23:04 INFO - PID 21625 | Cycle 1(7): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:23:50 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6820655829596414 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6699373956594323 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7536031560490941 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7057161125319704 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.139248275862069 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.168989583333333 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.6376000000000004 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.540477876106193 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.640366541353389 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.5873743016759745 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.06999999999999 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 9.665555555555558 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.19695895522388 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.529447368421058 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.605945378151246 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.698713450292416 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.586814671814674 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.114666666666663 ms/frame 04:23:50 INFO - PID 21625 | 04:23:50 INFO - PID 21625 | Cycle 1(8): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:24:36 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.68222533632287 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6685988323603007 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7710064935064935 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.729498703543648 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.017342704149933 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.150020746887966 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.6636141636141635 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.552877442273535 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.514761029411763 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.604201680672271 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.000649999999998 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 10.004050000000007 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.03327205882354 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585079365079336 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.554602510460263 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.976377245508983 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.411159695817497 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.300112994350297 ms/frame 04:24:36 INFO - PID 21625 | 04:24:36 INFO - PID 21625 | Cycle 1(9): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:25:22 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6950197740112993 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6682318598832357 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.72949855907781 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6935055038103293 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.104651162790698 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.108993839835729 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.5175849941383355 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.455742659758204 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.682784090909095 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.543240997229908 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.00278333333333 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 10.105176767676772 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.236910112359555 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.81667567567567 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.449896265560177 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.201310975609752 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.197052238805961 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.754623655913981 ms/frame 04:25:22 INFO - PID 21625 | 04:25:22 INFO - PID 21625 | Cycle 1(10): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:26:09 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6779178311906093 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6673875000000005 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7597624633431082 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7671510600706721 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 4.133450413223141 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.133688016528925 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.546258865248227 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4973426573426565 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.650376647834272 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.512369146005514 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.346913793103447 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 9.954303482587058 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.11448148148148 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.58481481481481 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.449854771784237 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.767499999999991 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 12.001200000000011 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.17726256983238 ms/frame 04:26:09 INFO - PID 21625 | 04:26:09 INFO - PID 21625 | Cycle 1(11): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:26:55 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6793816452154449 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6691951626355297 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7445145348837208 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.735503035559411 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_startup = 3.9954660452729684 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.9846215139442243 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_startup = 3.453181818181817 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1_inclip = 3.373827993254638 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.725648854961835 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.619255617977522 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_startup = 10.309656357388318 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.480p.60fps.webm_scale_2_inclip = 9.663285024154604 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.195391791044782 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.754489247311824 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.24814285714285 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.909107142857161 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.674805447470828 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.29971751412431 ms/frame 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | Cycle 1(12): loaded http://localhost:32965/tests/video/video_playback.html (next: http://localhost:32965/tests/video/video_playback.html) 04:26:55 INFO - PID 21625 | __start_tp_report 04:26:55 INFO - PID 21625 | _x_x_mozilla_page_load 04:26:55 INFO - PID 21625 | _x_x_mozilla_page_load_details 04:26:55 INFO - PID 21625 | |i|pagename|runs| 04:26:55 INFO - PID 21625 | |0;240p.120fps.mp4_scale_1_startup;1.6810700280112045;1.684023569023569;1.6821889013452915;1.6817180493273542;1.680125979843225;1.680243561030235;1.6788248461108004;1.6820655829596414;1.68222533632287;1.6950197740112993;1.6779178311906093;1.6793816452154449 04:26:55 INFO - PID 21625 | |1;240p.120fps.mp4_scale_1_inclip;1.6698121869782971;1.6700417362270452;1.6716708437761072;1.6682860717264387;1.6684070058381981;1.6668708333333333;1.6681651376146787;1.6699373956594323;1.6685988323603007;1.6682318598832357;1.6673875000000005;1.6691951626355297 04:26:55 INFO - PID 21625 | |2;240p.120fps.mp4_scale_1.1_startup;1.7304065743944634;1.7335413056036975;1.7292708933717578;1.7361979166666666;1.737298784018529;1.7188201603665518;1.7275302245250428;1.7536031560490941;1.7710064935064935;1.72949855907781;1.7597624633431082;1.7445145348837208 04:26:55 INFO - PID 21625 | |3;240p.120fps.mp4_scale_1.1_inclip;1.7037052810902902;1.6956949152542373;1.713916023993145;1.70997435897436;1.7039054514480403;1.6979286926994905;1.6909509721048186;1.7057161125319704;1.729498703543648;1.6935055038103293;1.7671510600706721;1.735503035559411 04:26:55 INFO - PID 21625 | |4;240p.120fps.mp4_scale_2_startup;4.049662618083672;4.110554794520548;4.179505571030641;4.001286666666667;4.059763193504735;4.138455172413792;4.049089068825911;4.139248275862069;4.017342704149933;4.104651162790698;4.133450413223141;3.9954660452729684 04:26:55 INFO - PID 21625 | |5;240p.120fps.mp4_scale_2_inclip;4.1336570247933855;3.961009900990098;4.158721413721416;4.09891393442623;4.1495539419087155;4.167333333333333;4.0327016129032245;4.168989583333333;4.150020746887966;4.108993839835729;4.133688016528925;3.9846215139442243 04:26:55 INFO - PID 21625 | |6;480p.60fps.webm_scale_1_startup;3.62021712907117;3.489255813953491;3.686554054054051;3.4484022988505756;3.481525522041764;3.4486264367816095;3.5301411764705892;3.6376000000000004;3.6636141636141635;3.5175849941383355;3.546258865248227;3.453181818181817 04:26:55 INFO - PID 21625 | |7;480p.60fps.webm_scale_1_inclip;3.572660714285712;3.414470989761088;3.6105505415162504;3.351524288107204;3.3902457627118627;3.362268907563024;3.442710843373494;3.540477876106193;3.552877442273535;3.455742659758204;3.4973426573426565;3.373827993254638 04:26:55 INFO - PID 21625 | |8;480p.60fps.webm_scale_1.1_startup;5.209852430555555;5.640009398496241;5.618511235955056;5.673119092627596;5.49575091575091;5.682774621212123;5.515496323529412;5.640366541353389;5.514761029411763;5.682784090909095;5.650376647834272;5.725648854961835 04:26:55 INFO - PID 21625 | |9;480p.60fps.webm_scale_1.1_inclip;5.634760563380282;5.602661064425774;5.452479564032701;5.450272479564033;5.652062146892661;5.525994475138122;5.391805929919139;5.5873743016759745;5.604201680672271;5.543240997229908;5.512369146005514;5.619255617977522 04:26:55 INFO - PID 21625 | |10;480p.60fps.webm_scale_2_startup;10.527561403508782;10.171305084745763;10.1360472972973;9.678387096774191;10.642145390070919;10.45304878048781;10.067919463087254;10.06999999999999;10.000649999999998;10.00278333333333;10.346913793103447;10.309656357388318 04:26:55 INFO - PID 21625 | |11;480p.60fps.webm_scale_2_inclip;10.257923076923069;10.417838541666677;10.58232804232803;10.206122448979599;9.526761904761917;9.662777777777777;10.261820512820515;9.665555555555558;10.004050000000007;10.105176767676772;9.954303482587058;9.663285024154604 04:26:55 INFO - PID 21625 | |12;1080p.60fps.mp4_scale_1_startup;10.949434306569332;11.156245353159846;11.112277777777773;11.071826568265683;11.03191176470587;11.196044776119393;11.036066176470593;11.19695895522388;11.03327205882354;11.236910112359555;11.11448148148148;11.195391791044782 04:26:55 INFO - PID 21625 | |13;1080p.60fps.mp4_scale_1_inclip;10.472748691099506;10.642260638297886;10.58240740740743;10.584100529100512;10.471753926701588;10.75362903225808;10.472198952879593;10.529447368421058;10.585079365079336;10.81667567567567;10.58481481481481;10.754489247311824 04:26:55 INFO - PID 21625 | |14;1080p.60fps.mp4_scale_1.1_startup;12.296086065573782;12.349032921810679;12.297725409836083;12.55504184100421;12.450601659751012;12.659894514767918;12.767617021276592;12.605945378151246;12.554602510460263;12.449896265560177;12.449854771784237;12.24814285714285 04:26:55 INFO - PID 21625 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.97709580838325;11.906726190476201;12.049939759036105;11.76726470588234;12.195640243902478;12.125909090909099;12.123393939393942;11.698713450292416;11.976377245508983;12.201310975609752;11.767499999999991;11.909107142857161 04:26:55 INFO - PID 21625 | |16;1080p.60fps.mp4_scale_2_startup;11.322075471698108;11.45194656488551;11.583918918918922;11.451526717557263;11.279586466165396;11.539288461538447;11.719667968750002;11.586814671814674;11.411159695817497;11.197052238805961;12.001200000000011;11.674805447470828 04:26:55 INFO - PID 21625 | |17;1080p.60fps.mp4_scale_2_inclip;10.582089947089944;10.992005494505484;11.175949720670406;11.050055248618772;10.930546448087437;10.86994565217391;11.111361111111142;11.114666666666663;11.300112994350297;10.754623655913981;11.17726256983238;11.29971751412431 04:26:55 INFO - PID 21625 | __end_tp_report 04:26:55 INFO - PID 21625 | __start_cc_report 04:26:55 INFO - PID 21625 | _x_x_mozilla_cycle_collect,591 04:26:55 INFO - PID 21625 | __end_cc_report 04:26:55 INFO - PID 21625 | __startTimestamp1510144015539__endTimestamp 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | ------- Summary: start ------- 04:26:55 INFO - PID 21625 | Number of tests: 18 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#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 04:26:55 INFO - PID 21625 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#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 04:26:55 INFO - PID 21625 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.74 Median:1.74 stddev:0.02 (0.9%) stddev-sans-first:0.02 04:26:55 INFO - PID 21625 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.8 1.8 1.7 1.8 1.7 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.71 Median:1.71 stddev:0.02 (1.3%) stddev-sans-first:0.02 04:26:55 INFO - PID 21625 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.8 1.7 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.08 Median:4.11 stddev:0.06 (1.5%) stddev-sans-first:0.06 04:26:55 INFO - PID 21625 | Values: 4.0 4.1 4.2 4.0 4.1 4.1 4.0 4.1 4.0 4.1 4.1 4.0 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.10 Median:4.14 stddev:0.07 (1.7%) stddev-sans-first:0.07 04:26:55 INFO - PID 21625 | Values: 4.1 4.0 4.2 4.1 4.1 4.2 4.0 4.2 4.2 4.1 4.1 4.0 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.54 Median:3.54 stddev:0.09 (2.5%) stddev-sans-first:0.09 04:26:55 INFO - PID 21625 | Values: 3.6 3.5 3.7 3.4 3.5 3.4 3.5 3.6 3.7 3.5 3.5 3.5 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.46 Median:3.48 stddev:0.09 (2.6%) stddev-sans-first:0.09 04:26:55 INFO - PID 21625 | Values: 3.6 3.4 3.6 3.4 3.4 3.4 3.4 3.5 3.6 3.5 3.5 3.4 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.59 Median:5.65 stddev:0.14 (2.5%) stddev-sans-first:0.08 04:26:55 INFO - PID 21625 | Values: 5.2 5.6 5.6 5.7 5.5 5.7 5.5 5.6 5.5 5.7 5.7 5.7 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.55 Median:5.60 stddev:0.08 (1.5%) stddev-sans-first:0.08 04:26:55 INFO - PID 21625 | Values: 5.6 5.6 5.5 5.5 5.7 5.5 5.4 5.6 5.6 5.5 5.5 5.6 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:10.20 Median:10.33 stddev:0.27 (2.6%) stddev-sans-first:0.26 04:26:55 INFO - PID 21625 | Values: 10.5 10.2 10.1 9.7 10.6 10.5 10.1 10.1 10.0 10.0 10.3 10.3 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:10.03 Median:10.05 stddev:0.34 (3.4%) stddev-sans-first:0.35 04:26:55 INFO - PID 21625 | Values: 10.3 10.4 10.6 10.2 9.5 9.7 10.3 9.7 10.0 10.1 10.0 9.7 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.11 Median:11.14 stddev:0.09 (0.8%) stddev-sans-first:0.08 04:26:55 INFO - PID 21625 | Values: 10.9 11.2 11.1 11.1 11.0 11.2 11.0 11.2 11.0 11.2 11.1 11.2 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.60 Median:10.58 stddev:0.12 (1.1%) stddev-sans-first:0.11 04:26:55 INFO - PID 21625 | Values: 10.5 10.6 10.6 10.6 10.5 10.8 10.5 10.5 10.6 10.8 10.6 10.8 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.47 Median:12.50 stddev:0.16 (1.3%) stddev-sans-first:0.16 04:26:55 INFO - PID 21625 | Values: 12.3 12.3 12.3 12.6 12.5 12.7 12.8 12.6 12.6 12.4 12.4 12.2 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.97 Median:12.01 stddev:0.17 (1.4%) stddev-sans-first:0.18 04:26:55 INFO - PID 21625 | Values: 12.0 11.9 12.0 11.8 12.2 12.1 12.1 11.7 12.0 12.2 11.8 11.9 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.52 Median:11.56 stddev:0.22 (1.9%) stddev-sans-first:0.22 04:26:55 INFO - PID 21625 | Values: 11.3 11.5 11.6 11.5 11.3 11.5 11.7 11.6 11.4 11.2 12.0 11.7 04:26:55 INFO - PID 21625 | 04:26:55 INFO - PID 21625 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:11.03 Median:11.11 stddev:0.22 (1.9%) stddev-sans-first:0.17 04:26:55 INFO - PID 21625 | Values: 10.6 11.0 11.2 11.1 10.9 10.9 11.1 11.1 11.3 10.8 11.2 11.3 04:26:55 INFO - PID 21625 | -------- Summary: end -------- 04:26:55 INFO - PID 21625 | 04:26:56 INFO - TEST-INFO | 21625: exit 0 04:26:56 INFO - TEST-OK | basic_compositor_video | took 561144ms 04:26:56 INFO - TEST-START | glvideo 04:26:56 INFO - Initialising browser for glvideo test... 04:26:56 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:32965/getInfo.html -profile /tmp/tmpt7eKTC/profile 04:26:56 INFO - TEST-INFO | started process 22872 (/builds/slave/test/build/application/firefox/firefox http://localhost:32965/getInfo.html) 04:27:01 INFO - TEST-INFO | 22872: exit 0 04:27:01 INFO - Browser initialized. 04:27:01 INFO - Running cycle 1/1 for glvideo test... 04:27:01 INFO - Using env: {'DISPLAY': ':0', 04:27:01 INFO - 'HOME': '/home/cltbld', 04:27:01 INFO - 'JSGC_DISABLE_POISONING': '1', 04:27:01 INFO - 'LANG': 'en_US.UTF-8', 04:27:01 INFO - 'LANGUAGE': 'en_US:en', 04:27:01 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 04:27:01 INFO - 'LOGNAME': 'cltbld', 04:27:01 INFO - 'MAIL': '/var/mail/cltbld', 04:27:01 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:27:01 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 04:27:01 INFO - 'MOZ_CRASHREPORTER': '1', 04:27:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:27:01 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 04:27:01 INFO - 'MOZ_NO_REMOTE': '1', 04:27:01 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:27:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:27:01 INFO - 'NO_EM_RESTART': '1', 04:27:01 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:27:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:27:01 INFO - 'PWD': '/builds/slave/test', 04:27:01 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:27:01 INFO - 'RUST_BACKTRACE': 'full', 04:27:01 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 04:27:01 INFO - 'SHELL': '/bin/bash', 04:27:01 INFO - 'SHLVL': '1', 04:27:01 INFO - 'STYLO_FORCE_DISABLED': '1', 04:27:01 INFO - 'TERM': 'linux', 04:27:01 INFO - 'TMOUT': '86400', 04:27:01 INFO - 'USER': 'cltbld', 04:27:01 INFO - 'XDG_SESSION_COOKIE': '652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680', 04:27:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:27:01 INFO - '_': '/tools/buildbot/bin/python'} 04:27:01 INFO - TEST-INFO | started process 23146 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpt7eKTC/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 04:27:02 INFO - PID 23146 | 04:27:02 INFO - PID 23146 | (/builds/slave/test/build/application/firefox/firefox:23197): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 04:27:02 INFO - PID 23146 | 04:27:03 INFO - PID 23146 | [talos glvideo result] Mean tick time across 100 ticks: 6.9198 ms 04:27:03 INFO - PID 23146 | Cycle 1(1): loaded http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html) 04:27:05 INFO - PID 23146 | [talos glvideo result] Mean tick time across 100 ticks: 6.517 ms 04:27:05 INFO - PID 23146 | Cycle 1(2): loaded http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html) 04:27:06 INFO - PID 23146 | [talos glvideo result] Mean tick time across 100 ticks: 6.56105 ms 04:27:06 INFO - PID 23146 | Cycle 1(3): loaded http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html) 04:27:07 INFO - PID 23146 | [talos glvideo result] Mean tick time across 100 ticks: 6.530399999999999 ms 04:27:07 INFO - PID 23146 | Cycle 1(4): loaded http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html) 04:27:09 INFO - PID 23146 | [talos glvideo result] Mean tick time across 100 ticks: 6.598400000000001 ms 04:27:09 INFO - PID 23146 | Cycle 1(5): loaded http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:32965/tests/webgl/benchmarks/video/video_upload.html) 04:27:09 INFO - PID 23146 | __start_tp_report 04:27:09 INFO - PID 23146 | _x_x_mozilla_page_load 04:27:09 INFO - PID 23146 | _x_x_mozilla_page_load_details 04:27:09 INFO - PID 23146 | |i|pagename|runs| 04:27:09 INFO - PID 23146 | |0;Mean tick time across 100 ticks: ;6.9198;6.517;6.56105;6.530399999999999;6.598400000000001 04:27:09 INFO - PID 23146 | __end_tp_report 04:27:09 INFO - PID 23146 | __start_cc_report 04:27:09 INFO - PID 23146 | _x_x_mozilla_cycle_collect,285 04:27:09 INFO - PID 23146 | __end_cc_report 04:27:09 INFO - PID 23146 | __startTimestamp1510144029270__endTimestamp 04:27:09 INFO - PID 23146 | 04:27:09 INFO - PID 23146 | ------- Summary: start ------- 04:27:09 INFO - PID 23146 | Number of tests: 1 04:27:09 INFO - PID 23146 | 04:27:09 INFO - PID 23146 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.63 Median:6.56 stddev:0.17 (2.6%) stddev-sans-first:0.04 04:27:09 INFO - PID 23146 | Values: 6.9 6.5 6.6 6.5 6.6 04:27:09 INFO - PID 23146 | -------- Summary: end -------- 04:27:09 INFO - PID 23146 | 04:27:09 INFO - PID 23146 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 04:27:09 INFO - TEST-INFO | 23146: exit 0 04:27:09 INFO - TEST-OK | glvideo | took 13786ms 04:27:09 INFO - SUITE-END | took 574s 04:27:10 INFO - Completed test suite (00:09:35) 04:27:10 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.5916279697228335, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6810700280112045, 1.684023569023569, 1.6821889013452915, 1.6817180493273542, 1.680125979843225, 1.680243561030235, 1.6788248461108004, 1.6820655829596414, 1.68222533632287, 1.6950197740112993, 1.6779178311906093, 1.6793816452154449], "value": 1.6817180493273542, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6698121869782971, 1.6700417362270452, 1.6716708437761072, 1.6682860717264387, 1.6684070058381981, 1.6668708333333333, 1.6681651376146787, 1.6699373956594323, 1.6685988323603007, 1.6682318598832357, 1.6673875000000005, 1.6691951626355297], "value": 1.6684070058381981, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7304065743944634, 1.7335413056036975, 1.7292708933717578, 1.7361979166666666, 1.737298784018529, 1.7188201603665518, 1.7275302245250428, 1.7536031560490941, 1.7710064935064935, 1.72949855907781, 1.7597624633431082, 1.7445145348837208], "value": 1.7361979166666666, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7037052810902902, 1.6956949152542373, 1.713916023993145, 1.70997435897436, 1.7039054514480403, 1.6979286926994905, 1.6909509721048186, 1.7057161125319704, 1.729498703543648, 1.6935055038103293, 1.7671510600706721, 1.735503035559411], "value": 1.7057161125319704, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.049662618083672, 4.110554794520548, 4.179505571030641, 4.001286666666667, 4.059763193504735, 4.138455172413792, 4.049089068825911, 4.139248275862069, 4.017342704149933, 4.104651162790698, 4.133450413223141, 3.9954660452729684], "value": 4.104651162790698, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.1336570247933855, 3.961009900990098, 4.158721413721416, 4.09891393442623, 4.1495539419087155, 4.167333333333333, 4.0327016129032245, 4.168989583333333, 4.150020746887966, 4.108993839835729, 4.133688016528925, 3.9846215139442243], "value": 4.133688016528925, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.62021712907117, 3.489255813953491, 3.686554054054051, 3.4484022988505756, 3.481525522041764, 3.4486264367816095, 3.5301411764705892, 3.6376000000000004, 3.6636141636141635, 3.5175849941383355, 3.546258865248227, 3.453181818181817], "value": 3.5175849941383355, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.572660714285712, 3.414470989761088, 3.6105505415162504, 3.351524288107204, 3.3902457627118627, 3.362268907563024, 3.442710843373494, 3.540477876106193, 3.552877442273535, 3.455742659758204, 3.4973426573426565, 3.373827993254638], "value": 3.442710843373494, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.209852430555555, 5.640009398496241, 5.618511235955056, 5.673119092627596, 5.49575091575091, 5.682774621212123, 5.515496323529412, 5.640366541353389, 5.514761029411763, 5.682784090909095, 5.650376647834272, 5.725648854961835], "value": 5.640366541353389, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.634760563380282, 5.602661064425774, 5.452479564032701, 5.450272479564033, 5.652062146892661, 5.525994475138122, 5.391805929919139, 5.5873743016759745, 5.604201680672271, 5.543240997229908, 5.512369146005514, 5.619255617977522], "value": 5.543240997229908, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.527561403508782, 10.171305084745763, 10.1360472972973, 9.678387096774191, 10.642145390070919, 10.45304878048781, 10.067919463087254, 10.06999999999999, 10.000649999999998, 10.00278333333333, 10.346913793103447, 10.309656357388318], "value": 10.1360472972973, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.257923076923069, 10.417838541666677, 10.58232804232803, 10.206122448979599, 9.526761904761917, 9.662777777777777, 10.261820512820515, 9.665555555555558, 10.004050000000007, 10.105176767676772, 9.954303482587058, 9.663285024154604], "value": 10.004050000000007, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.949434306569332, 11.156245353159846, 11.112277777777773, 11.071826568265683, 11.03191176470587, 11.196044776119393, 11.036066176470593, 11.19695895522388, 11.03327205882354, 11.236910112359555, 11.11448148148148, 11.195391791044782], "value": 11.11448148148148, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.472748691099506, 10.642260638297886, 10.58240740740743, 10.584100529100512, 10.471753926701588, 10.75362903225808, 10.472198952879593, 10.529447368421058, 10.585079365079336, 10.81667567567567, 10.58481481481481, 10.754489247311824], "value": 10.58481481481481, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.296086065573782, 12.349032921810679, 12.297725409836083, 12.55504184100421, 12.450601659751012, 12.659894514767918, 12.767617021276592, 12.605945378151246, 12.554602510460263, 12.449896265560177, 12.449854771784237, 12.24814285714285], "value": 12.450601659751012, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.97709580838325, 11.906726190476201, 12.049939759036105, 11.76726470588234, 12.195640243902478, 12.125909090909099, 12.123393939393942, 11.698713450292416, 11.976377245508983, 12.201310975609752, 11.767499999999991, 11.909107142857161], "value": 11.976377245508983, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.322075471698108, 11.45194656488551, 11.583918918918922, 11.451526717557263, 11.279586466165396, 11.539288461538447, 11.719667968750002, 11.586814671814674, 11.411159695817497, 11.197052238805961, 12.001200000000011, 11.674805447470828], "value": 11.539288461538447, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.582089947089944, 10.992005494505484, 11.175949720670406, 11.050055248618772, 10.930546448087437, 10.86994565217391, 11.111361111111142, 11.114666666666663, 11.300112994350297, 10.754623655913981, 11.17726256983238, 11.29971751412431], "value": 11.111361111111142, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.9198, 6.517, 6.56105, 6.530399999999999, 6.598400000000001], "value": 6.545724999999999, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]} 04:27:10 INFO - Return code: 0 04:27:10 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 04:27:10 INFO - # TBPL SUCCESS # 04:27:10 INFO - Running post-action listener: _package_coverage_data 04:27:10 INFO - Running post-action listener: _resource_record_post_action 04:27:10 INFO - [mozharness: 2017-11-08 12:27:10.447950Z] Finished run-tests step (success) 04:27:10 INFO - Running post-run listener: _resource_record_post_run 04:27:10 INFO - Total resource usage - Wall time: 595s; CPU: 39.0%; Read bytes: 12288; Write bytes: 306700288; Read time: 284; Write time: 209016 04:27:10 INFO - TinderboxPrint: CPU usage
38.6% 04:27:10 INFO - TinderboxPrint: I/O read bytes / time
12,288 / 284 04:27:10 INFO - TinderboxPrint: I/O write bytes / time
306,700,288 / 209,016 04:27:10 INFO - TinderboxPrint: CPU idle
2,863.4 (61.4%) 04:27:10 INFO - TinderboxPrint: CPU system
303.9 (6.5%) 04:27:10 INFO - TinderboxPrint: CPU user
1,486.4 (31.9%) 04:27:10 INFO - TinderboxPrint: Swap in / out
0 / 0 04:27:10 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 5427200; Read time: 0; Write time: 5428 04:27:10 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 04:27:10 INFO - run-tests - Wall time: 576s; CPU: 39.0%; Read bytes: 12288; Write bytes: 301273088; Read time: 284; Write time: 203588 04:27:10 INFO - Running post-run listener: _upload_blobber_files 04:27:10 INFO - Blob upload gear active. 04:27:10 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 04:27:10 INFO - Files from /builds/slave/test/build/blobber_upload_dir are to be uploaded with branch at the following location(s): https://blobupload.elasticbeanstalk.com 04:27:10 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/test/oauth.txt', '-b', 'Firefox', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 04:27:10 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/test/oauth.txt -b Firefox -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 04:27:10 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:339: SNIMissingWarning: An HTTPS request has been made, but the SNI (Subject Name Indication) extension to TLS is not available on this platform. This may cause the server to present an incorrect TLS certificate, which can cause validation failures. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:27:10 INFO - SNIMissingWarning 04:27: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 04:27:10 INFO - InsecurePlatformWarning 04:27: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.) 04:27:11 INFO - SubjectAltNameWarning 04:27:11 INFO - (blobuploader) - INFO - Open directory for files ... 04:27:11 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log ... 04:27:11 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:27:11 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:27: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 04:27:11 INFO - InsecurePlatformWarning 04:27: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.) 04:27:11 INFO - SubjectAltNameWarning 04:27: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 04:27:11 INFO - InsecurePlatformWarning 04:27:12 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_raw.log: uploaded 04:27:12 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:27:12 INFO - (blobuploader) - INFO - Done attempting. 04:27:12 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 04:27:12 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:27:12 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:27: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 04:27:12 INFO - InsecurePlatformWarning 04:27: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.) 04:27:12 INFO - SubjectAltNameWarning 04:27: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 04:27:12 INFO - InsecurePlatformWarning 04:27:12 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 04:27:12 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:27:12 INFO - (blobuploader) - INFO - Done attempting. 04:27:12 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log ... 04:27:12 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:27:12 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:27: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 04:27:12 INFO - InsecurePlatformWarning 04:27:13 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 04:27:13 INFO - SubjectAltNameWarning 04:27: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 04:27:13 INFO - InsecurePlatformWarning 04:27:13 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_errorsummary.log: uploaded 04:27:13 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:27:13 INFO - (blobuploader) - INFO - Done attempting. 04:27:13 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 04:27:13 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 04:27:13 INFO - (blobuploader) - INFO - Uploading, attempt #1. 04:27: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 04:27:13 INFO - InsecurePlatformWarning 04:27:14 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 04:27:14 INFO - SubjectAltNameWarning 04:27:18 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 04:27:18 INFO - InsecurePlatformWarning 04:27:18 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 04:27:18 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 04:27:18 INFO - (blobuploader) - INFO - Done attempting. 04:27:18 INFO - (blobuploader) - INFO - Iteration through files over. 04:27:18 INFO - Return code: 0 04:27:18 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 04:27:18 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 04:27:18 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/60ec3d36d9c53862dcf93b39c17938d8d5e492c6a6840c16388df75dc53546fb2dae905815c1767c426a2d7f28420f0cfa0399ad06370c074786c3aefdcaa9dc", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d6fc913d6be8227d5a8d8cf652f64db64f0c0d30e6c204f0c3de7acdb6f48f79e0b2e499062887f447b1316c991a6e15e0864e70151ea363cfa87256bde5aa97", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8673db4f626fed4fa7093523fd6827fcc8e135fcd477c794ad811b5e610e0bf46b28a022fea2e3c44af43db05f2a4e9af28bb18fb41f325cdea2f92c424e5e1e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1b14620121a93d51115cc57e7b44bb39a280416b0f0b5b89be7820dcd3ec6fe800368362f13fe4d1f7d26d502a20c0fd502233eae2b8e9133611de6a4b7be8c4"} 04:27:18 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 04:27:18 INFO - Writing to file /builds/slave/test/properties/blobber_files 04:27:18 INFO - Contents: 04:27:18 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/60ec3d36d9c53862dcf93b39c17938d8d5e492c6a6840c16388df75dc53546fb2dae905815c1767c426a2d7f28420f0cfa0399ad06370c074786c3aefdcaa9dc", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d6fc913d6be8227d5a8d8cf652f64db64f0c0d30e6c204f0c3de7acdb6f48f79e0b2e499062887f447b1316c991a6e15e0864e70151ea363cfa87256bde5aa97", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8673db4f626fed4fa7093523fd6827fcc8e135fcd477c794ad811b5e610e0bf46b28a022fea2e3c44af43db05f2a4e9af28bb18fb41f325cdea2f92c424e5e1e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1b14620121a93d51115cc57e7b44bb39a280416b0f0b5b89be7820dcd3ec6fe800368362f13fe4d1f7d26d502a20c0fd502233eae2b8e9133611de6a4b7be8c4"} 04:27:18 INFO - Running post-run listener: copy_logs_to_upload_dir 04:27:18 INFO - Copying logs to upload dir... 04:27:18 INFO - mkdir: /builds/slave/test/build/upload/logs 04:27:18 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=719.618146 ========= master_lag: 0.04 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 59 secs) (at 2017-11-08 04:27:18.557943) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-08 04:27:18.561678) ========= 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=652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/60ec3d36d9c53862dcf93b39c17938d8d5e492c6a6840c16388df75dc53546fb2dae905815c1767c426a2d7f28420f0cfa0399ad06370c074786c3aefdcaa9dc", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d6fc913d6be8227d5a8d8cf652f64db64f0c0d30e6c204f0c3de7acdb6f48f79e0b2e499062887f447b1316c991a6e15e0864e70151ea363cfa87256bde5aa97", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8673db4f626fed4fa7093523fd6827fcc8e135fcd477c794ad811b5e610e0bf46b28a022fea2e3c44af43db05f2a4e9af28bb18fb41f325cdea2f92c424e5e1e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1b14620121a93d51115cc57e7b44bb39a280416b0f0b5b89be7820dcd3ec6fe800368362f13fe4d1f7d26d502a20c0fd502233eae2b8e9133611de6a4b7be8c4"} build_url:https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011341 build_url: 'https://queue.taskcluster.net/v1/task/JWakzwr3TEe5iMKuEKFsxw/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/60ec3d36d9c53862dcf93b39c17938d8d5e492c6a6840c16388df75dc53546fb2dae905815c1767c426a2d7f28420f0cfa0399ad06370c074786c3aefdcaa9dc", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/d6fc913d6be8227d5a8d8cf652f64db64f0c0d30e6c204f0c3de7acdb6f48f79e0b2e499062887f447b1316c991a6e15e0864e70151ea363cfa87256bde5aa97", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/8673db4f626fed4fa7093523fd6827fcc8e135fcd477c794ad811b5e610e0bf46b28a022fea2e3c44af43db05f2a4e9af28bb18fb41f325cdea2f92c424e5e1e", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/1b14620121a93d51115cc57e7b44bb39a280416b0f0b5b89be7820dcd3ec6fe800368362f13fe4d1f7d26d502a20c0fd502233eae2b8e9133611de6a4b7be8c4"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-08 04:27:18.593738) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-08 04:27:18.594342) ========= 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=652eb03db935cfc1c15ebda0000001ad-1510142637.286925-456926680 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004509 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-08 04:27:18.679003) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-08 04:27:18.679377) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-08 04:27:18.679675) ========= ========= Total master_lag: 0.28 =========