builder: mozilla-central_ubuntu64_hw_qr_test-g4-e10s slave: talos-linux64-ix-052 starttime: 1506003194.39 results: success (0) revision: f7e9777221a34f9f23c2e4933307eb38b621b679 ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.395434) ========= master: http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.396149) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.396634) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.417480) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.417847) ========= 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=826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-09-21 07:13:15-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.102, 63.245.215.25 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.102|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 438K=0.03s 2017-09-21 07:13:15 (438 KB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.141341 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.575509) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.578863) ========= 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=826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.020003 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:14.628365) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 29 secs) (at 2017-09-21 07:13:14.631730) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev f7e9777221a34f9f23c2e4933307eb38b621b679 --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 f7e9777221a34f9f23c2e4933307eb38b621b679 --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=826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-09-21 07:13:15,361 truncating revision to first 12 chars 2017-09-21 07:13:15,361 Setting DEBUG logging. 2017-09-21 07:13:15,361 attempt 1/10 2017-09-21 07:13:15,361 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/f7e9777221a3?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-09-21 07:13:16,320 attempt 1/10 2017-09-21 07:13:16,850 current task status: no status available at this point. state: PENDING 2017-09-21 07:13:16,851 sleeping for 10.00s (attempt 1/10) 2017-09-21 07:13:26,861 attempt 2/10 2017-09-21 07:13:27,527 current task status: no status available at this point. state: PENDING 2017-09-21 07:13:27,527 sleeping for 16.00s (attempt 2/10) 2017-09-21 07:13:43,543 attempt 3/10 2017-09-21 07:13:43,877 current task status: Task completed! Check 's3_urls' for upload locations. state: SUCCESS 2017-09-21 07:13:44,060 unpacking tar archive at: mozilla-central-f7e9777221a3/testing/mozharness/ program finished with exit code 0 elapsedTime=29.019664 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 29 secs) (at 2017-09-21 07:13:43.668386) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:43.671706) ========= script_repo_revision: f7e9777221a34f9f23c2e4933307eb38b621b679 ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:43.672089) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:43.672347) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-09-21 07:13:43.686252) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 1 secs) (at 2017-09-21 07:13:43.686701) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 07:13:44 INFO - MultiFileLogger online at 20170921 07:13:44 in /builds/slave/test 07:13:44 INFO - Run as scripts/scripts/talos_script.py --suite g4-e10s --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 07:13:44 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 07:13:44 INFO - {'append_to_log': False, 07:13:44 INFO - 'base_work_dir': '/builds/slave/test', 07:13:44 INFO - 'blob_upload_branch': 'Firefox', 07:13:44 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 07:13:44 INFO - 'branch': 'Firefox', 07:13:44 INFO - 'buildbot_json_path': 'buildprops.json', 07:13:44 INFO - 'code_coverage': False, 07:13:44 INFO - 'config_files': ('talos/linux_config.py',), 07:13:44 INFO - 'default_actions': ('clobber', 07:13:44 INFO - 'read-buildbot-config', 07:13:44 INFO - 'download-and-extract', 07:13:44 INFO - 'populate-webroot', 07:13:44 INFO - 'create-virtualenv', 07:13:44 INFO - 'install', 07:13:44 INFO - 'setup-mitmproxy', 07:13:44 INFO - 'run-tests'), 07:13:44 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 07:13:44 INFO - 'disable_ccov_upload': False, 07:13:44 INFO - 'disable_stylo': False, 07:13:44 INFO - 'download_minidump_stackwalk': True, 07:13:44 INFO - 'download_symbols': 'ondemand', 07:13:44 INFO - 'enable_stylo': False, 07:13:44 INFO - 'enable_webrender': False, 07:13:44 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 07:13:44 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 07:13:44 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 07:13:44 INFO - 'gecko_profile': False, 07:13:44 INFO - 'gecko_profile_interval': 0, 07:13:44 INFO - 'installer_path': 'installer.exe', 07:13:44 INFO - 'log_level': 'info', 07:13:44 INFO - 'log_name': 'talos', 07:13:44 INFO - 'log_to_console': True, 07:13:44 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 07:13:44 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 07:13:44 INFO - 'opt_config_files': (), 07:13:44 INFO - 'pip_index': False, 07:13:44 INFO - 'suite': 'g4-e10s', 07:13:44 INFO - 'system_bits': '32', 07:13:44 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 07:13:44 INFO - 'title': 'talos-linux64-ix-052', 07:13:44 INFO - 'tooltool_cache': '/builds/tooltool_cache', 07:13:44 INFO - 'use_talos_json': True, 07:13:44 INFO - 'verify': 'False', 07:13:44 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 07:13:44 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 07:13:44 INFO - 'work_dir': 'build'} 07:13:44 INFO - [mozharness: 2017-09-21 14:13:44.551846Z] Running clobber step. 07:13:44 INFO - Running pre-action listener: _resource_record_pre_action 07:13:44 INFO - Running main action method: clobber 07:13:44 INFO - rmtree: /builds/slave/test/build 07:13:44 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 07:13:46 INFO - Running post-action listener: _resource_record_post_action 07:13:46 INFO - [mozharness: 2017-09-21 14:13:46.079341Z] Finished clobber step (success) 07:13:46 INFO - [mozharness: 2017-09-21 14:13:46.079439Z] Running read-buildbot-config step. 07:13:46 INFO - Running pre-action listener: _resource_record_pre_action 07:13:46 INFO - Running main action method: read_buildbot_config 07:13:46 INFO - Using buildbot properties: 07:13:46 INFO - { 07:13:46 INFO - "project": "", 07:13:46 INFO - "product": "firefox", 07:13:46 INFO - "who": "archaeopteryx@coole-files.de", 07:13:46 INFO - "installer_path": "public/build/target.tar.bz2", 07:13:46 INFO - "builddir": "mozilla-central_ubuntu64_hw_qr_test-g4-e10s", 07:13:46 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 07:13:46 INFO - "buildername": "Ubuntu HW 12.04 x64 qr mozilla-central talos g4-e10s", 07:13:46 INFO - "stage_platform": "linux64-qr", 07:13:46 INFO - "basedir": "/builds/slave/test", 07:13:46 INFO - "buildnumber": 80, 07:13:46 INFO - "platform": "ubuntu64_hw_qr", 07:13:46 INFO - "master": "http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/", 07:13:46 INFO - "slavebuilddir": "test", 07:13:46 INFO - "taskId": "WGbiO_YqTDeOP5PW-0i1sQ", 07:13:46 INFO - "branch": "mozilla-central", 07:13:46 INFO - "script_repo_revision": "production", 07:13:46 INFO - "revision": "f7e9777221a34f9f23c2e4933307eb38b621b679", 07:13:46 INFO - "slavename": "talos-linux64-ix-052", 07:13:46 INFO - "repo_path": "mozilla-central" 07:13:46 INFO - } 07:13:46 INFO - Finding installer, test and symbols from parent task. 07:13:46 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/WGbiO_YqTDeOP5PW-0i1sQ'}, attempt #1 07:13:46 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/WGbiO_YqTDeOP5PW-0i1sQ'}, attempt #1 07:13:47 INFO - Task dependencies: OYLYgPYVTVKEo2gH9bptQA 07:13:47 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA'}, attempt #1 07:13:47 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2 07:13:47 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.test_packages.json 07:13:47 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.crashreporter-symbols.zip 07:13:47 INFO - Running post-action listener: _resource_record_post_action 07:13:47 INFO - [mozharness: 2017-09-21 14:13:47.496632Z] Finished read-buildbot-config step (success) 07:13:47 INFO - [mozharness: 2017-09-21 14:13:47.496852Z] Running download-and-extract step. 07:13:47 INFO - Running pre-action listener: _resource_record_pre_action 07:13:47 INFO - Running main action method: download_and_extract 07:13:47 INFO - mkdir: /builds/slave/test/build/tests 07:13:47 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:13:47 INFO - trying https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.test_packages.json 07:13:47 INFO - Downloading https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 07:13:47 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 07:13:48 INFO - Downloaded 989 bytes. 07:13:48 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 07:13:48 INFO - Using the following test package requirements: 07:13:48 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 07:13:48 INFO - u'common': [u'target.common.tests.zip'], 07:13:48 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 07:13:48 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 07:13:48 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 07:13:48 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 07:13:48 INFO - u'mozbase': [u'target.common.tests.zip'], 07:13:48 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 07:13:48 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 07:13:48 INFO - u'web-platform': [u'target.common.tests.zip', 07:13:48 INFO - u'target.web-platform.tests.tar.gz'], 07:13:48 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 07:13:48 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 07:13:48 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.common.tests.zip 07:13:48 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.common.tests.zip'}, attempt #1 07:13:48 INFO - Fetch https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.common.tests.zip into memory 07:13:49 INFO - Content-Length response header: 54741111 07:13:49 INFO - Bytes received: 54741111 07:13:59 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.talos.tests.zip 07:13:59 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.talos.tests.zip'}, attempt #1 07:13:59 INFO - Fetch https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.talos.tests.zip into memory 07:14:00 INFO - Content-Length response header: 14509184 07:14:00 INFO - Bytes received: 14509184 07:14: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')]} 07:14:00 INFO - trying https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2 07:14:00 INFO - Downloading https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 07:14:00 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 07:14:02 INFO - Downloaded 61718892 bytes. 07:14:02 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2 07:14:02 INFO - mkdir: /builds/slave/test/properties 07:14:02 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 07:14:02 INFO - Writing to file /builds/slave/test/properties/build_url 07:14:02 INFO - Contents: 07:14:02 INFO - build_url:https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2 07:14:02 INFO - Running post-action listener: _resource_record_post_action 07:14:02 INFO - Running post-action listener: find_tests_for_verification 07:14:02 INFO - Running post-action listener: set_extra_try_arguments 07:14:02 INFO - [mozharness: 2017-09-21 14:14:02.525422Z] Finished download-and-extract step (success) 07:14:02 INFO - [mozharness: 2017-09-21 14:14:02.525658Z] Running populate-webroot step. 07:14:02 INFO - Running pre-action listener: _resource_record_pre_action 07:14:02 INFO - Running main action method: populate_webroot 07:14:02 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 07:14:02 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['tresize', 07:14:02 INFO - 'tcanvasmark']}, 07:14:02 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 07:14:02 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['dromaeo_css', 07:14:02 INFO - 'kraken']}, 07:14:02 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 07:14:02 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 07:14:02 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'tests': ['damp', 'tps']}, 07:14:02 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['damp', 'tps']}, 07:14:02 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 07:14:02 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['dromaeo_dom']}, 07:14:02 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 07:14:02 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['basic_compositor_video', 07:14:02 INFO - 'glvideo']}, 07:14:02 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 07:14:02 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['ts_paint_webext', 07:14:02 INFO - 'tp5o_webext']}, 07:14:02 INFO - 'other-e10s': {'tests': ['a11yr', 07:14:02 INFO - 'ts_paint', 07:14:02 INFO - 'tpaint', 07:14:02 INFO - 'sessionrestore', 07:14:02 INFO - 'sessionrestore_many_windows', 07:14:02 INFO - 'sessionrestore_no_auto_restore', 07:14:02 INFO - 'tabpaint']}, 07:14:02 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['a11yr', 07:14:02 INFO - 'ts_paint', 07:14:02 INFO - 'tpaint', 07:14:02 INFO - 'sessionrestore', 07:14:02 INFO - 'sessionrestore_many_windows', 07:14:02 INFO - 'sessionrestore_no_auto_restore', 07:14:02 INFO - 'tabpaint']}, 07:14:02 INFO - 'perf-reftest-e10s': {'tests': ['bloom_basic']}, 07:14:02 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 07:14:02 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['perf_reftest_singletons']}, 07:14:02 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['bloom_basic']}, 07:14:02 INFO - 'svgr-e10s': {'tests': ['tsvgx', 07:14:02 INFO - 'tsvgr_opacity', 07:14:02 INFO - 'tart', 07:14:02 INFO - 'tscrollx', 07:14:02 INFO - 'tsvg_static']}, 07:14:02 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['tsvgx', 07:14:02 INFO - 'tsvgr_opacity', 07:14:02 INFO - 'tart', 07:14:02 INFO - 'tscrollx', 07:14:02 INFO - 'tsvg_static']}, 07:14:02 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 07:14:02 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'talos_options': ['--disable-stylo'], 07:14:02 INFO - 'tests': ['tp5o']}, 07:14:02 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 07:14:02 INFO - 'talos_options': ['--mitmproxy', 07:14:02 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 07:14:02 INFO - '--firstNonBlankPaint'], 07:14:02 INFO - 'tests': ['tp6_google', 07:14:02 INFO - 'tp6_youtube', 07:14:02 INFO - 'tp6_amazon', 07:14:02 INFO - 'tp6_facebook']}, 07:14:02 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 07:14:02 INFO - 'talos_options': ['--disable-stylo', 07:14:02 INFO - '--mitmproxy', 07:14:02 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 07:14:02 INFO - '--firstNonBlankPaint'], 07:14:02 INFO - 'tests': ['tp6_google', 07:14:02 INFO - 'tp6_youtube', 07:14:02 INFO - 'tp6_amazon', 07:14:02 INFO - 'tp6_facebook']}, 07:14:02 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 07:14:02 INFO - 'talos_options': ['--stylo-threads=1', 07:14:02 INFO - '--mitmproxy', 07:14:02 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 07:14:02 INFO - '--firstNonBlankPaint'], 07:14:02 INFO - 'tests': ['tp6_google', 07:14:02 INFO - 'tp6_youtube', 07:14:02 INFO - 'tp6_amazon', 07:14:02 INFO - 'tp6_facebook']}, 07:14:02 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'talos_options': ['--xperf_path', 07:14:02 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 07:14:02 INFO - 'tests': ['tp5n']}, 07:14:02 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 07:14:02 INFO - 'talos_options': ['--disable-stylo', 07:14:02 INFO - '--xperf_path', 07:14:02 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 07:14:02 INFO - 'tests': ['tp5n']}}} 07:14:02 INFO - Running post-action listener: _resource_record_post_action 07:14:02 INFO - [mozharness: 2017-09-21 14:14:02.548234Z] Finished populate-webroot step (success) 07:14:02 INFO - [mozharness: 2017-09-21 14:14:02.548325Z] Running create-virtualenv step. 07:14:02 INFO - Running pre-action listener: _resource_record_pre_action 07:14:02 INFO - Running main action method: create_virtualenv 07:14:02 INFO - Creating virtualenv /builds/slave/test/build/venv 07:14:02 INFO - Running command: ['virtualenv', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 07:14:02 INFO - Copy/paste: virtualenv --no-site-packages --distribute /builds/slave/test/build/venv 07:14:02 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 07:14:02 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 07:14:02 INFO - New python executable in /builds/slave/test/build/venv/bin/python 07:14:03 INFO - Installing distribute.............................................................................................................................................................................................done. 07:14:03 INFO - Installing pip...............done. 07:14:03 INFO - Return code: 0 07:14:03 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 07:14:03 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 07:14:03 INFO - Reading from file tmpfile_stdout 07:14:03 INFO - Output received: 07:14:03 INFO - pip 1.1 from /builds/slave/test/build/venv/lib/python2.7/site-packages/pip-1.1-py2.7.egg (python 2.7) 07:14:03 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 07:14:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:03 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:03 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:03 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:03 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build 07:14:03 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5 07:14:03 INFO - Using env: {'DISPLAY': ':0', 07:14:03 INFO - 'HOME': '/home/cltbld', 07:14:03 INFO - 'LANG': 'en_US.UTF-8', 07:14:03 INFO - 'LANGUAGE': 'en_US:en', 07:14:03 INFO - 'LOGNAME': 'cltbld', 07:14:03 INFO - 'MAIL': '/var/mail/cltbld', 07:14:03 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:03 INFO - 'MOZ_NO_REMOTE': '1', 07:14:03 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:03 INFO - 'NO_EM_RESTART': '1', 07:14:03 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:03 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:03 INFO - 'PWD': '/builds/slave/test', 07:14:03 INFO - 'SHELL': '/bin/bash', 07:14:03 INFO - 'SHLVL': '1', 07:14:03 INFO - 'TERM': 'linux', 07:14:03 INFO - 'TMOUT': '86400', 07:14:03 INFO - 'USER': 'cltbld', 07:14:03 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:03 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:03 INFO - '_': '/tools/buildbot/bin/python'} 07:14:04 INFO - Ignoring indexes: http://pypi.python.org/simple/ 07:14:04 INFO - Downloading/unpacking pip>=1.5 07:14:04 INFO - Running setup.py egg_info for package pip 07:14:04 INFO - warning: no files found matching 'pip/cacert.pem' 07:14:04 INFO - warning: no files found matching '*.html' under directory 'docs' 07:14:04 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 07:14:04 INFO - no previously-included directories found matching 'docs/_build/_sources' 07:14:04 INFO - Installing collected packages: pip 07:14:04 INFO - Found existing installation: pip 1.1 07:14:04 INFO - Uninstalling pip: 07:14:04 INFO - Successfully uninstalled pip 07:14:04 INFO - Running setup.py install for pip 07:14:04 INFO - warning: no files found matching 'pip/cacert.pem' 07:14:04 INFO - warning: no files found matching '*.html' under directory 'docs' 07:14:04 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 07:14:04 INFO - no previously-included directories found matching 'docs/_build/_sources' 07:14:04 INFO - Installing pip script to /builds/slave/test/build/venv/bin 07:14:04 INFO - Installing pip2.7 script to /builds/slave/test/build/venv/bin 07:14:04 INFO - Installing pip2 script to /builds/slave/test/build/venv/bin 07:14:04 INFO - Successfully installed pip 07:14:04 INFO - Cleaning up... 07:14:04 INFO - Return code: 0 07:14:04 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 07:14:04 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')]} 07:14:04 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:04 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')]} 07:14:04 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:04 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:04 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1'] in /builds/slave/test/build 07:14:04 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=3.1.1 07:14:04 INFO - Using env: {'DISPLAY': ':0', 07:14:04 INFO - 'HOME': '/home/cltbld', 07:14:04 INFO - 'LANG': 'en_US.UTF-8', 07:14:04 INFO - 'LANGUAGE': 'en_US:en', 07:14:04 INFO - 'LOGNAME': 'cltbld', 07:14:04 INFO - 'MAIL': '/var/mail/cltbld', 07:14:04 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:04 INFO - 'MOZ_NO_REMOTE': '1', 07:14:04 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:04 INFO - 'NO_EM_RESTART': '1', 07:14:04 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:04 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:04 INFO - 'PWD': '/builds/slave/test', 07:14:04 INFO - 'SHELL': '/bin/bash', 07:14:04 INFO - 'SHLVL': '1', 07:14:04 INFO - 'TERM': 'linux', 07:14:04 INFO - 'TMOUT': '86400', 07:14:04 INFO - 'USER': 'cltbld', 07:14:04 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:04 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:04 INFO - '_': '/tools/buildbot/bin/python'} 07:14:05 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:05 INFO - Downloading/unpacking psutil>=3.1.1 07:14:05 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:05 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:05 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:05 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:06 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 07:14:06 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 07:14:06 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 07:14:06 INFO - Installing collected packages: psutil 07:14:06 INFO - Running setup.py install for psutil 07:14:06 INFO - building 'psutil._psutil_linux' extension 07:14:06 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o 07:14:06 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so 07:14:06 INFO - building 'psutil._psutil_posix' extension 07:14:06 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o 07:14:06 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so 07:14:06 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 07:14:06 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 07:14:06 INFO - Successfully installed psutil 07:14:06 INFO - Cleaning up... 07:14:06 INFO - Return code: 0 07:14:06 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 07:14:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:06 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:06 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:06 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:06 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:06 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 07:14:06 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.3 07:14:06 INFO - Using env: {'DISPLAY': ':0', 07:14:06 INFO - 'HOME': '/home/cltbld', 07:14:06 INFO - 'LANG': 'en_US.UTF-8', 07:14:06 INFO - 'LANGUAGE': 'en_US:en', 07:14:06 INFO - 'LOGNAME': 'cltbld', 07:14:06 INFO - 'MAIL': '/var/mail/cltbld', 07:14:06 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:06 INFO - 'MOZ_NO_REMOTE': '1', 07:14:06 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:06 INFO - 'NO_EM_RESTART': '1', 07:14:06 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:06 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:06 INFO - 'PWD': '/builds/slave/test', 07:14:06 INFO - 'SHELL': '/bin/bash', 07:14:06 INFO - 'SHLVL': '1', 07:14:06 INFO - 'TERM': 'linux', 07:14:06 INFO - 'TMOUT': '86400', 07:14:06 INFO - 'USER': 'cltbld', 07:14:06 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:06 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:06 INFO - '_': '/tools/buildbot/bin/python'} 07:14:07 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:07 INFO - Downloading/unpacking mozsystemmonitor==0.3 07:14:07 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:07 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:07 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:07 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:08 INFO - Downloading mozsystemmonitor-0.3.tar.gz 07:14:08 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 07:14:08 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 07:14:08 INFO - Installing collected packages: mozsystemmonitor 07:14:08 INFO - Running setup.py install for mozsystemmonitor 07:14:08 INFO - Successfully installed mozsystemmonitor 07:14:08 INFO - Cleaning up... 07:14:10 INFO - Return code: 0 07:14:10 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 07:14:10 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')]} 07:14:10 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:10 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')]} 07:14:10 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:10 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:10 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1'] in /builds/slave/test/build 07:14:10 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema==2.5.1 07:14:10 INFO - Using env: {'DISPLAY': ':0', 07:14:10 INFO - 'HOME': '/home/cltbld', 07:14:10 INFO - 'LANG': 'en_US.UTF-8', 07:14:10 INFO - 'LANGUAGE': 'en_US:en', 07:14:10 INFO - 'LOGNAME': 'cltbld', 07:14:10 INFO - 'MAIL': '/var/mail/cltbld', 07:14:10 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:10 INFO - 'MOZ_NO_REMOTE': '1', 07:14:10 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:10 INFO - 'NO_EM_RESTART': '1', 07:14:10 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:10 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:10 INFO - 'PWD': '/builds/slave/test', 07:14:10 INFO - 'SHELL': '/bin/bash', 07:14:10 INFO - 'SHLVL': '1', 07:14:10 INFO - 'TERM': 'linux', 07:14:10 INFO - 'TMOUT': '86400', 07:14:10 INFO - 'USER': 'cltbld', 07:14:10 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:10 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:10 INFO - '_': '/tools/buildbot/bin/python'} 07:14:10 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:11 INFO - Downloading/unpacking jsonschema==2.5.1 07:14:11 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:11 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:11 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:11 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:12 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 07:14:12 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 07:14:12 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:12 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:12 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:12 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:12 INFO - Downloading functools32-3.2.3-2.tar.gz 07:14:12 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 07:14:12 INFO - warning: no files found matching '*.txt' 07:14:12 INFO - no previously-included directories found matching 'build' 07:14:12 INFO - no previously-included directories found matching 'dist' 07:14:12 INFO - no previously-included directories found matching '.git*' 07:14:12 INFO - Installing collected packages: jsonschema, functools32 07:14:12 INFO - Running setup.py install for functools32 07:14:12 INFO - warning: no files found matching '*.txt' 07:14:12 INFO - no previously-included directories found matching 'build' 07:14:12 INFO - no previously-included directories found matching 'dist' 07:14:12 INFO - no previously-included directories found matching '.git*' 07:14:12 INFO - Successfully installed jsonschema functools32 07:14:12 INFO - Cleaning up... 07:14:12 INFO - Return code: 0 07:14:12 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 07:14:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:12 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'functools32==3.2.3-2']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:12 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'functools32==3.2.3-2'] in /builds/slave/test/build 07:14:12 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub functools32==3.2.3-2 07:14:12 INFO - Using env: {'DISPLAY': ':0', 07:14:12 INFO - 'HOME': '/home/cltbld', 07:14:12 INFO - 'LANG': 'en_US.UTF-8', 07:14:12 INFO - 'LANGUAGE': 'en_US:en', 07:14:12 INFO - 'LOGNAME': 'cltbld', 07:14:12 INFO - 'MAIL': '/var/mail/cltbld', 07:14:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:12 INFO - 'MOZ_NO_REMOTE': '1', 07:14:12 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:12 INFO - 'NO_EM_RESTART': '1', 07:14:12 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:12 INFO - 'PWD': '/builds/slave/test', 07:14:12 INFO - 'SHELL': '/bin/bash', 07:14:12 INFO - 'SHLVL': '1', 07:14:12 INFO - 'TERM': 'linux', 07:14:12 INFO - 'TMOUT': '86400', 07:14:12 INFO - 'USER': 'cltbld', 07:14:12 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:12 INFO - '_': '/tools/buildbot/bin/python'} 07:14:12 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:12 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 07:14:12 INFO - Cleaning up... 07:14:12 INFO - Return code: 0 07:14:12 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 07:14:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:12 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:12 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:12 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:12 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:12 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 07:14:12 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 07:14:12 INFO - Using env: {'DISPLAY': ':0', 07:14:12 INFO - 'HOME': '/home/cltbld', 07:14:12 INFO - 'LANG': 'en_US.UTF-8', 07:14:12 INFO - 'LANGUAGE': 'en_US:en', 07:14:12 INFO - 'LOGNAME': 'cltbld', 07:14:12 INFO - 'MAIL': '/var/mail/cltbld', 07:14:12 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:12 INFO - 'MOZ_NO_REMOTE': '1', 07:14:12 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:12 INFO - 'NO_EM_RESTART': '1', 07:14:12 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:12 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:12 INFO - 'PWD': '/builds/slave/test', 07:14:12 INFO - 'SHELL': '/bin/bash', 07:14:12 INFO - 'SHLVL': '1', 07:14:12 INFO - 'TERM': 'linux', 07:14:12 INFO - 'TMOUT': '86400', 07:14:12 INFO - 'USER': 'cltbld', 07:14:12 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:12 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:12 INFO - '_': '/tools/buildbot/bin/python'} 07:14:13 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:13 INFO - Downloading/unpacking blobuploader==1.2.4 07:14:13 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:13 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:13 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:13 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:14 INFO - Downloading blobuploader-1.2.4.tar.gz 07:14:14 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 07:14:14 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 07:14:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:14 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 07:14:14 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 07:14:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:14 INFO - Downloading docopt-0.6.1.tar.gz 07:14:14 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 07:14:14 INFO - Installing collected packages: blobuploader, requests, docopt 07:14:14 INFO - Running setup.py install for blobuploader 07:14:14 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 07:14:14 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 07:14:14 INFO - Running setup.py install for requests 07:14:15 INFO - Running setup.py install for docopt 07:14:15 INFO - Successfully installed blobuploader requests docopt 07:14:15 INFO - Cleaning up... 07:14:15 INFO - Return code: 0 07:14:15 INFO - Installing None into virtualenv /builds/slave/test/build/venv 07:14: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')]} 07:14:15 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14: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')]} 07:14:15 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:15 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:15 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 07:14:15 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 07:14:15 INFO - Using env: {'DISPLAY': ':0', 07:14:15 INFO - 'HOME': '/home/cltbld', 07:14:15 INFO - 'LANG': 'en_US.UTF-8', 07:14:15 INFO - 'LANGUAGE': 'en_US:en', 07:14:15 INFO - 'LOGNAME': 'cltbld', 07:14:15 INFO - 'MAIL': '/var/mail/cltbld', 07:14:15 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:15 INFO - 'MOZ_NO_REMOTE': '1', 07:14:15 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:15 INFO - 'NO_EM_RESTART': '1', 07:14:15 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:15 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:15 INFO - 'PWD': '/builds/slave/test', 07:14:15 INFO - 'SHELL': '/bin/bash', 07:14:15 INFO - 'SHLVL': '1', 07:14:15 INFO - 'TERM': 'linux', 07:14:15 INFO - 'TMOUT': '86400', 07:14:15 INFO - 'USER': 'cltbld', 07:14:15 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:15 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:15 INFO - '_': '/tools/buildbot/bin/python'} 07:14:15 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:15 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 07:14:15 INFO - Running setup.py (path:/tmp/pip-MB0EXI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 07:14:15 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 07:14:15 INFO - Running setup.py (path:/tmp/pip-dIj1X1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 07:14:15 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 07:14:15 INFO - Running setup.py (path:/tmp/pip-zbzNTB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 07:14:15 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 07:14:15 INFO - Running setup.py (path:/tmp/pip-vGDnf5-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 07:14:15 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 07:14:15 INFO - Running setup.py (path:/tmp/pip-rYRPSc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 07:14:15 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 07:14:15 INFO - Running setup.py (path:/tmp/pip-1As0TC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 07:14:16 INFO - Running setup.py (path:/tmp/pip-6S84oj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 07:14:16 INFO - Running setup.py (path:/tmp/pip-kUea56-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 07:14:16 INFO - Running setup.py (path:/tmp/pip-bsadIF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 07:14:16 INFO - Running setup.py (path:/tmp/pip-jyGWbS-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 07:14:16 INFO - Running setup.py (path:/tmp/pip-nH_11A-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 07:14:16 INFO - Running setup.py (path:/tmp/pip-tFWlOK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 07:14:16 INFO - Running setup.py (path:/tmp/pip-Hoscpg-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 07:14:16 INFO - Running setup.py (path:/tmp/pip-GLS5Xf-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 07:14:16 INFO - Running setup.py (path:/tmp/pip-GHLB1h-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 07:14:16 INFO - Running setup.py (path:/tmp/pip-7MAw1Y-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 07:14:16 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 07:14:16 INFO - Running setup.py (path:/tmp/pip-vJvqvO-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 07:14:16 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 07:14:16 INFO - Running setup.py install for manifestparser 07:14:16 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 07:14:16 INFO - Running setup.py install for mozcrash 07:14:17 INFO - Running setup.py install for mozdebug 07:14:17 INFO - Running setup.py install for mozdevice 07:14:17 INFO - Installing dm script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Running setup.py install for mozfile 07:14:17 INFO - Running setup.py install for mozhttpd 07:14:17 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Running setup.py install for mozinfo 07:14:17 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Running setup.py install for mozInstall 07:14:17 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Running setup.py install for mozleak 07:14:17 INFO - Running setup.py install for mozlog 07:14:17 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Running setup.py install for moznetwork 07:14:17 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 07:14:17 INFO - Running setup.py install for mozprocess 07:14:18 INFO - Running setup.py install for mozprofile 07:14:18 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 07:14:18 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 07:14:18 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 07:14:18 INFO - Running setup.py install for mozrunner 07:14:18 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 07:14:18 INFO - Running setup.py install for mozscreenshot 07:14:18 INFO - Running setup.py install for moztest 07:14:18 INFO - Running setup.py install for mozversion 07:14:18 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 07:14:18 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 07:14:18 INFO - Cleaning up... 07:14:18 INFO - Return code: 0 07:14:18 INFO - Installing None into virtualenv /builds/slave/test/build/venv 07:14:18 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')]} 07:14:18 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:18 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')]} 07:14:18 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:18 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:18 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 07:14:18 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 07:14:18 INFO - Using env: {'DISPLAY': ':0', 07:14:18 INFO - 'HOME': '/home/cltbld', 07:14:18 INFO - 'LANG': 'en_US.UTF-8', 07:14:18 INFO - 'LANGUAGE': 'en_US:en', 07:14:18 INFO - 'LOGNAME': 'cltbld', 07:14:18 INFO - 'MAIL': '/var/mail/cltbld', 07:14:18 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:18 INFO - 'MOZ_NO_REMOTE': '1', 07:14:18 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:18 INFO - 'NO_EM_RESTART': '1', 07:14:18 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:18 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:18 INFO - 'PWD': '/builds/slave/test', 07:14:18 INFO - 'SHELL': '/bin/bash', 07:14:18 INFO - 'SHLVL': '1', 07:14:18 INFO - 'TERM': 'linux', 07:14:18 INFO - 'TMOUT': '86400', 07:14:18 INFO - 'USER': 'cltbld', 07:14:18 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:18 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:18 INFO - '_': '/tools/buildbot/bin/python'} 07:14:18 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:18 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 07:14:18 INFO - Running setup.py (path:/tmp/pip-HXeCNC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 07:14:18 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 07:14:18 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 07:14:18 INFO - Running setup.py (path:/tmp/pip-QMvlHP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 07:14:18 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)) 07:14:18 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 07:14:18 INFO - Running setup.py (path:/tmp/pip-7wtaL7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 07:14:19 INFO - Running setup.py (path:/tmp/pip-0k6lDE-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 07:14:19 INFO - Running setup.py (path:/tmp/pip-9chbiX-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 07:14:19 INFO - Running setup.py (path:/tmp/pip-yWIcZd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 07:14:19 INFO - Running setup.py (path:/tmp/pip-axAgOs-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 07:14:19 INFO - Running setup.py (path:/tmp/pip-hJ8EVY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 07:14:19 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.13 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 07:14:19 INFO - Running setup.py (path:/tmp/pip-uQ_jpO-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 07:14:19 INFO - Running setup.py (path:/tmp/pip-7Oy6DG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 07:14:19 INFO - Running setup.py (path:/tmp/pip-T8jD4D-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 07:14:19 INFO - Running setup.py (path:/tmp/pip-wfGi5D-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 07:14:19 INFO - Running setup.py (path:/tmp/pip-DMdDYb-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 07:14:19 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.28 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 07:14:19 INFO - Running setup.py (path:/tmp/pip-bIeoXs-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 07:14:19 INFO - Running setup.py (path:/tmp/pip-jdIWCK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 07:14:19 INFO - Running setup.py (path:/tmp/pip-l2via7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 07:14:19 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)) 07:14:19 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 07:14:19 INFO - Running setup.py (path:/tmp/pip-bVMHaK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 07:14:20 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)) 07:14:20 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)) 07:14:20 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)) 07:14:20 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)) 07:14:20 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)) 07:14:20 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)) 07:14:20 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.13->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 07:14:20 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 07:14:20 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:20 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:20 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:20 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:21 INFO - Downloading blessings-1.6.tar.gz 07:14:21 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 07:14:21 INFO - Installing collected packages: blessings 07:14:21 INFO - Running setup.py install for blessings 07:14:21 INFO - Successfully installed blessings 07:14:21 INFO - Cleaning up... 07:14:21 INFO - Return code: 0 07:14:21 INFO - Done creating virtualenv /builds/slave/test/build/venv. 07:14:21 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 07:14:21 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 07:14:21 INFO - Reading from file tmpfile_stdout 07:14:21 INFO - Current package versions: 07:14:21 INFO - argparse == 1.2.1 07:14:21 INFO - blessings == 1.6 07:14:21 INFO - blobuploader == 1.2.4 07:14:21 INFO - docopt == 0.6.1 07:14:21 INFO - functools32 == 3.2.3-2 07:14:21 INFO - jsonschema == 2.5.1 07:14:21 INFO - manifestparser == 1.1 07:14:21 INFO - mozInstall == 1.13 07:14:21 INFO - mozcrash == 1.0 07:14:21 INFO - mozdebug == 0.1 07:14:21 INFO - mozdevice == 0.51 07:14:21 INFO - mozfile == 1.2 07:14:21 INFO - mozhttpd == 0.7 07:14:21 INFO - mozinfo == 0.10 07:14:21 INFO - mozleak == 0.1 07:14:21 INFO - mozlog == 3.5 07:14:21 INFO - moznetwork == 0.27 07:14:21 INFO - mozprocess == 0.25 07:14:21 INFO - mozprofile == 0.28 07:14:21 INFO - mozrunner == 6.13 07:14:21 INFO - mozscreenshot == 0.1 07:14:21 INFO - mozsystemmonitor == 0.3 07:14:21 INFO - moztest == 0.8 07:14:21 INFO - mozversion == 1.4 07:14:21 INFO - psutil == 3.1.1 07:14:21 INFO - requests == 1.2.3 07:14:21 INFO - wsgiref == 0.1.2 07:14:21 INFO - Installing None into virtualenv /builds/slave/test/build/venv 07:14: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')]} 07:14:21 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14: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')]} 07:14:21 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:21 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:21 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos 07:14:21 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 07:14:21 INFO - Using env: {'DISPLAY': ':0', 07:14:21 INFO - 'HOME': '/home/cltbld', 07:14:21 INFO - 'LANG': 'en_US.UTF-8', 07:14:21 INFO - 'LANGUAGE': 'en_US:en', 07:14:21 INFO - 'LOGNAME': 'cltbld', 07:14:21 INFO - 'MAIL': '/var/mail/cltbld', 07:14:21 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:21 INFO - 'MOZ_NO_REMOTE': '1', 07:14:21 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:21 INFO - 'NO_EM_RESTART': '1', 07:14:21 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:21 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:21 INFO - 'PWD': '/builds/slave/test', 07:14:21 INFO - 'SHELL': '/bin/bash', 07:14:21 INFO - 'SHLVL': '1', 07:14:21 INFO - 'TERM': 'linux', 07:14:21 INFO - 'TMOUT': '86400', 07:14:21 INFO - 'USER': 'cltbld', 07:14:21 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:21 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:21 INFO - '_': '/tools/buildbot/bin/python'} 07:14:21 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:21 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)) 07:14:21 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)) 07:14:21 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)) 07:14:21 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)) 07:14:21 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)) 07:14:21 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)) 07:14:21 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)) 07:14:21 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)) 07:14:21 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)) 07:14:21 INFO - Downloading/unpacking simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 07:14:21 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:21 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:21 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 07:14:21 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 07:14:22 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/simplejson/setup.py) egg_info for package simplejson 07:14:23 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)) 07:14:23 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)) 07:14:23 INFO - Installing collected packages: simplejson 07:14:23 INFO - Running setup.py install for simplejson 07:14:23 INFO - building 'simplejson._speedups' extension 07:14:23 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c simplejson/_speedups.c -o build/temp.linux-x86_64-2.7/simplejson/_speedups.o 07:14:23 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/simplejson/_speedups.o -o build/lib.linux-x86_64-2.7/simplejson/_speedups.so 07:14:24 INFO - Successfully installed simplejson 07:14:24 INFO - Cleaning up... 07:14:24 INFO - Return code: 0 07:14:24 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 07:14:24 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')]} 07:14:24 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 07:14:24 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')]} 07:14:24 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 07:14:24 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1d9c1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1f65a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x2108a60>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, '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': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', '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 07:14:24 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema'] in /builds/slave/test/build 07:14:24 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema 07:14:24 INFO - Using env: {'DISPLAY': ':0', 07:14:24 INFO - 'HOME': '/home/cltbld', 07:14:24 INFO - 'LANG': 'en_US.UTF-8', 07:14:24 INFO - 'LANGUAGE': 'en_US:en', 07:14:24 INFO - 'LOGNAME': 'cltbld', 07:14:24 INFO - 'MAIL': '/var/mail/cltbld', 07:14:24 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:24 INFO - 'MOZ_NO_REMOTE': '1', 07:14:24 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:24 INFO - 'NO_EM_RESTART': '1', 07:14:24 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:24 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:24 INFO - 'PWD': '/builds/slave/test', 07:14:24 INFO - 'SHELL': '/bin/bash', 07:14:24 INFO - 'SHLVL': '1', 07:14:24 INFO - 'TERM': 'linux', 07:14:24 INFO - 'TMOUT': '86400', 07:14:24 INFO - 'USER': 'cltbld', 07:14:24 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:24 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:24 INFO - '_': '/tools/buildbot/bin/python'} 07:14:24 INFO - Ignoring indexes: https://pypi.python.org/simple/ 07:14:24 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 07:14:24 INFO - Cleaning up... 07:14:24 INFO - Return code: 0 07:14:24 INFO - Running post-action listener: _resource_record_post_action 07:14:24 INFO - Running post-action listener: _start_resource_monitoring 07:14:24 INFO - Starting resource monitoring. 07:14:24 INFO - [mozharness: 2017-09-21 14:14:24.307373Z] Finished create-virtualenv step (success) 07:14:24 INFO - [mozharness: 2017-09-21 14:14:24.307895Z] Running install step. 07:14:24 INFO - Running pre-action listener: _resource_record_pre_action 07:14:24 INFO - Running main action method: install 07:14:24 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 07:14:24 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 07:14:24 INFO - Reading from file tmpfile_stdout 07:14:24 INFO - Detecting whether we're running mozinstall >=1.0... 07:14:24 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 07:14:24 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 07:14:24 INFO - Reading from file tmpfile_stdout 07:14:24 INFO - Output received: 07:14:24 INFO - Usage: mozinstall [options] installer 07:14:24 INFO - Options: 07:14:24 INFO - -h, --help show this help message and exit 07:14:24 INFO - -d DEST, --destination=DEST 07:14:24 INFO - Directory to install application into. [default: 07:14:24 INFO - "/builds/slave/test"] 07:14:24 INFO - --app=APP Application being installed. [default: firefox] 07:14:24 INFO - mkdir: /builds/slave/test/build/application 07:14:24 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'] 07:14:24 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 07:14:42 INFO - Reading from file tmpfile_stdout 07:14:42 INFO - Output received: 07:14:42 INFO - /builds/slave/test/build/application/firefox/firefox 07:14:42 INFO - Running post-action listener: _resource_record_post_action 07:14:42 INFO - [mozharness: 2017-09-21 14:14:42.478713Z] Finished install step (success) 07:14:42 INFO - [mozharness: 2017-09-21 14:14:42.478967Z] Running setup-mitmproxy step. 07:14:42 INFO - Running pre-action listener: _resource_record_pre_action 07:14:42 INFO - Running main action method: setup_mitmproxy 07:14:42 INFO - Skipping: mitmproxy is not required 07:14:42 INFO - Running post-action listener: _resource_record_post_action 07:14:42 INFO - [mozharness: 2017-09-21 14:14:42.480103Z] Finished setup-mitmproxy step (success) 07:14:42 INFO - [mozharness: 2017-09-21 14:14:42.480330Z] Running run-tests step. 07:14:42 INFO - Running pre-action listener: _resource_record_pre_action 07:14:42 INFO - Running pre-action listener: _set_gcov_prefix 07:14:42 INFO - Running main action method: run_tests 07:14:42 WARNING - Try message not found. 07:14:42 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 07:14:42 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 07:14:42 INFO - Python 2.7.3 07:14:42 INFO - Return code: 0 07:14:42 INFO - grabbing minidump binary from tooltool 07:14:42 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 07:14:42 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 0x210c090>, '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 0x210cd80>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x2106f90>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 07:14:42 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 07:14:42 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 07:14:42 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 07:14:42 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 07:14:42 INFO - Return code: 0 07:14:42 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 07:14:42 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 07:14:42 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 07:14:42 INFO - ENV: RUST_BACKTRACE is now full 07:14:42 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 07:14:42 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 07:14:42 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-052', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] in /builds/slave/test/build 07:14:42 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite g4-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-052 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log 07:14:42 INFO - Using env: {'DISPLAY': ':0', 07:14:42 INFO - 'HOME': '/home/cltbld', 07:14:42 INFO - 'LANG': 'en_US.UTF-8', 07:14:42 INFO - 'LANGUAGE': 'en_US:en', 07:14:42 INFO - 'LOGNAME': 'cltbld', 07:14:42 INFO - 'MAIL': '/var/mail/cltbld', 07:14:42 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 07:14:42 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 07:14:42 INFO - 'MOZ_ACCELERATED': '1', 07:14:42 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:42 INFO - 'MOZ_NO_REMOTE': '1', 07:14:42 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 07:14:42 INFO - 'MOZ_WEBRENDER': '1', 07:14:42 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:42 INFO - 'NO_EM_RESTART': '1', 07:14:42 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:42 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:42 INFO - 'PWD': '/builds/slave/test', 07:14:42 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 07:14:42 INFO - 'RUST_BACKTRACE': 'full', 07:14:42 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 07:14:42 INFO - 'SHELL': '/bin/bash', 07:14:42 INFO - 'SHLVL': '1', 07:14:42 INFO - 'TERM': 'linux', 07:14:42 INFO - 'TMOUT': '86400', 07:14:42 INFO - 'USER': 'cltbld', 07:14:42 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:42 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:42 INFO - '_': '/tools/buildbot/bin/python'} 07:14:42 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'g4-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-052', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log'] with output_timeout 3600 07:14:42 INFO - mozversion application_buildid: 20170921132403 07:14:42 INFO - mozversion application_changeset: f7e9777221a34f9f23c2e4933307eb38b621b679 07:14:42 INFO - mozversion application_display_name: Nightly 07:14:42 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 07:14:42 INFO - mozversion application_name: Firefox 07:14:42 INFO - mozversion application_remotingname: firefox 07:14:42 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 07:14:42 INFO - mozversion application_vendor: Mozilla 07:14:42 INFO - mozversion application_version: 57.0a1 07:14:42 INFO - mozversion platform_buildid: 20170921132403 07:14:42 INFO - mozversion platform_changeset: f7e9777221a34f9f23c2e4933307eb38b621b679 07:14:42 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 07:14:42 INFO - mozversion platform_version: 57.0a1 07:14:42 INFO - using testdate: 1506003282 07:14:42 INFO - actual date: 1506003282 07:14:42 INFO - starting webserver on 'localhost:52985' 07:14:42 INFO - SUITE-START | Running 2 tests 07:14:42 INFO - TEST-START | basic_compositor_video 07:14:42 INFO - Initialising browser for basic_compositor_video test... 07:14:42 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:52985/getInfo.html -profile /tmp/tmpRM5FMB/profile 07:14:42 INFO - TEST-INFO | started process 30920 (/builds/slave/test/build/application/firefox/firefox http://localhost:52985/getInfo.html) 07:14:49 INFO - TEST-INFO | 30920: exit 0 07:14:49 INFO - Browser initialized. 07:14:49 INFO - Running cycle 1/1 for basic_compositor_video test... 07:14:49 INFO - Using env: {'DISPLAY': ':0', 07:14:49 INFO - 'HOME': '/home/cltbld', 07:14:49 INFO - 'JSGC_DISABLE_POISONING': '1', 07:14:49 INFO - 'LANG': 'en_US.UTF-8', 07:14:49 INFO - 'LANGUAGE': 'en_US:en', 07:14:49 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 07:14:49 INFO - 'LOGNAME': 'cltbld', 07:14:49 INFO - 'MAIL': '/var/mail/cltbld', 07:14:49 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 07:14:49 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 07:14:49 INFO - 'MOZ_ACCELERATED': '1', 07:14:49 INFO - 'MOZ_CRASHREPORTER': '1', 07:14:49 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:14:49 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 07:14:49 INFO - 'MOZ_NO_REMOTE': '1', 07:14:49 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 07:14:49 INFO - 'MOZ_WEBRENDER': '1', 07:14:49 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:14:49 INFO - 'NO_EM_RESTART': '1', 07:14:49 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:14:49 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:14:49 INFO - 'PWD': '/builds/slave/test', 07:14:49 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 07:14:49 INFO - 'RUST_BACKTRACE': 'full', 07:14:49 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 07:14:49 INFO - 'SHELL': '/bin/bash', 07:14:49 INFO - 'SHLVL': '1', 07:14:49 INFO - 'TERM': 'linux', 07:14:49 INFO - 'TMOUT': '86400', 07:14:49 INFO - 'USER': 'cltbld', 07:14:49 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:14:49 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:14:49 INFO - '_': '/tools/buildbot/bin/python'} 07:14:49 INFO - TEST-INFO | started process 31163 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpRM5FMB/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 07:14:50 INFO - PID 31163 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 07:14:50 INFO - PID 31163 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 07:14:50 INFO - PID 31163 | 07:14:50 INFO - PID 31163 | (/builds/slave/test/build/application/firefox/firefox:31223): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 07:14:50 INFO - PID 31163 | 07:15:01 INFO - PID 31163 | RSS: Main: 188624896 07:15:01 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.40598235765838 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.367100591715976 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4595737704918026 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3785493460166474 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.982241550695825 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.8951591895803186 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.273981481481483 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.175532359081416 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.466366120218579 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.236282722513085 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.942322899505763 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.753004750593822 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.069479865771806 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.434551886792454 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.41725694444444 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.479336492890992 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.315790378006861 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.437523584905682 ms/frame 07:15:46 INFO - PID 31163 | 07:15:46 INFO - PID 31163 | Cycle 1(1): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:15:47 INFO - PID 31163 | RSS: Main: 1761677312 07:15:47 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.5559880749574106 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.376543942992874 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.453495502861815 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3821369047619045 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.985850746268657 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.8911777456647396 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.342778581765558 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.275576923076925 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.418446244477172 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.2114105263157935 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.9517244224422425 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.763654761904763 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.033595317725746 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.391807511737097 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.453222996515695 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.48229857819905 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.386141868512114 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.391619718309864 ms/frame 07:16:32 INFO - PID 31163 | 07:16:32 INFO - PID 31163 | Cycle 1(2): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:16:33 INFO - PID 31163 | RSS: Main: 1771208704 07:16:33 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.5690068493150684 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.3704502369668243 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4471492659053835 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.383885578069131 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.985388059701493 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.904172714078375 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.342865412445728 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.2482377919320635 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.28287852112676 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.170788113695093 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.9101227495908395 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.728605200945628 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.000483333333348 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.437311320754713 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.456515679442523 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.433867924528283 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.527385964912282 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.435235849056589 ms/frame 07:17:18 INFO - PID 31163 | 07:17:18 INFO - PID 31163 | Cycle 1(3): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:17:19 INFO - PID 31163 | RSS: Main: 1764163584 07:17:19 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.569379280821918 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.3730960854092533 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.457571662571662 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3817916666666665 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.9884312749003987 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.903149492017417 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.310818965517239 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.194696016771494 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.319982269503548 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.926096059113298 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.9179590163934455 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.729657210401892 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.067231543624148 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.43431603773587 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.453344947735193 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.481872037914671 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.492307692307676 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.389577464788747 ms/frame 07:18:04 INFO - PID 31163 | 07:18:04 INFO - PID 31163 | Cycle 1(4): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:18:05 INFO - PID 31163 | RSS: Main: 1787383808 07:18:05 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.55805200341006 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.3762351543942986 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.459360655737705 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.390489844683392 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.9768898809523807 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.907420058139533 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.2687980085348505 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.2213291139240505 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.245804195804199 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.182461139896374 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 5.050875420875417 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.856310679611648 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.070385906040263 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.437476415094352 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.38084775086506 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.437830188679245 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.416701388888871 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.435801886792484 ms/frame 07:18:50 INFO - PID 31163 | 07:18:50 INFO - PID 31163 | Cycle 1(5): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:18:50 INFO - PID 31163 | RSS: Main: 1799065600 07:18:50 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.5711610968294774 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.381059523809524 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.445578647106764 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.378376932223545 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.9972227772227784 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.8999565217391297 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.367074235807864 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.192714884696016 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.870836038961041 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.0775126903553325 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.886066775244303 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.695809859154923 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.0006 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.436721698113203 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.455435540069683 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.480213270142166 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.493076923076938 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.43580188679245 ms/frame 07:19:36 INFO - PID 31163 | 07:19:36 INFO - PID 31163 | Cycle 1(6): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:19:36 INFO - PID 31163 | RSS: Main: 1803546624 07:19:36 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.568493150684932 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.382190476190476 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.469296296296296 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3809345238095236 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.9793495531281033 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.8991811594202916 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.341722141823446 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.246645435244158 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.254570928196149 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.1022831632653 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.910695581014732 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.706188235294111 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.03680602006688 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.390798122065751 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.45299651567945 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.436108490566012 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.453118466898948 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.436768867924533 ms/frame 07:20:22 INFO - PID 31163 | 07:20:22 INFO - PID 31163 | Cycle 1(7): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:20:22 INFO - PID 31163 | RSS: Main: 1819938816 07:20:22 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.564474358974359 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.3813630952380955 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4659326211996713 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3877446300715994 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.9911914257228305 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.8998333333333335 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.387061403508772 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.246496815286621 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.755855784469096 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.319202127659576 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.91834426229508 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.775011933174232 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.03643812709029 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.435731132075471 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.45649825783972 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.47995260663509 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.3831660899654 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.481872037914671 ms/frame 07:21:08 INFO - PID 31163 | 07:21:08 INFO - PID 31163 | Cycle 1(8): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:21:08 INFO - PID 31163 | RSS: Main: 1832099840 07:21:08 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.564653846153846 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.375724465558195 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4555032733224222 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.390250896057347 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 3.003593593593594 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.8986159420289854 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.40008064516129 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.312392241379312 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.273541300527241 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.1545747422680375 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.959355371900826 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.762857142857138 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.002533333333329 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.393333333333327 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.42010416666666 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.47969194312798 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.456393728222999 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.438537735849062 ms/frame 07:21:54 INFO - PID 31163 | 07:21:54 INFO - PID 31163 | Cycle 1(9): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:21:54 INFO - PID 31163 | RSS: Main: 1843949568 07:21:54 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.5646410256410257 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.3706872037914692 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4571908271908267 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3784126040428073 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.9881274900398407 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.904143686502177 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.336741329479768 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.1236494845360845 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.854716828478964 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.832016908212556 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.918090163934426 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.728522458628843 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.069647651006703 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.43596698113209 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.490506993007005 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.435023584905654 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.419097222222238 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.435872641509429 ms/frame 07:22:40 INFO - PID 31163 | 07:22:40 INFO - PID 31163 | Cycle 1(10): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:22:40 INFO - PID 31163 | RSS: Main: 1854926848 07:22:40 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.538574450084602 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.378501783590963 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.449212244897959 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3871718377088316 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.9911266201395814 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.8996304347826074 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.317805755395684 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.221445147679325 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 4.992088186356072 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 4.844903147699757 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.943286655683692 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.819156626506026 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 9.968189368770775 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.524214285714281 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.492080419580422 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.435235849056589 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.490909090909096 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.47964454976304 ms/frame 07:23:26 INFO - PID 31163 | 07:23:26 INFO - PID 31163 | Cycle 1(11): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:23:26 INFO - PID 31163 | RSS: Main: 1860059136 07:23:26 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_startup = 2.545212044105174 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1_inclip = 2.381559523809524 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_startup = 2.4595204918032794 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 2.3754334916864615 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_startup = 2.994955089820359 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.240p.120fps.mp4_scale_2_inclip = 2.903693759071118 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_startup = 4.348442028985506 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1_inclip = 4.1947589098532525 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.387351885098745 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.025339195979897 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_startup = 4.935008223684211 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.480p.60fps.webm_scale_2_inclip = 4.751294536817098 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.000083333333325 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1_inclip = 9.437146226415107 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 10.5286842105263 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 9.433750000000009 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.456271777003499 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | testsrc.1080p.60fps.mp4_scale_2_inclip = 9.435094339622632 ms/frame 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | Cycle 1(12): loaded http://localhost:52985/tests/video/video_playback.html (next: http://localhost:52985/tests/video/video_playback.html) 07:24:12 INFO - PID 31163 | RSS: Main: 1876262912 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | __start_tp_report 07:24:12 INFO - PID 31163 | _x_x_mozilla_page_load 07:24:12 INFO - PID 31163 | _x_x_mozilla_page_load_details 07:24:12 INFO - PID 31163 | |i|pagename|runs| 07:24:12 INFO - PID 31163 | |0;240p.120fps.mp4_scale_1_startup;2.40598235765838;2.5559880749574106;2.5690068493150684;2.569379280821918;2.55805200341006;2.5711610968294774;2.568493150684932;2.564474358974359;2.564653846153846;2.5646410256410257;2.538574450084602;2.545212044105174 07:24:12 INFO - PID 31163 | |1;240p.120fps.mp4_scale_1_inclip;2.367100591715976;2.376543942992874;2.3704502369668243;2.3730960854092533;2.3762351543942986;2.381059523809524;2.382190476190476;2.3813630952380955;2.375724465558195;2.3706872037914692;2.378501783590963;2.381559523809524 07:24:12 INFO - PID 31163 | |2;240p.120fps.mp4_scale_1.1_startup;2.4595737704918026;2.453495502861815;2.4471492659053835;2.457571662571662;2.459360655737705;2.445578647106764;2.469296296296296;2.4659326211996713;2.4555032733224222;2.4571908271908267;2.449212244897959;2.4595204918032794 07:24:12 INFO - PID 31163 | |3;240p.120fps.mp4_scale_1.1_inclip;2.3785493460166474;2.3821369047619045;2.383885578069131;2.3817916666666665;2.390489844683392;2.378376932223545;2.3809345238095236;2.3877446300715994;2.390250896057347;2.3784126040428073;2.3871718377088316;2.3754334916864615 07:24:12 INFO - PID 31163 | |4;240p.120fps.mp4_scale_2_startup;2.982241550695825;2.985850746268657;2.985388059701493;2.9884312749003987;2.9768898809523807;2.9972227772227784;2.9793495531281033;2.9911914257228305;3.003593593593594;2.9881274900398407;2.9911266201395814;2.994955089820359 07:24:12 INFO - PID 31163 | |5;240p.120fps.mp4_scale_2_inclip;2.8951591895803186;2.8911777456647396;2.904172714078375;2.903149492017417;2.907420058139533;2.8999565217391297;2.8991811594202916;2.8998333333333335;2.8986159420289854;2.904143686502177;2.8996304347826074;2.903693759071118 07:24:12 INFO - PID 31163 | |6;480p.60fps.webm_scale_1_startup;4.273981481481483;4.342778581765558;4.342865412445728;4.310818965517239;4.2687980085348505;4.367074235807864;4.341722141823446;4.387061403508772;4.40008064516129;4.336741329479768;4.317805755395684;4.348442028985506 07:24:12 INFO - PID 31163 | |7;480p.60fps.webm_scale_1_inclip;4.175532359081416;4.275576923076925;4.2482377919320635;4.194696016771494;4.2213291139240505;4.192714884696016;4.246645435244158;4.246496815286621;4.312392241379312;4.1236494845360845;4.221445147679325;4.1947589098532525 07:24:12 INFO - PID 31163 | |8;480p.60fps.webm_scale_1.1_startup;5.466366120218579;4.418446244477172;5.28287852112676;5.319982269503548;5.245804195804199;4.870836038961041;5.254570928196149;4.755855784469096;5.273541300527241;4.854716828478964;4.992088186356072;5.387351885098745 07:24:12 INFO - PID 31163 | |9;480p.60fps.webm_scale_1.1_inclip;5.236282722513085;4.2114105263157935;5.170788113695093;4.926096059113298;5.182461139896374;5.0775126903553325;5.1022831632653;5.319202127659576;5.1545747422680375;4.832016908212556;4.844903147699757;5.025339195979897 07:24:12 INFO - PID 31163 | |10;480p.60fps.webm_scale_2_startup;4.942322899505763;4.9517244224422425;4.9101227495908395;4.9179590163934455;5.050875420875417;4.886066775244303;4.910695581014732;4.91834426229508;4.959355371900826;4.918090163934426;4.943286655683692;4.935008223684211 07:24:12 INFO - PID 31163 | |11;480p.60fps.webm_scale_2_inclip;4.753004750593822;4.763654761904763;4.728605200945628;4.729657210401892;4.856310679611648;4.695809859154923;4.706188235294111;4.775011933174232;4.762857142857138;4.728522458628843;4.819156626506026;4.751294536817098 07:24:12 INFO - PID 31163 | |12;1080p.60fps.mp4_scale_1_startup;10.069479865771806;10.033595317725746;10.000483333333348;10.067231543624148;10.070385906040263;10.0006;10.03680602006688;10.03643812709029;10.002533333333329;10.069647651006703;9.968189368770775;10.000083333333325 07:24:12 INFO - PID 31163 | |13;1080p.60fps.mp4_scale_1_inclip;9.434551886792454;9.391807511737097;9.437311320754713;9.43431603773587;9.437476415094352;9.436721698113203;9.390798122065751;9.435731132075471;9.393333333333327;9.43596698113209;9.524214285714281;9.437146226415107 07:24:12 INFO - PID 31163 | |14;1080p.60fps.mp4_scale_1.1_startup;10.41725694444444;10.453222996515695;10.456515679442523;10.453344947735193;10.38084775086506;10.455435540069683;10.45299651567945;10.45649825783972;10.42010416666666;10.490506993007005;10.492080419580422;10.5286842105263 07:24:12 INFO - PID 31163 | |15;1080p.60fps.mp4_scale_1.1_inclip;9.479336492890992;9.48229857819905;9.433867924528283;9.481872037914671;9.437830188679245;9.480213270142166;9.436108490566012;9.47995260663509;9.47969194312798;9.435023584905654;9.435235849056589;9.433750000000009 07:24:12 INFO - PID 31163 | |16;1080p.60fps.mp4_scale_2_startup;10.315790378006861;10.386141868512114;10.527385964912282;10.492307692307676;10.416701388888871;10.493076923076938;10.453118466898948;10.3831660899654;10.456393728222999;10.419097222222238;10.490909090909096;10.456271777003499 07:24:12 INFO - PID 31163 | |17;1080p.60fps.mp4_scale_2_inclip;9.437523584905682;9.391619718309864;9.435235849056589;9.389577464788747;9.435801886792484;9.43580188679245;9.436768867924533;9.481872037914671;9.438537735849062;9.435872641509429;9.47964454976304;9.435094339622632 07:24:12 INFO - PID 31163 | __end_tp_report 07:24:12 INFO - PID 31163 | __start_cc_report 07:24:12 INFO - PID 31163 | _x_x_mozilla_cycle_collect,595 07:24:12 INFO - PID 31163 | __end_cc_report 07:24:12 INFO - PID 31163 | __startTimestamp1506003852571__endTimestamp 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | ------- Summary: start ------- 07:24:12 INFO - PID 31163 | Number of tests: 18 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:2.55 Median:2.56 stddev:0.05 (1.8%) stddev-sans-first:0.01 07:24:12 INFO - PID 31163 | Values: 2.4 2.6 2.6 2.6 2.6 2.6 2.6 2.6 2.6 2.6 2.5 2.5 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:2.38 Median:2.38 stddev:0.01 (0.2%) stddev-sans-first:0.00 07:24:12 INFO - PID 31163 | Values: 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:2.46 Median:2.46 stddev:0.01 (0.3%) stddev-sans-first:0.01 07:24:12 INFO - PID 31163 | Values: 2.5 2.5 2.4 2.5 2.5 2.4 2.5 2.5 2.5 2.5 2.4 2.5 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:2.38 Median:2.38 stddev:0.01 (0.2%) stddev-sans-first:0.01 07:24:12 INFO - PID 31163 | Values: 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 2.4 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:2.99 Median:2.99 stddev:0.01 (0.3%) stddev-sans-first:0.01 07:24:12 INFO - PID 31163 | Values: 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 3.0 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:2.90 Median:2.90 stddev:0.00 (0.2%) stddev-sans-first:0.00 07:24:12 INFO - PID 31163 | Values: 2.9 2.9 2.9 2.9 2.9 2.9 2.9 2.9 2.9 2.9 2.9 2.9 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:4.34 Median:4.34 stddev:0.04 (0.9%) stddev-sans-first:0.04 07:24:12 INFO - PID 31163 | Values: 4.3 4.3 4.3 4.3 4.3 4.4 4.3 4.4 4.4 4.3 4.3 4.3 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:4.22 Median:4.23 stddev:0.05 (1.2%) stddev-sans-first:0.05 07:24:12 INFO - PID 31163 | Values: 4.2 4.3 4.2 4.2 4.2 4.2 4.2 4.2 4.3 4.1 4.2 4.2 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.09 Median:5.26 stddev:0.31 (6.0%) stddev-sans-first:0.30 07:24:12 INFO - PID 31163 | Values: 5.5 4.4 5.3 5.3 5.2 4.9 5.3 4.8 5.3 4.9 5.0 5.4 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.01 Median:5.13 stddev:0.29 (5.7%) stddev-sans-first:0.30 07:24:12 INFO - PID 31163 | Values: 5.2 4.2 5.2 4.9 5.2 5.1 5.1 5.3 5.2 4.8 4.8 5.0 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:4.94 Median:4.94 stddev:0.04 (0.8%) stddev-sans-first:0.04 07:24:12 INFO - PID 31163 | Values: 4.9 5.0 4.9 4.9 5.1 4.9 4.9 4.9 5.0 4.9 4.9 4.9 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:4.76 Median:4.76 stddev:0.05 (1.0%) stddev-sans-first:0.05 07:24:12 INFO - PID 31163 | Values: 4.8 4.8 4.7 4.7 4.9 4.7 4.7 4.8 4.8 4.7 4.8 4.8 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:10.03 Median:10.05 stddev:0.03 (0.3%) stddev-sans-first:0.03 07:24:12 INFO - PID 31163 | Values: 10.1 10.0 10.0 10.1 10.1 10.0 10.0 10.0 10.0 10.1 10.0 10.0 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:9.43 Median:9.44 stddev:0.03 (0.4%) stddev-sans-first:0.04 07:24:12 INFO - PID 31163 | Values: 9.4 9.4 9.4 9.4 9.4 9.4 9.4 9.4 9.4 9.4 9.5 9.4 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:10.45 Median:10.46 stddev:0.04 (0.4%) stddev-sans-first:0.04 07:24:12 INFO - PID 31163 | Values: 10.4 10.5 10.5 10.5 10.4 10.5 10.5 10.5 10.4 10.5 10.5 10.5 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:9.46 Median:9.48 stddev:0.02 (0.2%) stddev-sans-first:0.02 07:24:12 INFO - PID 31163 | Values: 9.5 9.5 9.4 9.5 9.4 9.5 9.4 9.5 9.5 9.4 9.4 9.4 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:10.44 Median:10.46 stddev:0.06 (0.6%) stddev-sans-first:0.05 07:24:12 INFO - PID 31163 | Values: 10.3 10.4 10.5 10.5 10.4 10.5 10.5 10.4 10.5 10.4 10.5 10.5 07:24:12 INFO - PID 31163 | 07:24:12 INFO - PID 31163 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:9.44 Median:9.44 stddev:0.03 (0.3%) stddev-sans-first:0.03 07:24:12 INFO - PID 31163 | Values: 9.4 9.4 9.4 9.4 9.4 9.4 9.4 9.5 9.4 9.4 9.5 9.4 07:24:12 INFO - PID 31163 | -------- Summary: end -------- 07:24:12 INFO - PID 31163 | 07:24:13 INFO - TEST-INFO | 31163: exit 0 07:24:13 INFO - TEST-OK | basic_compositor_video | took 570474ms 07:24:13 INFO - TEST-START | glvideo 07:24:13 INFO - Initialising browser for glvideo test... 07:24:13 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:52985/getInfo.html -profile /tmp/tmp5DzNFm/profile 07:24:13 INFO - TEST-INFO | started process 32379 (/builds/slave/test/build/application/firefox/firefox http://localhost:52985/getInfo.html) 07:24:18 INFO - TEST-INFO | 32379: exit 0 07:24:18 INFO - Browser initialized. 07:24:18 INFO - Running cycle 1/1 for glvideo test... 07:24:18 INFO - Using env: {'DISPLAY': ':0', 07:24:18 INFO - 'HOME': '/home/cltbld', 07:24:18 INFO - 'JSGC_DISABLE_POISONING': '1', 07:24:18 INFO - 'LANG': 'en_US.UTF-8', 07:24:18 INFO - 'LANGUAGE': 'en_US:en', 07:24:18 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 07:24:18 INFO - 'LOGNAME': 'cltbld', 07:24:18 INFO - 'MAIL': '/var/mail/cltbld', 07:24:18 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 07:24:18 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 07:24:18 INFO - 'MOZ_ACCELERATED': '1', 07:24:18 INFO - 'MOZ_CRASHREPORTER': '1', 07:24:18 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 07:24:18 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 07:24:18 INFO - 'MOZ_NO_REMOTE': '1', 07:24:18 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 07:24:18 INFO - 'MOZ_WEBRENDER': '1', 07:24:18 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 07:24:18 INFO - 'NO_EM_RESTART': '1', 07:24:18 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 07:24:18 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 07:24:18 INFO - 'PWD': '/builds/slave/test', 07:24:18 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 07:24:18 INFO - 'RUST_BACKTRACE': 'full', 07:24:18 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 07:24:18 INFO - 'SHELL': '/bin/bash', 07:24:18 INFO - 'SHLVL': '1', 07:24:18 INFO - 'TERM': 'linux', 07:24:18 INFO - 'TMOUT': '86400', 07:24:18 INFO - 'USER': 'cltbld', 07:24:18 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743', 07:24:18 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 07:24:18 INFO - '_': '/tools/buildbot/bin/python'} 07:24:18 INFO - TEST-INFO | started process 32623 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp5DzNFm/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 07:24:19 INFO - PID 32623 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 07:24:19 INFO - PID 32623 | WebRender - OpenGL version new 3.2.0 NVIDIA 361.42 07:24:19 INFO - PID 32623 | 07:24:19 INFO - PID 32623 | (/builds/slave/test/build/application/firefox/firefox:32683): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 07:24:19 INFO - PID 32623 | 07:24:30 INFO - PID 32623 | RSS: Main: 191459328 07:24:30 INFO - PID 32623 | 07:24:31 INFO - PID 32623 | [talos glvideo result] Mean tick time across 100 ticks: 7.128700000000001 ms 07:24:31 INFO - PID 32623 | Cycle 1(1): loaded http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html) 07:24:31 INFO - PID 32623 | RSS: Main: 190124032 07:24:31 INFO - PID 32623 | 07:24:32 INFO - PID 32623 | [talos glvideo result] Mean tick time across 100 ticks: 6.4761500000000005 ms 07:24:32 INFO - PID 32623 | Cycle 1(2): loaded http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html) 07:24:33 INFO - PID 32623 | RSS: Main: 186576896 07:24:33 INFO - PID 32623 | 07:24:33 INFO - PID 32623 | [talos glvideo result] Mean tick time across 100 ticks: 6.54665 ms 07:24:33 INFO - PID 32623 | Cycle 1(3): loaded http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html) 07:24:34 INFO - PID 32623 | RSS: Main: 186904576 07:24:34 INFO - PID 32623 | 07:24:35 INFO - PID 32623 | [talos glvideo result] Mean tick time across 100 ticks: 6.599549999999999 ms 07:24:35 INFO - PID 32623 | Cycle 1(4): loaded http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html) 07:24:35 INFO - PID 32623 | RSS: Main: 186724352 07:24:35 INFO - PID 32623 | 07:24:36 INFO - PID 32623 | [talos glvideo result] Mean tick time across 100 ticks: 6.5615 ms 07:24:36 INFO - PID 32623 | Cycle 1(5): loaded http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:52985/tests/webgl/benchmarks/video/video_upload.html) 07:24:36 INFO - PID 32623 | RSS: Main: 187199488 07:24:36 INFO - PID 32623 | 07:24:36 INFO - PID 32623 | __start_tp_report 07:24:36 INFO - PID 32623 | _x_x_mozilla_page_load 07:24:36 INFO - PID 32623 | _x_x_mozilla_page_load_details 07:24:36 INFO - PID 32623 | |i|pagename|runs| 07:24:36 INFO - PID 32623 | |0;Mean tick time across 100 ticks: ;7.128700000000001;6.4761500000000005;6.54665;6.599549999999999;6.5615 07:24:36 INFO - PID 32623 | __end_tp_report 07:24:36 INFO - PID 32623 | __start_cc_report 07:24:36 INFO - PID 32623 | _x_x_mozilla_cycle_collect,234 07:24:36 INFO - PID 32623 | __end_cc_report 07:24:36 INFO - PID 32623 | __startTimestamp1506003876750__endTimestamp 07:24:36 INFO - PID 32623 | 07:24:36 INFO - PID 32623 | ------- Summary: start ------- 07:24:36 INFO - PID 32623 | Number of tests: 1 07:24:36 INFO - PID 32623 | 07:24:36 INFO - PID 32623 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.66 Median:6.56 stddev:0.26 (4.0%) stddev-sans-first:0.05 07:24:36 INFO - PID 32623 | Values: 7.1 6.5 6.5 6.6 6.6 07:24:36 INFO - PID 32623 | -------- Summary: end -------- 07:24:36 INFO - PID 32623 | 07:24:37 INFO - PID 32623 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 07:24:37 INFO - TEST-INFO | 32623: exit 0 07:24:37 INFO - TEST-OK | glvideo | took 24409ms 07:24:37 INFO - SUITE-END | took 594s 07:24:37 INFO - Completed test suite (00:09:54) 07:24:37 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.082550721350622, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.40598235765838, 2.5559880749574106, 2.5690068493150684, 2.569379280821918, 2.55805200341006, 2.5711610968294774, 2.568493150684932, 2.564474358974359, 2.564653846153846, 2.5646410256410257, 2.538574450084602, 2.545212044105174], "value": 2.5646410256410257, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.367100591715976, 2.376543942992874, 2.3704502369668243, 2.3730960854092533, 2.3762351543942986, 2.381059523809524, 2.382190476190476, 2.3813630952380955, 2.375724465558195, 2.3706872037914692, 2.378501783590963, 2.381559523809524], "value": 2.376543942992874, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.4595737704918026, 2.453495502861815, 2.4471492659053835, 2.457571662571662, 2.459360655737705, 2.445578647106764, 2.469296296296296, 2.4659326211996713, 2.4555032733224222, 2.4571908271908267, 2.449212244897959, 2.4595204918032794], "value": 2.4571908271908267, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.3785493460166474, 2.3821369047619045, 2.383885578069131, 2.3817916666666665, 2.390489844683392, 2.378376932223545, 2.3809345238095236, 2.3877446300715994, 2.390250896057347, 2.3784126040428073, 2.3871718377088316, 2.3754334916864615], "value": 2.3821369047619045, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.982241550695825, 2.985850746268657, 2.985388059701493, 2.9884312749003987, 2.9768898809523807, 2.9972227772227784, 2.9793495531281033, 2.9911914257228305, 3.003593593593594, 2.9881274900398407, 2.9911266201395814, 2.994955089820359], "value": 2.9884312749003987, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [2.8951591895803186, 2.8911777456647396, 2.904172714078375, 2.903149492017417, 2.907420058139533, 2.8999565217391297, 2.8991811594202916, 2.8998333333333335, 2.8986159420289854, 2.904143686502177, 2.8996304347826074, 2.903693759071118], "value": 2.8999565217391297, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.273981481481483, 4.342778581765558, 4.342865412445728, 4.310818965517239, 4.2687980085348505, 4.367074235807864, 4.341722141823446, 4.387061403508772, 4.40008064516129, 4.336741329479768, 4.317805755395684, 4.348442028985506], "value": 4.342778581765558, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.175532359081416, 4.275576923076925, 4.2482377919320635, 4.194696016771494, 4.2213291139240505, 4.192714884696016, 4.246645435244158, 4.246496815286621, 4.312392241379312, 4.1236494845360845, 4.221445147679325, 4.1947589098532525], "value": 4.221445147679325, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.466366120218579, 4.418446244477172, 5.28287852112676, 5.319982269503548, 5.245804195804199, 4.870836038961041, 5.254570928196149, 4.755855784469096, 5.273541300527241, 4.854716828478964, 4.992088186356072, 5.387351885098745], "value": 5.245804195804199, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.236282722513085, 4.2114105263157935, 5.170788113695093, 4.926096059113298, 5.182461139896374, 5.0775126903553325, 5.1022831632653, 5.319202127659576, 5.1545747422680375, 4.832016908212556, 4.844903147699757, 5.025339195979897], "value": 5.0775126903553325, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.942322899505763, 4.9517244224422425, 4.9101227495908395, 4.9179590163934455, 5.050875420875417, 4.886066775244303, 4.910695581014732, 4.91834426229508, 4.959355371900826, 4.918090163934426, 4.943286655683692, 4.935008223684211], "value": 4.91834426229508, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.753004750593822, 4.763654761904763, 4.728605200945628, 4.729657210401892, 4.856310679611648, 4.695809859154923, 4.706188235294111, 4.775011933174232, 4.762857142857138, 4.728522458628843, 4.819156626506026, 4.751294536817098], "value": 4.751294536817098, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.069479865771806, 10.033595317725746, 10.000483333333348, 10.067231543624148, 10.070385906040263, 10.0006, 10.03680602006688, 10.03643812709029, 10.002533333333329, 10.069647651006703, 9.968189368770775, 10.000083333333325], "value": 10.033595317725746, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.434551886792454, 9.391807511737097, 9.437311320754713, 9.43431603773587, 9.437476415094352, 9.436721698113203, 9.390798122065751, 9.435731132075471, 9.393333333333327, 9.43596698113209, 9.524214285714281, 9.437146226415107], "value": 9.43596698113209, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.41725694444444, 10.453222996515695, 10.456515679442523, 10.453344947735193, 10.38084775086506, 10.455435540069683, 10.45299651567945, 10.45649825783972, 10.42010416666666, 10.490506993007005, 10.492080419580422, 10.5286842105263], "value": 10.455435540069683, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.479336492890992, 9.48229857819905, 9.433867924528283, 9.481872037914671, 9.437830188679245, 9.480213270142166, 9.436108490566012, 9.47995260663509, 9.47969194312798, 9.435023584905654, 9.435235849056589, 9.433750000000009], "value": 9.437830188679245, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.315790378006861, 10.386141868512114, 10.527385964912282, 10.492307692307676, 10.416701388888871, 10.493076923076938, 10.453118466898948, 10.3831660899654, 10.456393728222999, 10.419097222222238, 10.490909090909096, 10.456271777003499], "value": 10.456271777003499, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.437523584905682, 9.391619718309864, 9.435235849056589, 9.389577464788747, 9.435801886792484, 9.43580188679245, 9.436768867924533, 9.481872037914671, 9.438537735849062, 9.435872641509429, 9.47964454976304, 9.435094339622632], "value": 9.435801886792484, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [7.128700000000001, 6.4761500000000005, 6.54665, 6.599549999999999, 6.5615], "value": 6.554074999999999, "unit": "ms"}], "extraOptions": ["e10s"], "name": "glvideo", "alertThreshold": 2.0}]} 07:24:37 INFO - Return code: 0 07:24:37 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 07:24:37 INFO - # TBPL SUCCESS # 07:24:37 INFO - Running post-action listener: _package_coverage_data 07:24:37 INFO - Running post-action listener: _resource_record_post_action 07:24:37 INFO - [mozharness: 2017-09-21 14:24:37.896930Z] Finished run-tests step (success) 07:24:37 INFO - Running post-run listener: _resource_record_post_run 07:24:37 INFO - Total resource usage - Wall time: 613s; CPU: 43.0%; Read bytes: 1896448; Write bytes: 326078464; Read time: 1312; Write time: 263652 07:24:37 INFO - TinderboxPrint: CPU usage
43.1% 07:24:37 INFO - TinderboxPrint: I/O read bytes / time
1,896,448 / 1,312 07:24:37 INFO - TinderboxPrint: I/O write bytes / time
326,078,464 / 263,652 07:24:37 INFO - TinderboxPrint: CPU idle
2,746.7 (56.9%) 07:24:37 INFO - TinderboxPrint: CPU system
588.3 (12.2%) 07:24:37 INFO - TinderboxPrint: CPU user
1,474.3 (30.5%) 07:24:37 INFO - TinderboxPrint: Swap in / out
0 / 0 07:24:37 INFO - install - Wall time: 18s; CPU: 13.0%; Read bytes: 0; Write bytes: 13131776; Read time: 0; Write time: 1132 07:24:37 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 07:24:37 INFO - run-tests - Wall time: 595s; CPU: 44.0%; Read bytes: 1892352; Write bytes: 312946688; Read time: 1292; Write time: 262520 07:24:38 INFO - Running post-run listener: _upload_blobber_files 07:24:38 INFO - Blob upload gear active. 07:24:38 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 07:24:38 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 07:24:38 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'] 07:24:38 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 07:24:38 INFO - (blobuploader) - INFO - Open directory for files ... 07:24:38 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 07:24:38 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:24:38 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:24:39 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 07:24:39 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:24:39 INFO - (blobuploader) - INFO - Done attempting. 07:24:39 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_errorsummary.log ... 07:24:39 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:24:39 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:24:40 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_errorsummary.log: uploaded 07:24:40 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:24:40 INFO - (blobuploader) - INFO - Done attempting. 07:24:40 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-e10s_raw.log ... 07:24:40 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:24:40 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:24:41 INFO - (blobuploader) - INFO - TinderboxPrint: g4-e10s_raw.log: uploaded 07:24:41 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:24:41 INFO - (blobuploader) - INFO - Done attempting. 07:24:41 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 07:24:41 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 07:24:41 INFO - (blobuploader) - INFO - Uploading, attempt #1. 07:24:46 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 07:24:46 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 07:24:46 INFO - (blobuploader) - INFO - Done attempting. 07:24:46 INFO - (blobuploader) - INFO - Iteration through files over. 07:24:46 INFO - Return code: 0 07:24:46 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 07:24:46 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 07:24:46 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f07f24ee88dcffc675beb713dffee255ae06d6f2fc327835dfb4d94eb15fd1ebe244ffa1ffc1ddab864a990053cc144dae0decd076c870fecdc7adfb542dc9f1", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/ed15a40d04e370c49a6243f8be171677edabfd9a9498ff5f8d1e61929fc9d53dd27a008ae4506f728a3c1be2396601c28c2b17352f410ff8c4794a467a2584a1", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6b8494f0fba88cc4a8a1e8c945241e6594f99d16396061b290c9b59d94e4a359179f43adfe91d1f4bd3ca4c4a23025b2665facbc611b2a0507c12836cdb762d8", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a19a93d48ff42c8090450002e6ec59bf5421a352ad7244f1e4b3d82605a3f1444efa60dde57d6a401001863830198b269c81251db38ddad22cae264895cd429c"} 07:24:46 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 07:24:46 INFO - Writing to file /builds/slave/test/properties/blobber_files 07:24:46 INFO - Contents: 07:24:46 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f07f24ee88dcffc675beb713dffee255ae06d6f2fc327835dfb4d94eb15fd1ebe244ffa1ffc1ddab864a990053cc144dae0decd076c870fecdc7adfb542dc9f1", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/ed15a40d04e370c49a6243f8be171677edabfd9a9498ff5f8d1e61929fc9d53dd27a008ae4506f728a3c1be2396601c28c2b17352f410ff8c4794a467a2584a1", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6b8494f0fba88cc4a8a1e8c945241e6594f99d16396061b290c9b59d94e4a359179f43adfe91d1f4bd3ca4c4a23025b2665facbc611b2a0507c12836cdb762d8", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a19a93d48ff42c8090450002e6ec59bf5421a352ad7244f1e4b3d82605a3f1444efa60dde57d6a401001863830198b269c81251db38ddad22cae264895cd429c"} 07:24:46 INFO - Running post-run listener: copy_logs_to_upload_dir 07:24:46 INFO - Copying logs to upload dir... 07:24:46 INFO - mkdir: /builds/slave/test/build/upload/logs 07:24:46 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=661.971340 ========= master_lag: -0.02 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 1 secs) (at 2017-09-21 07:24:45.637693) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-09-21 07:24:45.642319) ========= 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=826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743 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/f07f24ee88dcffc675beb713dffee255ae06d6f2fc327835dfb4d94eb15fd1ebe244ffa1ffc1ddab864a990053cc144dae0decd076c870fecdc7adfb542dc9f1", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/ed15a40d04e370c49a6243f8be171677edabfd9a9498ff5f8d1e61929fc9d53dd27a008ae4506f728a3c1be2396601c28c2b17352f410ff8c4794a467a2584a1", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6b8494f0fba88cc4a8a1e8c945241e6594f99d16396061b290c9b59d94e4a359179f43adfe91d1f4bd3ca4c4a23025b2665facbc611b2a0507c12836cdb762d8", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a19a93d48ff42c8090450002e6ec59bf5421a352ad7244f1e4b3d82605a3f1444efa60dde57d6a401001863830198b269c81251db38ddad22cae264895cd429c"} build_url:https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011313 build_url: 'https://queue.taskcluster.net/v1/task/OYLYgPYVTVKEo2gH9bptQA/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/f07f24ee88dcffc675beb713dffee255ae06d6f2fc327835dfb4d94eb15fd1ebe244ffa1ffc1ddab864a990053cc144dae0decd076c870fecdc7adfb542dc9f1", "g4-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/ed15a40d04e370c49a6243f8be171677edabfd9a9498ff5f8d1e61929fc9d53dd27a008ae4506f728a3c1be2396601c28c2b17352f410ff8c4794a467a2584a1", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/6b8494f0fba88cc4a8a1e8c945241e6594f99d16396061b290c9b59d94e4a359179f43adfe91d1f4bd3ca4c4a23025b2665facbc611b2a0507c12836cdb762d8", "g4-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/a19a93d48ff42c8090450002e6ec59bf5421a352ad7244f1e4b3d82605a3f1444efa60dde57d6a401001863830198b269c81251db38ddad22cae264895cd429c"}' ========= master_lag: 0.03 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-09-21 07:24:45.683099) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-09-21 07:24:45.683423) ========= 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=826874ccc97bd7bf541b4875000001d5-1506003193.974550-264314743 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004565 ========= master_lag: 0.05 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-09-21 07:24:45.742657) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-09-21 07:24:45.742975) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-09-21 07:24:45.743286) ========= ========= Total master_lag: 0.13 =========