builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s slave: talos-linux64-ix-045 starttime: 1507748609.76 results: success (0) revision: 5cc87630fff42a8cb272ec58c530ef68007ecacd ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.762981) ========= master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.763409) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.763710) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.781572) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.781904) ========= 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=4300f881736b422476174874000001bc-1507748608.868977-205121776 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-10-11 12:03:29-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org (hg.mozilla.org)... 63.245.215.25, 63.245.215.102 Connecting to hg.mozilla.org (hg.mozilla.org)|63.245.215.25|:443... connected. HTTP request sent, awaiting response... 200 Script output follows Length: 12179 (12K) [text/x-python] Saving to: `archiver_client.py' 0K .......... . 100% 205M=0s 2017-10-11 12:03:29 (205 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.123491 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.923433) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.923876) ========= 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=4300f881736b422476174874000001bc-1507748608.868977-205121776 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.015739 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.973873) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:29.974227) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 5cc87630fff42a8cb272ec58c530ef68007ecacd --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 5cc87630fff42a8cb272ec58c530ef68007ecacd --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=4300f881736b422476174874000001bc-1507748608.868977-205121776 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-10-11 12:03:30,028 truncating revision to first 12 chars 2017-10-11 12:03:30,028 Setting DEBUG logging. 2017-10-11 12:03:30,029 attempt 1/10 2017-10-11 12:03:30,029 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/5cc87630fff4?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-10-11 12:03:30,642 unpacking tar archive at: mozilla-central-5cc87630fff4/testing/mozharness/ program finished with exit code 0 elapsedTime=0.970831 ========= master_lag: 0.01 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:30.959183) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:30.959537) ========= script_repo_revision: 5cc87630fff42a8cb272ec58c530ef68007ecacd ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:30.959959) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:30.960262) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-10-11 12:03:30.973715) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 46 secs) (at 2017-10-11 12:03:30.974194) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox-Non-PGO --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox-Non-PGO in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'g4-stylo-disabled-e10s', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox-Non-PGO', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox-Non-PGO'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=4300f881736b422476174874000001bc-1507748608.868977-205121776 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 12:03:31 INFO - MultiFileLogger online at 20171011 12:03:31 in /builds/slave/test 12:03:31 INFO - Run as scripts/scripts/talos_script.py --suite g4-stylo-disabled-e10s --add-option --webServer,localhost --branch-name Firefox-Non-PGO --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox-Non-PGO 12:03:31 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 12:03:31 INFO - {'append_to_log': False, 12:03:31 INFO - 'base_work_dir': '/builds/slave/test', 12:03:31 INFO - 'blob_upload_branch': 'Firefox-Non-PGO', 12:03:31 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 12:03:31 INFO - 'branch': 'Firefox-Non-PGO', 12:03:31 INFO - 'buildbot_json_path': 'buildprops.json', 12:03:31 INFO - 'code_coverage': False, 12:03:31 INFO - 'config_files': ('talos/linux_config.py',), 12:03:31 INFO - 'default_actions': ('clobber', 12:03:31 INFO - 'read-buildbot-config', 12:03:31 INFO - 'download-and-extract', 12:03:31 INFO - 'populate-webroot', 12:03:31 INFO - 'create-virtualenv', 12:03:31 INFO - 'install', 12:03:31 INFO - 'setup-mitmproxy', 12:03:31 INFO - 'run-tests'), 12:03:31 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 12:03:31 INFO - 'disable_ccov_upload': False, 12:03:31 INFO - 'disable_stylo': False, 12:03:31 INFO - 'download_minidump_stackwalk': True, 12:03:31 INFO - 'download_symbols': 'ondemand', 12:03:31 INFO - 'enable_stylo': False, 12:03:31 INFO - 'enable_webrender': False, 12:03:31 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'}, 12:03:31 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 12:03:31 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 12:03:31 INFO - 'gecko_profile': False, 12:03:31 INFO - 'gecko_profile_interval': 0, 12:03:31 INFO - 'installer_path': 'installer.exe', 12:03:31 INFO - 'log_level': 'info', 12:03:31 INFO - 'log_name': 'talos', 12:03:31 INFO - 'log_to_console': True, 12:03:31 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 12:03:31 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 12:03:31 INFO - 'opt_config_files': (), 12:03:31 INFO - 'pip_index': False, 12:03:31 INFO - 'suite': 'g4-stylo-disabled-e10s', 12:03:31 INFO - 'system_bits': '32', 12:03:31 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 12:03:31 INFO - 'title': 'talos-linux64-ix-045', 12:03:31 INFO - 'tooltool_cache': '/builds/tooltool_cache', 12:03:31 INFO - 'use_talos_json': True, 12:03:31 INFO - 'verify': 'False', 12:03:31 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 12:03:31 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 12:03:31 INFO - 'work_dir': 'build'} 12:03:31 INFO - [mozharness: 2017-10-11 19:03:31.175421Z] Running clobber step. 12:03:31 INFO - Running pre-action listener: _resource_record_pre_action 12:03:31 INFO - Running main action method: clobber 12:03:31 INFO - rmtree: /builds/slave/test/build 12:03:31 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 12:03:32 INFO - Running post-action listener: _resource_record_post_action 12:03:32 INFO - [mozharness: 2017-10-11 19:03:32.801819Z] Finished clobber step (success) 12:03:32 INFO - [mozharness: 2017-10-11 19:03:32.801918Z] Running read-buildbot-config step. 12:03:32 INFO - Running pre-action listener: _resource_record_pre_action 12:03:32 INFO - Running main action method: read_buildbot_config 12:03:32 INFO - Using buildbot properties: 12:03:32 INFO - { 12:03:32 INFO - "project": "", 12:03:32 INFO - "product": "firefox", 12:03:32 INFO - "who": "ffxbld@noreply.mozilla.org", 12:03:32 INFO - "installer_path": "public/build/target.tar.bz2", 12:03:32 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s", 12:03:32 INFO - "repository": "https://hg.mozilla.org/mozilla-central", 12:03:32 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central talos g4-stylo-disabled-e10s", 12:03:32 INFO - "stage_platform": "linux64", 12:03:32 INFO - "basedir": "/builds/slave/test", 12:03:32 INFO - "buildnumber": 77, 12:03:32 INFO - "platform": "ubuntu64_hw", 12:03:32 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/", 12:03:32 INFO - "slavebuilddir": "test", 12:03:32 INFO - "taskId": "CxYe1M0BTc-WJHwJNlWENA", 12:03:32 INFO - "branch": "mozilla-central", 12:03:32 INFO - "script_repo_revision": "production", 12:03:32 INFO - "revision": "5cc87630fff42a8cb272ec58c530ef68007ecacd", 12:03:32 INFO - "slavename": "talos-linux64-ix-045", 12:03:32 INFO - "repo_path": "mozilla-central" 12:03:32 INFO - } 12:03:32 INFO - Finding installer, test and symbols from parent task. 12:03:32 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/CxYe1M0BTc-WJHwJNlWENA'}, attempt #1 12:03:33 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/CxYe1M0BTc-WJHwJNlWENA'}, attempt #1 12:03:33 INFO - Task dependencies: XHvknNjMSeC1ZgFv1mRYbw 12:03:33 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw'}, attempt #1 12:03:34 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2 12:03:34 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.test_packages.json 12:03:34 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.crashreporter-symbols.zip 12:03:34 INFO - Running post-action listener: _resource_record_post_action 12:03:34 INFO - [mozharness: 2017-10-11 19:03:34.128472Z] Finished read-buildbot-config step (success) 12:03:34 INFO - [mozharness: 2017-10-11 19:03:34.128690Z] Running download-and-extract step. 12:03:34 INFO - Running pre-action listener: _resource_record_pre_action 12:03:34 INFO - Running main action method: download_and_extract 12:03:34 INFO - mkdir: /builds/slave/test/build/tests 12:03:34 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:34 INFO - trying https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.test_packages.json 12:03:34 INFO - Downloading https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 12:03:34 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 12:03:34 INFO - Downloaded 989 bytes. 12:03:34 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 12:03:34 INFO - Using the following test package requirements: 12:03:34 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'], 12:03:34 INFO - u'common': [u'target.common.tests.zip'], 12:03:34 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 12:03:34 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 12:03:34 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 12:03:34 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 12:03:34 INFO - u'mozbase': [u'target.common.tests.zip'], 12:03:34 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 12:03:34 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 12:03:34 INFO - u'web-platform': [u'target.common.tests.zip', 12:03:34 INFO - u'target.web-platform.tests.tar.gz'], 12:03:34 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 12:03:34 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos'] 12:03:34 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.common.tests.zip 12:03:34 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.common.tests.zip'}, attempt #1 12:03:34 INFO - Fetch https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.common.tests.zip into memory 12:03:36 INFO - Content-Length response header: 55326185 12:03:36 INFO - Bytes received: 55326185 12:03:47 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.talos.tests.zip 12:03:47 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.talos.tests.zip'}, attempt #1 12:03:47 INFO - Fetch https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.talos.tests.zip into memory 12:03:48 INFO - Content-Length response header: 18736602 12:03:48 INFO - Bytes received: 18736602 12:03:49 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:49 INFO - trying https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2 12:03:49 INFO - Downloading https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 12:03:49 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 12:03:52 INFO - Downloaded 62077077 bytes. 12:03:52 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2 12:03:52 INFO - mkdir: /builds/slave/test/properties 12:03:52 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 12:03:52 INFO - Writing to file /builds/slave/test/properties/build_url 12:03:52 INFO - Contents: 12:03:52 INFO - build_url:https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2 12:03:52 INFO - Running post-action listener: _resource_record_post_action 12:03:52 INFO - Running post-action listener: find_tests_for_verification 12:03:52 INFO - Running post-action listener: set_extra_try_arguments 12:03:52 INFO - [mozharness: 2017-10-11 19:03:52.005753Z] Finished download-and-extract step (success) 12:03:52 INFO - [mozharness: 2017-10-11 19:03:52.005849Z] Running populate-webroot step. 12:03:52 INFO - Running pre-action listener: _resource_record_pre_action 12:03:52 INFO - Running main action method: populate_webroot 12:03:52 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 12:03:52 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['tresize', 12:03:52 INFO - 'tcanvasmark']}, 12:03:52 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 12:03:52 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['dromaeo_css', 12:03:52 INFO - 'kraken']}, 12:03:52 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 12:03:52 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 12:03:52 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'tests': ['damp', 'tps']}, 12:03:52 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['damp', 'tps']}, 12:03:52 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 12:03:52 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['dromaeo_dom']}, 12:03:52 INFO - 'g4-e10s': {'tests': ['basic_compositor_video', 'glvideo']}, 12:03:52 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['basic_compositor_video', 12:03:52 INFO - 'glvideo']}, 12:03:52 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']}, 12:03:52 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['ts_paint_webext', 12:03:52 INFO - 'tp5o_webext']}, 12:03:52 INFO - 'other-e10s': {'tests': ['a11yr', 12:03:52 INFO - 'ts_paint', 12:03:52 INFO - 'tpaint', 12:03:52 INFO - 'sessionrestore', 12:03:52 INFO - 'sessionrestore_many_windows', 12:03:52 INFO - 'sessionrestore_no_auto_restore', 12:03:52 INFO - 'tabpaint', 12:03:52 INFO - 'cpstartup']}, 12:03:52 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['a11yr', 12:03:52 INFO - 'ts_paint', 12:03:52 INFO - 'tpaint', 12:03:52 INFO - 'sessionrestore', 12:03:52 INFO - 'sessionrestore_many_windows', 12:03:52 INFO - 'sessionrestore_no_auto_restore', 12:03:52 INFO - 'tabpaint', 12:03:52 INFO - 'cpstartup']}, 12:03:52 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']}, 12:03:52 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']}, 12:03:52 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['perf_reftest_singletons']}, 12:03:52 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['perf_reftest']}, 12:03:52 INFO - 'speedometer-e10s': {'tests': ['speedometer']}, 12:03:52 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['speedometer']}, 12:03:52 INFO - 'svgr-e10s': {'tests': ['tsvgx', 12:03:52 INFO - 'tsvgr_opacity', 12:03:52 INFO - 'tart', 12:03:52 INFO - 'tscrollx', 12:03:52 INFO - 'tsvg_static']}, 12:03:52 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['tsvgx', 12:03:52 INFO - 'tsvgr_opacity', 12:03:52 INFO - 'tart', 12:03:52 INFO - 'tscrollx', 12:03:52 INFO - 'tsvg_static']}, 12:03:52 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 12:03:52 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'talos_options': ['--disable-stylo'], 12:03:52 INFO - 'tests': ['tp5o']}, 12:03:52 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 12:03:52 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 12:03:52 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 12:03:52 INFO - 'talos_options': ['--mitmproxy', 12:03:52 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 12:03:52 INFO - '--firstNonBlankPaint'], 12:03:52 INFO - 'tests': ['tp6_google', 12:03:52 INFO - 'tp6_youtube', 12:03:52 INFO - 'tp6_amazon', 12:03:52 INFO - 'tp6_facebook']}, 12:03:52 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 12:03:52 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 12:03:52 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 12:03:52 INFO - 'talos_options': ['--disable-stylo', 12:03:52 INFO - '--mitmproxy', 12:03:52 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 12:03:52 INFO - '--firstNonBlankPaint'], 12:03:52 INFO - 'tests': ['tp6_google', 12:03:52 INFO - 'tp6_youtube', 12:03:52 INFO - 'tp6_amazon', 12:03:52 INFO - 'tp6_facebook']}, 12:03:52 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip', 12:03:52 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz', 12:03:52 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz', 12:03:52 INFO - 'talos_options': ['--stylo-threads=1', 12:03:52 INFO - '--mitmproxy', 12:03:52 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp', 12:03:52 INFO - '--firstNonBlankPaint'], 12:03:52 INFO - 'tests': ['tp6_google', 12:03:52 INFO - 'tp6_youtube', 12:03:52 INFO - 'tp6_amazon', 12:03:52 INFO - 'tp6_facebook']}, 12:03:52 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'talos_options': ['--xperf_path', 12:03:52 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 12:03:52 INFO - 'tests': ['tp5n']}, 12:03:52 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip', 12:03:52 INFO - 'talos_options': ['--disable-stylo', 12:03:52 INFO - '--xperf_path', 12:03:52 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 12:03:52 INFO - 'tests': ['tp5n']}}} 12:03:52 INFO - Running post-action listener: _resource_record_post_action 12:03:52 INFO - [mozharness: 2017-10-11 19:03:52.022561Z] Finished populate-webroot step (success) 12:03:52 INFO - [mozharness: 2017-10-11 19:03:52.022651Z] Running create-virtualenv step. 12:03:52 INFO - Running pre-action listener: _resource_record_pre_action 12:03:52 INFO - Running main action method: create_virtualenv 12:03:52 INFO - Creating virtualenv /builds/slave/test/build/venv 12:03:52 INFO - Running command: ['virtualenv', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 12:03:52 INFO - Copy/paste: virtualenv --no-site-packages --distribute /builds/slave/test/build/venv 12:03:52 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 12:03:52 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 12:03:52 INFO - New python executable in /builds/slave/test/build/venv/bin/python 12:03:52 INFO - Installing distribute.............................................................................................................................................................................................done. 12:03:52 INFO - Installing pip...............done. 12:03:52 INFO - Return code: 0 12:03:52 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 12:03:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 12:03:52 INFO - Reading from file tmpfile_stdout 12:03:52 INFO - Output received: 12:03:53 INFO - pip 1.1 from /builds/slave/test/build/venv/lib/python2.7/site-packages/pip-1.1-py2.7.egg (python 2.7) 12:03:53 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 12:03:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:53 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:03:53 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:53 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:03:53 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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:03:53 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 12:03:53 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 12:03:53 INFO - Using env: {'DISPLAY': ':0', 12:03:53 INFO - 'HOME': '/home/cltbld', 12:03:53 INFO - 'LANG': 'en_US.UTF-8', 12:03:53 INFO - 'LANGUAGE': 'en_US:en', 12:03:53 INFO - 'LOGNAME': 'cltbld', 12:03:53 INFO - 'MAIL': '/var/mail/cltbld', 12:03:53 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:03:53 INFO - 'MOZ_NO_REMOTE': '1', 12:03:53 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:03:53 INFO - 'NO_EM_RESTART': '1', 12:03:53 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:03:53 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:03:53 INFO - 'PWD': '/builds/slave/test', 12:03:53 INFO - 'SHELL': '/bin/bash', 12:03:53 INFO - 'SHLVL': '1', 12:03:53 INFO - 'TERM': 'linux', 12:03:53 INFO - 'TMOUT': '86400', 12:03:53 INFO - 'USER': 'cltbld', 12:03:53 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:03:53 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:03:53 INFO - '_': '/tools/buildbot/bin/python'} 12:03:55 INFO - Ignoring indexes: http://pypi.python.org/simple/ 12:03:55 INFO - Downloading/unpacking pip>=1.5 12:03:55 INFO - Running setup.py egg_info for package pip 12:03:55 INFO - warning: no files found matching 'pip/cacert.pem' 12:03:55 INFO - warning: no files found matching '*.html' under directory 'docs' 12:03:55 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 12:03:55 INFO - no previously-included directories found matching 'docs/_build/_sources' 12:03:55 INFO - Installing collected packages: pip 12:03:55 INFO - Found existing installation: pip 1.1 12:03:55 INFO - Uninstalling pip: 12:03:55 INFO - Successfully uninstalled pip 12:03:55 INFO - Running setup.py install for pip 12:03:55 INFO - warning: no files found matching 'pip/cacert.pem' 12:03:55 INFO - warning: no files found matching '*.html' under directory 'docs' 12:03:55 INFO - warning: no previously-included files matching '*.rst' found under directory 'docs/_build' 12:03:55 INFO - no previously-included directories found matching 'docs/_build/_sources' 12:03:55 INFO - Installing pip script to /builds/slave/test/build/venv/bin 12:03:55 INFO - Installing pip2.7 script to /builds/slave/test/build/venv/bin 12:03:55 INFO - Installing pip2 script to /builds/slave/test/build/venv/bin 12:03:55 INFO - Successfully installed pip 12:03:55 INFO - Cleaning up... 12:03:55 INFO - Return code: 0 12:03:55 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 12:03:55 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:55 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:03:55 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:55 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:03:55 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:03:55 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1'] in /builds/slave/test/build 12:03:55 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=3.1.1 12:03:55 INFO - Using env: {'DISPLAY': ':0', 12:03:55 INFO - 'HOME': '/home/cltbld', 12:03:55 INFO - 'LANG': 'en_US.UTF-8', 12:03:55 INFO - 'LANGUAGE': 'en_US:en', 12:03:55 INFO - 'LOGNAME': 'cltbld', 12:03:55 INFO - 'MAIL': '/var/mail/cltbld', 12:03:55 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:03:55 INFO - 'MOZ_NO_REMOTE': '1', 12:03:55 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:03:55 INFO - 'NO_EM_RESTART': '1', 12:03:55 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:03:55 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:03:55 INFO - 'PWD': '/builds/slave/test', 12:03:55 INFO - 'SHELL': '/bin/bash', 12:03:55 INFO - 'SHLVL': '1', 12:03:55 INFO - 'TERM': 'linux', 12:03:55 INFO - 'TMOUT': '86400', 12:03:55 INFO - 'USER': 'cltbld', 12:03:55 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:03:55 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:03:55 INFO - '_': '/tools/buildbot/bin/python'} 12:03:55 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:03:55 INFO - Downloading/unpacking psutil>=3.1.1 12:03:55 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 12:03:55 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 12:03:55 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 12:03:55 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 12:03:56 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 12:03:56 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 12:03:56 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 12:03:56 INFO - Installing collected packages: psutil 12:03:56 INFO - Running setup.py install for psutil 12:03:56 INFO - building 'psutil._psutil_linux' extension 12:03:56 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 12:03:56 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 12:03:56 INFO - building 'psutil._psutil_posix' extension 12:03:56 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 12:03:57 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 12:03:57 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 12:03:57 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 12:03:57 INFO - Successfully installed psutil 12:03:57 INFO - Cleaning up... 12:03:57 INFO - Return code: 0 12:03:57 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 12:03:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:57 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:03:57 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:57 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:03:57 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:03:57 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 12:03:57 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.3 12:03:57 INFO - Using env: {'DISPLAY': ':0', 12:03:57 INFO - 'HOME': '/home/cltbld', 12:03:57 INFO - 'LANG': 'en_US.UTF-8', 12:03:57 INFO - 'LANGUAGE': 'en_US:en', 12:03:57 INFO - 'LOGNAME': 'cltbld', 12:03:57 INFO - 'MAIL': '/var/mail/cltbld', 12:03:57 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:03:57 INFO - 'MOZ_NO_REMOTE': '1', 12:03:57 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:03:57 INFO - 'NO_EM_RESTART': '1', 12:03:57 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:03:57 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:03:57 INFO - 'PWD': '/builds/slave/test', 12:03:57 INFO - 'SHELL': '/bin/bash', 12:03:57 INFO - 'SHLVL': '1', 12:03:57 INFO - 'TERM': 'linux', 12:03:57 INFO - 'TMOUT': '86400', 12:03:57 INFO - 'USER': 'cltbld', 12:03:57 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:03:57 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:03:57 INFO - '_': '/tools/buildbot/bin/python'} 12:03:58 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:03:58 INFO - Downloading/unpacking mozsystemmonitor==0.3 12:03:58 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 12:03:58 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 12:03:58 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 12:03:58 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 12:03:59 INFO - Downloading mozsystemmonitor-0.3.tar.gz 12:03:59 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 12:03:59 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 12:03:59 INFO - Installing collected packages: mozsystemmonitor 12:03:59 INFO - Running setup.py install for mozsystemmonitor 12:03:59 INFO - Successfully installed mozsystemmonitor 12:03:59 INFO - Cleaning up... 12:03:59 INFO - Return code: 0 12:03:59 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 12:03:59 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:59 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:03:59 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:03:59 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:03:59 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:03:59 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1'] in /builds/slave/test/build 12:03:59 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema==2.5.1 12:03:59 INFO - Using env: {'DISPLAY': ':0', 12:03:59 INFO - 'HOME': '/home/cltbld', 12:03:59 INFO - 'LANG': 'en_US.UTF-8', 12:03:59 INFO - 'LANGUAGE': 'en_US:en', 12:03:59 INFO - 'LOGNAME': 'cltbld', 12:03:59 INFO - 'MAIL': '/var/mail/cltbld', 12:03:59 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:03:59 INFO - 'MOZ_NO_REMOTE': '1', 12:03:59 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:03:59 INFO - 'NO_EM_RESTART': '1', 12:03:59 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:03:59 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:03:59 INFO - 'PWD': '/builds/slave/test', 12:03:59 INFO - 'SHELL': '/bin/bash', 12:03:59 INFO - 'SHLVL': '1', 12:03:59 INFO - 'TERM': 'linux', 12:03:59 INFO - 'TMOUT': '86400', 12:03:59 INFO - 'USER': 'cltbld', 12:03:59 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:03:59 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:03:59 INFO - '_': '/tools/buildbot/bin/python'} 12:03:59 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:03:59 INFO - Downloading/unpacking jsonschema==2.5.1 12:03:59 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 12:03:59 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 12:03:59 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 12:03:59 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 12:04:00 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 12:04:00 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 12:04:00 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 12:04:00 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 12:04:00 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 12:04:00 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 12:04:00 INFO - Downloading functools32-3.2.3-2.tar.gz 12:04:00 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 12:04:00 INFO - warning: no files found matching '*.txt' 12:04:00 INFO - no previously-included directories found matching 'build' 12:04:00 INFO - no previously-included directories found matching 'dist' 12:04:00 INFO - no previously-included directories found matching '.git*' 12:04:00 INFO - Installing collected packages: jsonschema, functools32 12:04:01 INFO - Running setup.py install for functools32 12:04:01 INFO - warning: no files found matching '*.txt' 12:04:01 INFO - no previously-included directories found matching 'build' 12:04:01 INFO - no previously-included directories found matching 'dist' 12:04:01 INFO - no previously-included directories found matching '.git*' 12:04:01 INFO - Successfully installed jsonschema functools32 12:04:01 INFO - Cleaning up... 12:04:01 INFO - Return code: 0 12:04:01 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 12:04:01 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:04:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:04:01 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:04:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:04:01 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:04:01 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'functools32==3.2.3-2'] in /builds/slave/test/build 12:04:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub functools32==3.2.3-2 12:04:01 INFO - Using env: {'DISPLAY': ':0', 12:04:01 INFO - 'HOME': '/home/cltbld', 12:04:01 INFO - 'LANG': 'en_US.UTF-8', 12:04:01 INFO - 'LANGUAGE': 'en_US:en', 12:04:01 INFO - 'LOGNAME': 'cltbld', 12:04:01 INFO - 'MAIL': '/var/mail/cltbld', 12:04:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:01 INFO - 'MOZ_NO_REMOTE': '1', 12:04:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:01 INFO - 'NO_EM_RESTART': '1', 12:04:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:01 INFO - 'PWD': '/builds/slave/test', 12:04:01 INFO - 'SHELL': '/bin/bash', 12:04:01 INFO - 'SHLVL': '1', 12:04:01 INFO - 'TERM': 'linux', 12:04:01 INFO - 'TMOUT': '86400', 12:04:01 INFO - 'USER': 'cltbld', 12:04:01 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:01 INFO - '_': '/tools/buildbot/bin/python'} 12:04:01 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:04:01 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 12:04:01 INFO - Cleaning up... 12:04:01 INFO - Return code: 0 12:04:01 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 12:04:01 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:04:01 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:04:01 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:04:01 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:04:01 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:04:01 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 12:04:01 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 12:04:01 INFO - Using env: {'DISPLAY': ':0', 12:04:01 INFO - 'HOME': '/home/cltbld', 12:04:01 INFO - 'LANG': 'en_US.UTF-8', 12:04:01 INFO - 'LANGUAGE': 'en_US:en', 12:04:01 INFO - 'LOGNAME': 'cltbld', 12:04:01 INFO - 'MAIL': '/var/mail/cltbld', 12:04:01 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:01 INFO - 'MOZ_NO_REMOTE': '1', 12:04:01 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:01 INFO - 'NO_EM_RESTART': '1', 12:04:01 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:01 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:01 INFO - 'PWD': '/builds/slave/test', 12:04:01 INFO - 'SHELL': '/bin/bash', 12:04:01 INFO - 'SHLVL': '1', 12:04:01 INFO - 'TERM': 'linux', 12:04:01 INFO - 'TMOUT': '86400', 12:04:01 INFO - 'USER': 'cltbld', 12:04:01 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:01 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:01 INFO - '_': '/tools/buildbot/bin/python'} 12:04:01 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:04:01 INFO - Downloading/unpacking blobuploader==1.2.4 12:04:01 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 12:04:01 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 12:04:01 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 12:04:01 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 12:04:02 INFO - Downloading blobuploader-1.2.4.tar.gz 12:04:02 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 12:04:02 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 12:04:02 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 12:04:02 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 12:04:02 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 12:04:02 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 12:04:02 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 12:04:03 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 12:04:03 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 12:04:03 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 12:04:03 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 12:04:03 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 12:04:03 INFO - Downloading docopt-0.6.1.tar.gz 12:04:03 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 12:04:03 INFO - Installing collected packages: blobuploader, requests, docopt 12:04:03 INFO - Running setup.py install for blobuploader 12:04:03 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 12:04:03 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 12:04:03 INFO - Running setup.py install for requests 12:04:03 INFO - Running setup.py install for docopt 12:04:03 INFO - Successfully installed blobuploader requests docopt 12:04:03 INFO - Cleaning up... 12:04:03 INFO - Return code: 0 12:04:03 INFO - Installing None into virtualenv /builds/slave/test/build/venv 12:04: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')]} 12:04:03 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:04: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')]} 12:04:03 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:04:03 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:04:03 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 12:04:03 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 12:04:03 INFO - Using env: {'DISPLAY': ':0', 12:04:03 INFO - 'HOME': '/home/cltbld', 12:04:03 INFO - 'LANG': 'en_US.UTF-8', 12:04:03 INFO - 'LANGUAGE': 'en_US:en', 12:04:03 INFO - 'LOGNAME': 'cltbld', 12:04:03 INFO - 'MAIL': '/var/mail/cltbld', 12:04:03 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:03 INFO - 'MOZ_NO_REMOTE': '1', 12:04:03 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:03 INFO - 'NO_EM_RESTART': '1', 12:04:03 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:03 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:03 INFO - 'PWD': '/builds/slave/test', 12:04:03 INFO - 'SHELL': '/bin/bash', 12:04:03 INFO - 'SHLVL': '1', 12:04:03 INFO - 'TERM': 'linux', 12:04:03 INFO - 'TMOUT': '86400', 12:04:03 INFO - 'USER': 'cltbld', 12:04:03 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:03 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:03 INFO - '_': '/tools/buildbot/bin/python'} 12:04:04 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 12:04:04 INFO - Running setup.py (path:/tmp/pip-Cg5lEj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 12:04:04 INFO - Running setup.py (path:/tmp/pip-UPclUH-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 12:04:04 INFO - Running setup.py (path:/tmp/pip-T1beuf-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 12:04:04 INFO - Running setup.py (path:/tmp/pip-lI0cn_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 12:04:04 INFO - Running setup.py (path:/tmp/pip-bhpVZL-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 12:04:04 INFO - Running setup.py (path:/tmp/pip-XxfkOz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 12:04:04 INFO - Running setup.py (path:/tmp/pip-tqZLyw-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 12:04:04 INFO - Running setup.py (path:/tmp/pip-2dU8X4-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 12:04:04 INFO - Running setup.py (path:/tmp/pip-PydFUA-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 12:04:04 INFO - Running setup.py (path:/tmp/pip-9cI3HP-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 12:04:04 INFO - Running setup.py (path:/tmp/pip-kaLpyR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 12:04:04 INFO - Running setup.py (path:/tmp/pip-0BpAy1-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 12:04:04 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 12:04:04 INFO - Running setup.py (path:/tmp/pip-RP006g-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 12:04:05 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 12:04:05 INFO - Running setup.py (path:/tmp/pip-fUgP9K-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 12:04:05 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 12:04:05 INFO - Running setup.py (path:/tmp/pip-oerzBh-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 12:04:05 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 12:04:05 INFO - Running setup.py (path:/tmp/pip-7n9kqj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 12:04:05 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 12:04:05 INFO - Running setup.py (path:/tmp/pip-Dd3U2D-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 12:04:05 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 12:04:05 INFO - Running setup.py install for manifestparser 12:04:05 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 12:04:05 INFO - Running setup.py install for mozcrash 12:04:05 INFO - Running setup.py install for mozdebug 12:04:05 INFO - Running setup.py install for mozdevice 12:04:05 INFO - Installing dm script to /builds/slave/test/build/venv/bin 12:04:05 INFO - Running setup.py install for mozfile 12:04:05 INFO - Running setup.py install for mozhttpd 12:04:05 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 12:04:05 INFO - Running setup.py install for mozinfo 12:04:06 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Running setup.py install for mozInstall 12:04:06 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Running setup.py install for mozleak 12:04:06 INFO - Running setup.py install for mozlog 12:04:06 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Running setup.py install for moznetwork 12:04:06 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Running setup.py install for mozprocess 12:04:06 INFO - Running setup.py install for mozprofile 12:04:06 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Running setup.py install for mozrunner 12:04:06 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 12:04:06 INFO - Running setup.py install for mozscreenshot 12:04:06 INFO - Running setup.py install for moztest 12:04:06 INFO - Running setup.py install for mozversion 12:04:07 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 12:04:07 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 12:04:07 INFO - Cleaning up... 12:04:07 INFO - Return code: 0 12:04:07 INFO - Installing None into virtualenv /builds/slave/test/build/venv 12:04:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:04:07 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:04:07 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:04:07 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:04:07 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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:04:07 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 12:04:07 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 12:04:07 INFO - Using env: {'DISPLAY': ':0', 12:04:07 INFO - 'HOME': '/home/cltbld', 12:04:07 INFO - 'LANG': 'en_US.UTF-8', 12:04:07 INFO - 'LANGUAGE': 'en_US:en', 12:04:07 INFO - 'LOGNAME': 'cltbld', 12:04:07 INFO - 'MAIL': '/var/mail/cltbld', 12:04:07 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:07 INFO - 'MOZ_NO_REMOTE': '1', 12:04:07 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:07 INFO - 'NO_EM_RESTART': '1', 12:04:07 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:07 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:07 INFO - 'PWD': '/builds/slave/test', 12:04:07 INFO - 'SHELL': '/bin/bash', 12:04:07 INFO - 'SHLVL': '1', 12:04:07 INFO - 'TERM': 'linux', 12:04:07 INFO - 'TMOUT': '86400', 12:04:07 INFO - 'USER': 'cltbld', 12:04:07 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:07 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:07 INFO - '_': '/tools/buildbot/bin/python'} 12:04:07 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 12:04:07 INFO - Running setup.py (path:/tmp/pip-X4bdsM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 12:04:07 INFO - Running setup.py (path:/tmp/pip-Lb4fhK-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 12:04:07 INFO - Running setup.py (path:/tmp/pip-0jowVz-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 12:04:07 INFO - Running setup.py (path:/tmp/pip-u0doCn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 12:04:07 INFO - Running setup.py (path:/tmp/pip-LXm5go-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 12:04:07 INFO - Running setup.py (path:/tmp/pip-_hdzXv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 12:04:07 INFO - Running setup.py (path:/tmp/pip-89jyzI-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 12:04:07 INFO - Running setup.py (path:/tmp/pip-8bdnpk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 12:04:07 INFO - Running setup.py (path:/tmp/pip-AMp9H6-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 12:04:07 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)) 12:04:07 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 12:04:07 INFO - Running setup.py (path:/tmp/pip-UPWA75-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 12:04:08 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)) 12:04:08 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 12:04:08 INFO - Running setup.py (path:/tmp/pip-UFt2KS-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 12:04:08 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)) 12:04:08 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 12:04:08 INFO - Running setup.py (path:/tmp/pip-b0Vqsn-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 12:04:08 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)) 12:04:08 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 12:04:08 INFO - Running setup.py (path:/tmp/pip-Bb5WjW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 12:04:08 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)) 12:04:08 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 12:04:08 INFO - Running setup.py (path:/tmp/pip-jCqyWc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 12:04:08 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)) 12:04:08 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 12:04:08 INFO - Running setup.py (path:/tmp/pip-IxGpdB-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 12:04:08 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)) 12:04:08 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 12:04:08 INFO - Running setup.py (path:/tmp/pip-jFj3tW-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 12:04:08 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)) 12:04:08 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 12:04:08 INFO - Running setup.py (path:/tmp/pip-lIwhn_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 12:04:08 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)) 12:04:08 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)) 12:04:08 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)) 12:04:08 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)) 12:04:08 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)) 12:04:08 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)) 12:04:08 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)) 12:04:08 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 12:04:08 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 12:04:08 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 12:04:08 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 12:04:08 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 12:04:09 INFO - Downloading blessings-1.6.tar.gz 12:04:09 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 12:04:09 INFO - Installing collected packages: blessings 12:04:09 INFO - Running setup.py install for blessings 12:04:09 INFO - Successfully installed blessings 12:04:09 INFO - Cleaning up... 12:04:09 INFO - Return code: 0 12:04:09 INFO - Done creating virtualenv /builds/slave/test/build/venv. 12:04:09 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 12:04:09 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 12:04:10 INFO - Reading from file tmpfile_stdout 12:04:10 INFO - Current package versions: 12:04:10 INFO - argparse == 1.2.1 12:04:10 INFO - blessings == 1.6 12:04:10 INFO - blobuploader == 1.2.4 12:04:10 INFO - docopt == 0.6.1 12:04:10 INFO - functools32 == 3.2.3-2 12:04:10 INFO - jsonschema == 2.5.1 12:04:10 INFO - manifestparser == 1.1 12:04:10 INFO - mozInstall == 1.13 12:04:10 INFO - mozcrash == 1.0 12:04:10 INFO - mozdebug == 0.1 12:04:10 INFO - mozdevice == 0.51 12:04:10 INFO - mozfile == 1.2 12:04:10 INFO - mozhttpd == 0.7 12:04:10 INFO - mozinfo == 0.10 12:04:10 INFO - mozleak == 0.1 12:04:10 INFO - mozlog == 3.5 12:04:10 INFO - moznetwork == 0.27 12:04:10 INFO - mozprocess == 0.25 12:04:10 INFO - mozprofile == 0.28 12:04:10 INFO - mozrunner == 6.13 12:04:10 INFO - mozscreenshot == 0.1 12:04:10 INFO - mozsystemmonitor == 0.3 12:04:10 INFO - moztest == 0.8 12:04:10 INFO - mozversion == 1.4 12:04:10 INFO - psutil == 3.1.1 12:04:10 INFO - requests == 1.2.3 12:04:10 INFO - wsgiref == 0.1.2 12:04:10 INFO - Installing None into virtualenv /builds/slave/test/build/venv 12:04: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')]} 12:04:10 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:04: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')]} 12:04:10 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:04:10 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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:04:10 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 12:04:10 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 12:04:10 INFO - Using env: {'DISPLAY': ':0', 12:04:10 INFO - 'HOME': '/home/cltbld', 12:04:10 INFO - 'LANG': 'en_US.UTF-8', 12:04:10 INFO - 'LANGUAGE': 'en_US:en', 12:04:10 INFO - 'LOGNAME': 'cltbld', 12:04:10 INFO - 'MAIL': '/var/mail/cltbld', 12:04:10 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:10 INFO - 'MOZ_NO_REMOTE': '1', 12:04:10 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:10 INFO - 'NO_EM_RESTART': '1', 12:04:10 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:10 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:10 INFO - 'PWD': '/builds/slave/test', 12:04:10 INFO - 'SHELL': '/bin/bash', 12:04:10 INFO - 'SHLVL': '1', 12:04:10 INFO - 'TERM': 'linux', 12:04:10 INFO - 'TMOUT': '86400', 12:04:10 INFO - 'USER': 'cltbld', 12:04:10 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:10 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:10 INFO - '_': '/tools/buildbot/bin/python'} 12:04:10 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:04:10 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)) 12:04:10 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)) 12:04:10 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)) 12:04:10 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)) 12:04:10 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)) 12:04:10 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)) 12:04:10 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)) 12:04:10 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)) 12:04:10 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)) 12:04:10 INFO - Downloading/unpacking simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10)) 12:04:10 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 12:04:10 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 12:04:10 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 12:04:10 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 12:04:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/simplejson/setup.py) egg_info for package simplejson 12:04:11 INFO - Downloading/unpacking requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11)) 12:04: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 12:04: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 12:04: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 12:04: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 12:04:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 12:04:11 INFO - warning: no files found matching 'test_requests.py' 12:04:11 INFO - warning: no files found matching 'requirements.txt' 12:04:11 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)) 12:04:11 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)) 12:04:11 INFO - Installing collected packages: simplejson, requests 12:04:11 INFO - Running setup.py install for simplejson 12:04:11 INFO - building 'simplejson._speedups' extension 12:04:11 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 12:04:12 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 12:04:12 INFO - Found existing installation: requests 1.2.3 12:04:12 INFO - Uninstalling requests: 12:04:12 INFO - Successfully uninstalled requests 12:04:12 INFO - Running setup.py install for requests 12:04:12 INFO - warning: no files found matching 'test_requests.py' 12:04:12 INFO - warning: no files found matching 'requirements.txt' 12:04:13 INFO - Successfully installed simplejson requests 12:04:13 INFO - Cleaning up... 12:04:13 INFO - Return code: 0 12:04:13 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 12:04:13 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')]} 12:04:13 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 12:04:13 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')]} 12:04:13 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 12:04:13 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 0x1f3f1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2108a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x22accc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, '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': '4300f881736b422476174874000001bc-1507748608.868977-205121776', '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 12:04:13 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 12:04:13 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 12:04:13 INFO - Using env: {'DISPLAY': ':0', 12:04:13 INFO - 'HOME': '/home/cltbld', 12:04:13 INFO - 'LANG': 'en_US.UTF-8', 12:04:13 INFO - 'LANGUAGE': 'en_US:en', 12:04:13 INFO - 'LOGNAME': 'cltbld', 12:04:13 INFO - 'MAIL': '/var/mail/cltbld', 12:04:13 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:13 INFO - 'MOZ_NO_REMOTE': '1', 12:04:13 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:13 INFO - 'NO_EM_RESTART': '1', 12:04:13 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:13 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:13 INFO - 'PWD': '/builds/slave/test', 12:04:13 INFO - 'SHELL': '/bin/bash', 12:04:13 INFO - 'SHLVL': '1', 12:04:13 INFO - 'TERM': 'linux', 12:04:13 INFO - 'TMOUT': '86400', 12:04:13 INFO - 'USER': 'cltbld', 12:04:13 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:13 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:13 INFO - '_': '/tools/buildbot/bin/python'} 12:04:13 INFO - Ignoring indexes: https://pypi.python.org/simple/ 12:04:13 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 12:04:13 INFO - Cleaning up... 12:04:13 INFO - Return code: 0 12:04:13 INFO - Running post-action listener: _resource_record_post_action 12:04:13 INFO - Running post-action listener: _start_resource_monitoring 12:04:13 INFO - Starting resource monitoring. 12:04:13 INFO - [mozharness: 2017-10-11 19:04:13.591865Z] Finished create-virtualenv step (success) 12:04:13 INFO - [mozharness: 2017-10-11 19:04:13.592382Z] Running install step. 12:04:13 INFO - Running pre-action listener: _resource_record_pre_action 12:04:13 INFO - Running main action method: install 12:04:13 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 12:04:13 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 12:04:13 INFO - Reading from file tmpfile_stdout 12:04:13 INFO - Detecting whether we're running mozinstall >=1.0... 12:04:13 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 12:04:13 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 12:04:13 INFO - Reading from file tmpfile_stdout 12:04:13 INFO - Output received: 12:04:13 INFO - Usage: mozinstall [options] installer 12:04:13 INFO - Options: 12:04:13 INFO - -h, --help show this help message and exit 12:04:13 INFO - -d DEST, --destination=DEST 12:04:13 INFO - Directory to install application into. [default: 12:04:13 INFO - "/builds/slave/test"] 12:04:13 INFO - --app=APP Application being installed. [default: firefox] 12:04:13 INFO - mkdir: /builds/slave/test/build/application 12:04:13 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'] 12:04:13 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 12:04:31 INFO - Reading from file tmpfile_stdout 12:04:31 INFO - Output received: 12:04:31 INFO - /builds/slave/test/build/application/firefox/firefox 12:04:31 INFO - Running post-action listener: _resource_record_post_action 12:04:31 INFO - [mozharness: 2017-10-11 19:04:31.904854Z] Finished install step (success) 12:04:31 INFO - [mozharness: 2017-10-11 19:04:31.905109Z] Running setup-mitmproxy step. 12:04:31 INFO - Running pre-action listener: _resource_record_pre_action 12:04:31 INFO - Running main action method: setup_mitmproxy 12:04:31 INFO - Skipping: mitmproxy is not required 12:04:31 INFO - Running post-action listener: _resource_record_post_action 12:04:31 INFO - [mozharness: 2017-10-11 19:04:31.906251Z] Finished setup-mitmproxy step (success) 12:04:31 INFO - [mozharness: 2017-10-11 19:04:31.906488Z] Running run-tests step. 12:04:31 INFO - Running pre-action listener: _resource_record_pre_action 12:04:31 INFO - Running pre-action listener: _set_gcov_prefix 12:04:31 INFO - Running main action method: run_tests 12:04:31 WARNING - Try message not found. 12:04:31 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 12:04:31 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 12:04:31 INFO - Python 2.7.3 12:04:31 INFO - Return code: 0 12:04:31 INFO - grabbing minidump binary from tooltool 12:04:31 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 12:04:31 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 0x22a9e60>, '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 0x22aad60>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x22ab1f0>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 12:04:31 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 12:04:31 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 12:04:31 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 12:04:31 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 12:04:32 INFO - Return code: 0 12:04:32 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 12:04:32 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 12:04:32 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 12:04:32 INFO - ENV: RUST_BACKTRACE is now full 12:04:32 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 12:04:32 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 12:04:32 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox-Non-PGO', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] in /builds/slave/test/build 12:04:32 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox-Non-PGO --suite g4-stylo-disabled-e10s --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-045 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log 12:04:32 INFO - Using env: {'DISPLAY': ':0', 12:04:32 INFO - 'HOME': '/home/cltbld', 12:04:32 INFO - 'LANG': 'en_US.UTF-8', 12:04:32 INFO - 'LANGUAGE': 'en_US:en', 12:04:32 INFO - 'LOGNAME': 'cltbld', 12:04:32 INFO - 'MAIL': '/var/mail/cltbld', 12:04:32 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 12:04:32 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 12:04:32 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:32 INFO - 'MOZ_NO_REMOTE': '1', 12:04:32 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 12:04:32 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:32 INFO - 'NO_EM_RESTART': '1', 12:04:32 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:32 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:32 INFO - 'PWD': '/builds/slave/test', 12:04:32 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 12:04:32 INFO - 'RUST_BACKTRACE': 'full', 12:04:32 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 12:04:32 INFO - 'SHELL': '/bin/bash', 12:04:32 INFO - 'SHLVL': '1', 12:04:32 INFO - 'TERM': 'linux', 12:04:32 INFO - 'TMOUT': '86400', 12:04:32 INFO - 'USER': 'cltbld', 12:04:32 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:32 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:32 INFO - '_': '/tools/buildbot/bin/python'} 12:04:32 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox-Non-PGO', '--suite', 'g4-stylo-disabled-e10s', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-045', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] with output_timeout 3600 12:04:32 INFO - mozversion application_buildid: 20171011180513 12:04:32 INFO - mozversion application_changeset: 5cc87630fff42a8cb272ec58c530ef68007ecacd 12:04:32 INFO - mozversion application_display_name: Nightly 12:04:32 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 12:04:32 INFO - mozversion application_name: Firefox 12:04:32 INFO - mozversion application_remotingname: firefox 12:04:32 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 12:04:32 INFO - mozversion application_vendor: Mozilla 12:04:32 INFO - mozversion application_version: 58.0a1 12:04:32 INFO - mozversion platform_buildid: 20171011180513 12:04:32 INFO - mozversion platform_changeset: 5cc87630fff42a8cb272ec58c530ef68007ecacd 12:04:32 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 12:04:32 INFO - mozversion platform_version: 58.0a1 12:04:32 INFO - using testdate: 1507748672 12:04:32 INFO - actual date: 1507748672 12:04:32 INFO - starting webserver on 'localhost:59872' 12:04:32 INFO - SUITE-START | Running 2 tests 12:04:32 INFO - TEST-START | basic_compositor_video 12:04:32 INFO - Initialising browser for basic_compositor_video test... 12:04:32 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:59872/getInfo.html -profile /tmp/tmpdgatGd/profile 12:04:32 INFO - TEST-INFO | started process 19664 (/builds/slave/test/build/application/firefox/firefox http://localhost:59872/getInfo.html) 12:04:37 INFO - TEST-INFO | 19664: exit 0 12:04:37 INFO - Browser initialized. 12:04:37 INFO - Running cycle 1/1 for basic_compositor_video test... 12:04:37 INFO - Using env: {'DISPLAY': ':0', 12:04:37 INFO - 'HOME': '/home/cltbld', 12:04:37 INFO - 'JSGC_DISABLE_POISONING': '1', 12:04:37 INFO - 'LANG': 'en_US.UTF-8', 12:04:37 INFO - 'LANGUAGE': 'en_US:en', 12:04:37 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 12:04:37 INFO - 'LOGNAME': 'cltbld', 12:04:37 INFO - 'MAIL': '/var/mail/cltbld', 12:04:37 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 12:04:37 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 12:04:37 INFO - 'MOZ_CRASHREPORTER': '1', 12:04:37 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:04:37 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 12:04:37 INFO - 'MOZ_NO_REMOTE': '1', 12:04:37 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 12:04:37 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:04:37 INFO - 'NO_EM_RESTART': '1', 12:04:37 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:04:37 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:04:37 INFO - 'PWD': '/builds/slave/test', 12:04:37 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 12:04:37 INFO - 'RUST_BACKTRACE': 'full', 12:04:37 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 12:04:37 INFO - 'SHELL': '/bin/bash', 12:04:37 INFO - 'SHLVL': '1', 12:04:37 INFO - 'STYLO_FORCE_DISABLED': '1', 12:04:37 INFO - 'TERM': 'linux', 12:04:37 INFO - 'TMOUT': '86400', 12:04:37 INFO - 'USER': 'cltbld', 12:04:37 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:04:37 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:04:37 INFO - '_': '/tools/buildbot/bin/python'} 12:04:37 INFO - TEST-INFO | started process 19934 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpdgatGd/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12) 12:04:38 INFO - PID 19934 | 12:04:38 INFO - PID 19934 | (/builds/slave/test/build/application/firefox/firefox:19982): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 12:04:38 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6818301569506728 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6724540133779264 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.72458908045977 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.699745114698386 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.09993169398907 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.194633123689727 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.606772836538463 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.497744755244754 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.629268292682929 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.51203856749311 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.968637873754146 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.806299019607845 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.237602996254676 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.871086956521733 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.297131147540984 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.90898809523809 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.631046511627899 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.050000000000017 ms/frame 12:05:24 INFO - PID 19934 | 12:05:24 INFO - PID 19934 | Cycle 1(1): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:06:11 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6808655462184876 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.669970784641068 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7442848837209304 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7198151332760099 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.0069225634178895 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.041222222222223 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.4726041666666685 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4023979591836744 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.6515254237288115 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.378400537634407 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.772817589576551 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.620624999999983 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.32141509433962 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.87173913043479 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.502895833333332 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.979491017964055 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.539730769230747 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.305225988700574 ms/frame 12:06:11 INFO - PID 19934 | 12:06:11 INFO - PID 19934 | Cycle 1(2): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:06:57 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6849354295339696 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6757663316582916 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.767052414605418 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.724922413793104 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.077058423913043 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.058894523326572 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.505029205607479 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4249571917808206 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.546284658040667 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.451267029972756 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.647041800643086 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 10.005349999999998 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.40720532319392 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.930355191256817 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.556213389121329 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.770558823529427 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.36556818181819 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.05149171270718 ms/frame 12:06:57 INFO - PID 19934 | 12:06:57 INFO - PID 19934 | Cycle 1(3): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:07:43 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6818021300448431 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6752386934673364 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7244913793103447 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6958389830508476 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.13848275862069 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.202636554621849 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.5263337250293794 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4792956521739087 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.6084953271028075 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.58705307262569 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.935033112582785 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.760414634146334 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.630135658914746 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.992307692307683 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.401095041322323 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.199999999999973 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.631279069767423 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.11561111111114 ms/frame 12:07:43 INFO - PID 19934 | 12:07:43 INFO - PID 19934 | Cycle 1(4): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:08:29 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6867509836987071 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.672336956521739 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7712190082644625 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.723350559862188 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.172774687065367 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.115637860082306 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.42519406392694 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4190085470085516 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.649943502824857 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.652598870056498 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.804575163398695 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.093840909090911 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.154089219330858 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.872173913043456 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.295491803278683 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.76667647058823 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.540903846153855 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.23648876404495 ms/frame 12:08:29 INFO - PID 19934 | 12:08:29 INFO - PID 19934 | Cycle 1(5): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:09:15 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6800503919372902 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.668548790658882 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7205189220183486 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7043867120953995 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.110986301369864 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.969940476190477 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.4925145518044234 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.425659246575341 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.587849162011172 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.556666666666671 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 10.383442906574402 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.263634259259257 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.540423076923071 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.931912568306016 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.29823770491802 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.97856287425153 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.676050583657597 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.932322404371574 ms/frame 12:09:15 INFO - PID 19934 | 12:09:15 INFO - PID 19934 | Cycle 1(6): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:10:01 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6856685393258426 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6704048414023376 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7503150525087514 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7039991482112435 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.105451436388508 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.117129629629632 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.641237864077671 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.553134991119007 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.7154380952380945 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.466024590163931 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 10.239436860068256 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 10.001149999999997 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.28122180451128 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.81697297297297 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.400000000000013 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.977874251497008 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.495670498084273 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.055662983425439 ms/frame 12:10:01 INFO - PID 19934 | 12:10:01 INFO - PID 19934 | Cycle 1(7): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:10:48 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6866498032602586 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6712949039264833 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7428252032520322 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.702178723404255 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.088106267029973 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.058661257606491 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.5642814726840855 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5658823529411747 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.629268292682929 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.571615598885791 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.740551948051948 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.17802752293577 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.584980694980702 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.99016483516483 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.55322175732215 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 12.051777108433742 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.364374999999999 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.23662921348312 ms/frame 12:10:48 INFO - PID 19934 | 12:10:48 INFO - PID 19934 | Cycle 1(8): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:11:34 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6868100056211355 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.673966527196653 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.721514629948365 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7065315699658699 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.167847222222223 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.142049689440995 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.517860492379839 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.396816638370116 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.771403846153848 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.4646174863387955 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.55523885350319 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.524595238095243 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.279191729323307 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.700962566844929 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.346131687242801 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.834378698224864 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.364393939393928 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.75325268817206 ms/frame 12:11:34 INFO - PID 19934 | 12:11:34 INFO - PID 19934 | Cycle 1(9): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:12:20 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6886381541924593 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6725292642140466 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7225172215843858 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7275690846286706 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.115336076817559 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.082224489795917 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.4649884526558874 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.407563884156732 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.609485981308413 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.435054347826093 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.466940063091483 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.135410958904105 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.278533834586467 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.81429729729728 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.39962809917355 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.839615384615366 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.585250965250973 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.991098901098887 ms/frame 12:12:20 INFO - PID 19934 | 12:12:20 INFO - PID 19934 | Cycle 1(10): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:13:06 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6856601123595507 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6704215358931551 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7566891100702577 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7094102564102567 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.043625336927224 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.16875 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.509725146198831 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4247773972602733 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.736701720841297 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.377459677419357 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 10.034063545150506 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.854088669950727 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.365984848484858 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 11.116972222222223 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.299569672131152 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.565086705202324 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.322641509433963 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.643909574468086 ms/frame 12:13:06 INFO - PID 19934 | 12:13:06 INFO - PID 19934 | Cycle 1(11): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:13:52 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6878177727784027 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6728428093645487 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7285627880184335 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.6872006745362567 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_startup = 4.179805013927577 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.177181628392486 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_startup = 3.67236842105263 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1_inclip = 3.6444808743169395 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.737743785850861 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.543310249307485 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_startup = 9.904339933993397 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.480p.60fps.webm_scale_2_inclip = 9.48158767772511 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.32379245283019 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.70077540106951 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.611785714285729 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.700116959064335 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.67566147859921 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | testsrc.1080p.60fps.mp4_scale_2_inclip = 11.242387640449461 ms/frame 12:13:52 INFO - PID 19934 | 12:13:52 INFO - PID 19934 | Cycle 1(12): loaded http://localhost:59872/tests/video/video_playback.html (next: http://localhost:59872/tests/video/video_playback.html) 12:13:53 INFO - PID 19934 | __start_tp_report 12:13:53 INFO - PID 19934 | _x_x_mozilla_page_load 12:13:53 INFO - PID 19934 | _x_x_mozilla_page_load_details 12:13:53 INFO - PID 19934 | |i|pagename|runs| 12:13:53 INFO - PID 19934 | |0;240p.120fps.mp4_scale_1_startup;1.6818301569506728;1.6808655462184876;1.6849354295339696;1.6818021300448431;1.6867509836987071;1.6800503919372902;1.6856685393258426;1.6866498032602586;1.6868100056211355;1.6886381541924593;1.6856601123595507;1.6878177727784027 12:13:53 INFO - PID 19934 | |1;240p.120fps.mp4_scale_1_inclip;1.6724540133779264;1.669970784641068;1.6757663316582916;1.6752386934673364;1.672336956521739;1.668548790658882;1.6704048414023376;1.6712949039264833;1.673966527196653;1.6725292642140466;1.6704215358931551;1.6728428093645487 12:13:53 INFO - PID 19934 | |2;240p.120fps.mp4_scale_1.1_startup;1.72458908045977;1.7442848837209304;1.767052414605418;1.7244913793103447;1.7712190082644625;1.7205189220183486;1.7503150525087514;1.7428252032520322;1.721514629948365;1.7225172215843858;1.7566891100702577;1.7285627880184335 12:13:53 INFO - PID 19934 | |3;240p.120fps.mp4_scale_1.1_inclip;1.699745114698386;1.7198151332760099;1.724922413793104;1.6958389830508476;1.723350559862188;1.7043867120953995;1.7039991482112435;1.702178723404255;1.7065315699658699;1.7275690846286706;1.7094102564102567;1.6872006745362567 12:13:53 INFO - PID 19934 | |4;240p.120fps.mp4_scale_2_startup;4.09993169398907;4.0069225634178895;4.077058423913043;4.13848275862069;4.172774687065367;4.110986301369864;4.105451436388508;4.088106267029973;4.167847222222223;4.115336076817559;4.043625336927224;4.179805013927577 12:13:53 INFO - PID 19934 | |5;240p.120fps.mp4_scale_2_inclip;4.194633123689727;4.041222222222223;4.058894523326572;4.202636554621849;4.115637860082306;3.969940476190477;4.117129629629632;4.058661257606491;4.142049689440995;4.082224489795917;4.16875;4.177181628392486 12:13:53 INFO - PID 19934 | |6;480p.60fps.webm_scale_1_startup;3.606772836538463;3.4726041666666685;3.505029205607479;3.5263337250293794;3.42519406392694;3.4925145518044234;3.641237864077671;3.5642814726840855;3.517860492379839;3.4649884526558874;3.509725146198831;3.67236842105263 12:13:53 INFO - PID 19934 | |7;480p.60fps.webm_scale_1_inclip;3.497744755244754;3.4023979591836744;3.4249571917808206;3.4792956521739087;3.4190085470085516;3.425659246575341;3.553134991119007;3.5658823529411747;3.396816638370116;3.407563884156732;3.4247773972602733;3.6444808743169395 12:13:53 INFO - PID 19934 | |8;480p.60fps.webm_scale_1.1_startup;5.629268292682929;5.6515254237288115;5.546284658040667;5.6084953271028075;5.649943502824857;5.587849162011172;5.7154380952380945;5.629268292682929;5.771403846153848;5.609485981308413;5.736701720841297;5.737743785850861 12:13:53 INFO - PID 19934 | |9;480p.60fps.webm_scale_1.1_inclip;5.51203856749311;5.378400537634407;5.451267029972756;5.58705307262569;5.652598870056498;5.556666666666671;5.466024590163931;5.571615598885791;5.4646174863387955;5.435054347826093;5.377459677419357;5.543310249307485 12:13:53 INFO - PID 19934 | |10;480p.60fps.webm_scale_2_startup;9.968637873754146;9.772817589576551;9.647041800643086;9.935033112582785;9.804575163398695;10.383442906574402;10.239436860068256;9.740551948051948;9.55523885350319;9.466940063091483;10.034063545150506;9.904339933993397 12:13:53 INFO - PID 19934 | |11;480p.60fps.webm_scale_2_inclip;9.806299019607845;9.620624999999983;10.005349999999998;9.760414634146334;9.093840909090911;9.263634259259257;10.001149999999997;9.17802752293577;9.524595238095243;9.135410958904105;9.854088669950727;9.48158767772511 12:13:53 INFO - PID 19934 | |12;1080p.60fps.mp4_scale_1_startup;11.237602996254676;11.32141509433962;11.40720532319392;11.630135658914746;11.154089219330858;11.540423076923071;11.28122180451128;11.584980694980702;11.279191729323307;11.278533834586467;11.365984848484858;11.32379245283019 12:13:53 INFO - PID 19934 | |13;1080p.60fps.mp4_scale_1_inclip;10.871086956521733;10.87173913043479;10.930355191256817;10.992307692307683;10.872173913043456;10.931912568306016;10.81697297297297;10.99016483516483;10.700962566844929;10.81429729729728;11.116972222222223;10.70077540106951 12:13:53 INFO - PID 19934 | |14;1080p.60fps.mp4_scale_1.1_startup;12.297131147540984;12.502895833333332;12.556213389121329;12.401095041322323;12.295491803278683;12.29823770491802;12.400000000000013;12.55322175732215;12.346131687242801;12.39962809917355;12.299569672131152;12.611785714285729 12:13:53 INFO - PID 19934 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.90898809523809;11.979491017964055;11.770558823529427;12.199999999999973;11.76667647058823;11.97856287425153;11.977874251497008;12.051777108433742;11.834378698224864;11.839615384615366;11.565086705202324;11.700116959064335 12:13:53 INFO - PID 19934 | |16;1080p.60fps.mp4_scale_2_startup;11.631046511627899;11.539730769230747;11.36556818181819;11.631279069767423;11.540903846153855;11.676050583657597;11.495670498084273;11.364374999999999;11.364393939393928;11.585250965250973;11.322641509433963;11.67566147859921 12:13:53 INFO - PID 19934 | |17;1080p.60fps.mp4_scale_2_inclip;11.050000000000017;11.305225988700574;11.05149171270718;11.11561111111114;11.23648876404495;10.932322404371574;11.055662983425439;11.23662921348312;10.75325268817206;10.991098901098887;10.643909574468086;11.242387640449461 12:13:53 INFO - PID 19934 | __end_tp_report 12:13:53 INFO - PID 19934 | __start_cc_report 12:13:53 INFO - PID 19934 | _x_x_mozilla_cycle_collect,581 12:13:53 INFO - PID 19934 | __end_cc_report 12:13:53 INFO - PID 19934 | __startTimestamp1507749233227__endTimestamp 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | ------- Summary: start ------- 12:13:53 INFO - PID 19934 | Number of tests: 18 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.69 stddev:0.00 (0.2%) stddev-sans-first:0.00 12:13:53 INFO - PID 19934 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#1] 240p.120fps.mp4_scale_1_inclip Cycles:12 Average:1.67 Median:1.67 stddev:0.00 (0.1%) stddev-sans-first:0.00 12:13:53 INFO - PID 19934 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.74 Median:1.74 stddev:0.02 (1.1%) stddev-sans-first:0.02 12:13:53 INFO - PID 19934 | Values: 1.7 1.7 1.8 1.7 1.8 1.7 1.8 1.7 1.7 1.7 1.8 1.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.71 Median:1.71 stddev:0.01 (0.7%) stddev-sans-first:0.01 12:13:53 INFO - PID 19934 | Values: 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 1.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.11 Median:4.11 stddev:0.05 (1.3%) stddev-sans-first:0.05 12:13:53 INFO - PID 19934 | Values: 4.1 4.0 4.1 4.1 4.2 4.1 4.1 4.1 4.2 4.1 4.0 4.2 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.11 Median:4.13 stddev:0.07 (1.7%) stddev-sans-first:0.07 12:13:53 INFO - PID 19934 | Values: 4.2 4.0 4.1 4.2 4.1 4.0 4.1 4.1 4.1 4.1 4.2 4.2 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.53 Median:3.52 stddev:0.07 (2.1%) stddev-sans-first:0.07 12:13:53 INFO - PID 19934 | Values: 3.6 3.5 3.5 3.5 3.4 3.5 3.6 3.6 3.5 3.5 3.5 3.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.47 Median:3.45 stddev:0.08 (2.3%) stddev-sans-first:0.08 12:13:53 INFO - PID 19934 | Values: 3.5 3.4 3.4 3.5 3.4 3.4 3.6 3.6 3.4 3.4 3.4 3.6 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.66 Median:5.65 stddev:0.07 (1.2%) stddev-sans-first:0.07 12:13:53 INFO - PID 19934 | Values: 5.6 5.7 5.5 5.6 5.6 5.6 5.7 5.6 5.8 5.6 5.7 5.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.50 Median:5.53 stddev:0.09 (1.5%) stddev-sans-first:0.09 12:13:53 INFO - PID 19934 | Values: 5.5 5.4 5.5 5.6 5.7 5.6 5.5 5.6 5.5 5.4 5.4 5.5 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:9.87 Median:9.76 stddev:0.27 (2.7%) stddev-sans-first:0.28 12:13:53 INFO - PID 19934 | Values: 10.0 9.8 9.6 9.9 9.8 10.4 10.2 9.7 9.6 9.5 10.0 9.9 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.56 Median:9.50 stddev:0.33 (3.5%) stddev-sans-first:0.34 12:13:53 INFO - PID 19934 | Values: 9.8 9.6 10.0 9.8 9.1 9.3 10.0 9.2 9.5 9.1 9.9 9.5 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.37 Median:11.34 stddev:0.15 (1.3%) stddev-sans-first:0.15 12:13:53 INFO - PID 19934 | Values: 11.2 11.3 11.4 11.6 11.2 11.5 11.3 11.6 11.3 11.3 11.4 11.3 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.88 Median:10.90 stddev:0.12 (1.1%) stddev-sans-first:0.13 12:13:53 INFO - PID 19934 | Values: 10.9 10.9 10.9 11.0 10.9 10.9 10.8 11.0 10.7 10.8 11.1 10.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.41 Median:12.40 stddev:0.12 (0.9%) stddev-sans-first:0.11 12:13:53 INFO - PID 19934 | Values: 12.3 12.5 12.6 12.4 12.3 12.3 12.4 12.6 12.3 12.4 12.3 12.6 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.88 Median:11.94 stddev:0.17 (1.4%) stddev-sans-first:0.18 12:13:53 INFO - PID 19934 | Values: 11.9 12.0 11.8 12.2 11.8 12.0 12.0 12.1 11.8 11.8 11.6 11.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.52 Median:11.56 stddev:0.13 (1.1%) stddev-sans-first:0.13 12:13:53 INFO - PID 19934 | Values: 11.6 11.5 11.4 11.6 11.5 11.7 11.5 11.4 11.4 11.6 11.3 11.7 12:13:53 INFO - PID 19934 | 12:13:53 INFO - PID 19934 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:11.05 Median:11.09 stddev:0.20 (1.8%) stddev-sans-first:0.21 12:13:53 INFO - PID 19934 | Values: 11.1 11.3 11.1 11.1 11.2 10.9 11.1 11.2 10.8 11.0 10.6 11.2 12:13:53 INFO - PID 19934 | -------- Summary: end -------- 12:13:53 INFO - PID 19934 | 12:13:53 INFO - TEST-INFO | 19934: exit 0 12:13:53 INFO - TEST-OK | basic_compositor_video | took 561442ms 12:13:53 INFO - TEST-START | glvideo 12:13:53 INFO - Initialising browser for glvideo test... 12:13:53 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:59872/getInfo.html -profile /tmp/tmpxnEUQ3/profile 12:13:53 INFO - TEST-INFO | started process 21177 (/builds/slave/test/build/application/firefox/firefox http://localhost:59872/getInfo.html) 12:13:59 INFO - TEST-INFO | 21177: exit 0 12:13:59 INFO - Browser initialized. 12:13:59 INFO - Running cycle 1/1 for glvideo test... 12:13:59 INFO - Using env: {'DISPLAY': ':0', 12:13:59 INFO - 'HOME': '/home/cltbld', 12:13:59 INFO - 'JSGC_DISABLE_POISONING': '1', 12:13:59 INFO - 'LANG': 'en_US.UTF-8', 12:13:59 INFO - 'LANGUAGE': 'en_US:en', 12:13:59 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox', 12:13:59 INFO - 'LOGNAME': 'cltbld', 12:13:59 INFO - 'MAIL': '/var/mail/cltbld', 12:13:59 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 12:13:59 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 12:13:59 INFO - 'MOZ_CRASHREPORTER': '1', 12:13:59 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 12:13:59 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1', 12:13:59 INFO - 'MOZ_NO_REMOTE': '1', 12:13:59 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 12:13:59 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 12:13:59 INFO - 'NO_EM_RESTART': '1', 12:13:59 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 12:13:59 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 12:13:59 INFO - 'PWD': '/builds/slave/test', 12:13:59 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 12:13:59 INFO - 'RUST_BACKTRACE': 'full', 12:13:59 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts', 12:13:59 INFO - 'SHELL': '/bin/bash', 12:13:59 INFO - 'SHLVL': '1', 12:13:59 INFO - 'STYLO_FORCE_DISABLED': '1', 12:13:59 INFO - 'TERM': 'linux', 12:13:59 INFO - 'TMOUT': '86400', 12:13:59 INFO - 'USER': 'cltbld', 12:13:59 INFO - 'XDG_SESSION_COOKIE': '4300f881736b422476174874000001bc-1507748608.868977-205121776', 12:13:59 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 12:13:59 INFO - '_': '/tools/buildbot/bin/python'} 12:13:59 INFO - TEST-INFO | started process 21454 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpxnEUQ3/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5) 12:14:00 INFO - PID 21454 | 12:14:00 INFO - PID 21454 | (/builds/slave/test/build/application/firefox/firefox:21503): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied 12:14:00 INFO - PID 21454 | 12:14:01 INFO - PID 21454 | [talos glvideo result] Mean tick time across 100 ticks: 6.787750000000001 ms 12:14:01 INFO - PID 21454 | Cycle 1(1): loaded http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html) 12:14:02 INFO - PID 21454 | [talos glvideo result] Mean tick time across 100 ticks: 6.4111 ms 12:14:02 INFO - PID 21454 | Cycle 1(2): loaded http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html) 12:14:04 INFO - PID 21454 | [talos glvideo result] Mean tick time across 100 ticks: 6.61605 ms 12:14:04 INFO - PID 21454 | Cycle 1(3): loaded http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html) 12:14:05 INFO - PID 21454 | [talos glvideo result] Mean tick time across 100 ticks: 6.557799999999999 ms 12:14:05 INFO - PID 21454 | Cycle 1(4): loaded http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html) 12:14:06 INFO - PID 21454 | [talos glvideo result] Mean tick time across 100 ticks: 6.6071 ms 12:14:06 INFO - PID 21454 | Cycle 1(5): loaded http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:59872/tests/webgl/benchmarks/video/video_upload.html) 12:14:07 INFO - PID 21454 | __start_tp_report 12:14:07 INFO - PID 21454 | _x_x_mozilla_page_load 12:14:07 INFO - PID 21454 | _x_x_mozilla_page_load_details 12:14:07 INFO - PID 21454 | |i|pagename|runs| 12:14:07 INFO - PID 21454 | |0;Mean tick time across 100 ticks: ;6.787750000000001;6.4111;6.61605;6.557799999999999;6.6071 12:14:07 INFO - PID 21454 | __end_tp_report 12:14:07 INFO - PID 21454 | __start_cc_report 12:14:07 INFO - PID 21454 | _x_x_mozilla_cycle_collect,292 12:14:07 INFO - PID 21454 | __end_cc_report 12:14:07 INFO - PID 21454 | __startTimestamp1507749247088__endTimestamp 12:14:07 INFO - PID 21454 | 12:14:07 INFO - PID 21454 | ------- Summary: start ------- 12:14:07 INFO - PID 21454 | Number of tests: 1 12:14:07 INFO - PID 21454 | 12:14:07 INFO - PID 21454 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.60 Median:6.61 stddev:0.14 (2.0%) stddev-sans-first:0.09 12:14:07 INFO - PID 21454 | Values: 6.8 6.4 6.6 6.6 6.6 12:14:07 INFO - PID 21454 | -------- Summary: end -------- 12:14:07 INFO - PID 21454 | 12:14:07 INFO - PID 21454 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping 12:14:07 INFO - TEST-INFO | 21454: exit 0 12:14:07 INFO - TEST-OK | glvideo | took 14158ms 12:14:07 INFO - SUITE-END | took 575s 12:14:08 INFO - Completed test suite (00:09:35) 12:14:08 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.5679168854802485, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6818301569506728, 1.6808655462184876, 1.6849354295339696, 1.6818021300448431, 1.6867509836987071, 1.6800503919372902, 1.6856685393258426, 1.6866498032602586, 1.6868100056211355, 1.6886381541924593, 1.6856601123595507, 1.6878177727784027], "value": 1.6856685393258426, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6724540133779264, 1.669970784641068, 1.6757663316582916, 1.6752386934673364, 1.672336956521739, 1.668548790658882, 1.6704048414023376, 1.6712949039264833, 1.673966527196653, 1.6725292642140466, 1.6704215358931551, 1.6728428093645487], "value": 1.672336956521739, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.72458908045977, 1.7442848837209304, 1.767052414605418, 1.7244913793103447, 1.7712190082644625, 1.7205189220183486, 1.7503150525087514, 1.7428252032520322, 1.721514629948365, 1.7225172215843858, 1.7566891100702577, 1.7285627880184335], "value": 1.7428252032520322, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.699745114698386, 1.7198151332760099, 1.724922413793104, 1.6958389830508476, 1.723350559862188, 1.7043867120953995, 1.7039991482112435, 1.702178723404255, 1.7065315699658699, 1.7275690846286706, 1.7094102564102567, 1.6872006745362567], "value": 1.7065315699658699, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.09993169398907, 4.0069225634178895, 4.077058423913043, 4.13848275862069, 4.172774687065367, 4.110986301369864, 4.105451436388508, 4.088106267029973, 4.167847222222223, 4.115336076817559, 4.043625336927224, 4.179805013927577], "value": 4.110986301369864, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.194633123689727, 4.041222222222223, 4.058894523326572, 4.202636554621849, 4.115637860082306, 3.969940476190477, 4.117129629629632, 4.058661257606491, 4.142049689440995, 4.082224489795917, 4.16875, 4.177181628392486], "value": 4.115637860082306, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.606772836538463, 3.4726041666666685, 3.505029205607479, 3.5263337250293794, 3.42519406392694, 3.4925145518044234, 3.641237864077671, 3.5642814726840855, 3.517860492379839, 3.4649884526558874, 3.509725146198831, 3.67236842105263], "value": 3.509725146198831, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.497744755244754, 3.4023979591836744, 3.4249571917808206, 3.4792956521739087, 3.4190085470085516, 3.425659246575341, 3.553134991119007, 3.5658823529411747, 3.396816638370116, 3.407563884156732, 3.4247773972602733, 3.6444808743169395], "value": 3.4249571917808206, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.629268292682929, 5.6515254237288115, 5.546284658040667, 5.6084953271028075, 5.649943502824857, 5.587849162011172, 5.7154380952380945, 5.629268292682929, 5.771403846153848, 5.609485981308413, 5.736701720841297, 5.737743785850861], "value": 5.649943502824857, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.51203856749311, 5.378400537634407, 5.451267029972756, 5.58705307262569, 5.652598870056498, 5.556666666666671, 5.466024590163931, 5.571615598885791, 5.4646174863387955, 5.435054347826093, 5.377459677419357, 5.543310249307485], "value": 5.466024590163931, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.968637873754146, 9.772817589576551, 9.647041800643086, 9.935033112582785, 9.804575163398695, 10.383442906574402, 10.239436860068256, 9.740551948051948, 9.55523885350319, 9.466940063091483, 10.034063545150506, 9.904339933993397], "value": 9.804575163398695, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.806299019607845, 9.620624999999983, 10.005349999999998, 9.760414634146334, 9.093840909090911, 9.263634259259257, 10.001149999999997, 9.17802752293577, 9.524595238095243, 9.135410958904105, 9.854088669950727, 9.48158767772511], "value": 9.524595238095243, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.237602996254676, 11.32141509433962, 11.40720532319392, 11.630135658914746, 11.154089219330858, 11.540423076923071, 11.28122180451128, 11.584980694980702, 11.279191729323307, 11.278533834586467, 11.365984848484858, 11.32379245283019], "value": 11.32379245283019, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.871086956521733, 10.87173913043479, 10.930355191256817, 10.992307692307683, 10.872173913043456, 10.931912568306016, 10.81697297297297, 10.99016483516483, 10.700962566844929, 10.81429729729728, 11.116972222222223, 10.70077540106951], "value": 10.872173913043456, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.297131147540984, 12.502895833333332, 12.556213389121329, 12.401095041322323, 12.295491803278683, 12.29823770491802, 12.400000000000013, 12.55322175732215, 12.346131687242801, 12.39962809917355, 12.299569672131152, 12.611785714285729], "value": 12.400000000000013, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.90898809523809, 11.979491017964055, 11.770558823529427, 12.199999999999973, 11.76667647058823, 11.97856287425153, 11.977874251497008, 12.051777108433742, 11.834378698224864, 11.839615384615366, 11.565086705202324, 11.700116959064335], "value": 11.839615384615366, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.631046511627899, 11.539730769230747, 11.36556818181819, 11.631279069767423, 11.540903846153855, 11.676050583657597, 11.495670498084273, 11.364374999999999, 11.364393939393928, 11.585250965250973, 11.322641509433963, 11.67566147859921], "value": 11.539730769230747, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.050000000000017, 11.305225988700574, 11.05149171270718, 11.11561111111114, 11.23648876404495, 10.932322404371574, 11.055662983425439, 11.23662921348312, 10.75325268817206, 10.991098901098887, 10.643909574468086, 11.242387640449461], "value": 11.055662983425439, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [6.787750000000001, 6.4111, 6.61605, 6.557799999999999, 6.6071], "value": 6.58245, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]} 12:14:08 INFO - Return code: 0 12:14:08 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 12:14:08 INFO - # TBPL SUCCESS # 12:14:08 INFO - Running post-action listener: _package_coverage_data 12:14:08 INFO - Running post-action listener: _resource_record_post_action 12:14:08 INFO - [mozharness: 2017-10-11 19:14:08.223489Z] Finished run-tests step (success) 12:14:08 INFO - Running post-run listener: _resource_record_post_run 12:14:08 INFO - Total resource usage - Wall time: 594s; CPU: 39.0%; Read bytes: 12288; Write bytes: 334585856; Read time: 128; Write time: 179132 12:14:08 INFO - TinderboxPrint: CPU usage
38.9% 12:14:08 INFO - TinderboxPrint: I/O read bytes / time
12,288 / 128 12:14:08 INFO - TinderboxPrint: I/O write bytes / time
334,585,856 / 179,132 12:14:08 INFO - TinderboxPrint: CPU idle
2,848.8 (61.1%) 12:14:08 INFO - TinderboxPrint: CPU system
300.6 (6.4%) 12:14:08 INFO - TinderboxPrint: CPU user
1,501.8 (32.2%) 12:14:08 INFO - TinderboxPrint: Swap in / out
0 / 0 12:14:08 INFO - install - Wall time: 18s; CPU: 13.0%; Read bytes: 0; Write bytes: 12873728; Read time: 0; Write time: 2208 12:14:08 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 12:14:08 INFO - run-tests - Wall time: 576s; CPU: 40.0%; Read bytes: 8192; Write bytes: 308432896; Read time: 112; Write time: 172808 12:14:08 INFO - Running post-run listener: _upload_blobber_files 12:14:08 INFO - Blob upload gear active. 12:14:08 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 12:14:08 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 12:14:08 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/test/oauth.txt', '-b', 'Firefox-Non-PGO', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 12:14:08 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/test/oauth.txt -b Firefox-Non-PGO -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 12:14:08 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:334: SNIMissingWarning: An HTTPS request has been made, but the SNI (Subject Name Indication) extension to TLS is not available on this platform. This may cause the server to present an incorrect TLS certificate, which can cause validation failures. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:08 INFO - SNIMissingWarning 12:14:08 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:08 INFO - InsecurePlatformWarning 12:14:08 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 12:14:08 INFO - SubjectAltNameWarning 12:14:08 INFO - (blobuploader) - INFO - Open directory for files ... 12:14:08 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log ... 12:14:09 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 12:14:09 INFO - (blobuploader) - INFO - Uploading, attempt #1. 12:14:09 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:09 INFO - InsecurePlatformWarning 12:14:09 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 12:14:09 INFO - SubjectAltNameWarning 12:14:09 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:09 INFO - InsecurePlatformWarning 12:14:10 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_raw.log: uploaded 12:14:10 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 12:14:10 INFO - (blobuploader) - INFO - Done attempting. 12:14:10 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 12:14:10 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 12:14:10 INFO - (blobuploader) - INFO - Uploading, attempt #1. 12:14:10 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:10 INFO - InsecurePlatformWarning 12:14:10 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 12:14:10 INFO - SubjectAltNameWarning 12:14:15 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:15 INFO - InsecurePlatformWarning 12:14:15 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 12:14:15 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 12:14:15 INFO - (blobuploader) - INFO - Done attempting. 12:14:15 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log ... 12:14:15 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 12:14:15 INFO - (blobuploader) - INFO - Uploading, attempt #1. 12:14:15 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:15 INFO - InsecurePlatformWarning 12:14:15 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 12:14:15 INFO - SubjectAltNameWarning 12:14:16 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:16 INFO - InsecurePlatformWarning 12:14:16 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_errorsummary.log: uploaded 12:14:16 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 12:14:16 INFO - (blobuploader) - INFO - Done attempting. 12:14:16 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ... 12:14:16 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 12:14:16 INFO - (blobuploader) - INFO - Uploading, attempt #1. 12:14:16 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:16 INFO - InsecurePlatformWarning 12:14:16 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/connection.py:340: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.) 12:14:16 INFO - SubjectAltNameWarning 12:14:17 INFO - /builds/slave/test/build/venv/local/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:132: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings 12:14:17 INFO - InsecurePlatformWarning 12:14:17 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded 12:14:17 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 12:14:17 INFO - (blobuploader) - INFO - Done attempting. 12:14:17 INFO - (blobuploader) - INFO - Iteration through files over. 12:14:17 INFO - Return code: 0 12:14:17 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 12:14:17 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 12:14:17 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3ab5cc069bf60b0aa80fd2c25283c617e96dcb2a6b9878d932987507ade405f6d2a60c930f39bd88f09d70b2adfb655f7b66e2802018fd85951e4ca0a2c7e7c5", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/8403f973defb62a1c2e27a4a5fa6f3c626371da5b6defc958c6fa83dcaf0b6fd7cc492465fc0a28c408df99f78c7a824fcafd91fe0bf97c4367e95fd144253b8", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5a3bca4a168bd2b91d43d3da2441de5cb56c9ce732efa4704acf7e0eb129f8fe6009a2a66d469311aa72b91a54ed31f1d76cc91fca687738215a6340de6c02d6", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/fa4432816cae2c32d17694f725df96fded694f218a62ba869afe76dc6f730535f0e8744cfffb916626536424a53b7fbee57211997ba43fcb53b6a8332a107e4f"} 12:14:17 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 12:14:17 INFO - Writing to file /builds/slave/test/properties/blobber_files 12:14:17 INFO - Contents: 12:14:17 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3ab5cc069bf60b0aa80fd2c25283c617e96dcb2a6b9878d932987507ade405f6d2a60c930f39bd88f09d70b2adfb655f7b66e2802018fd85951e4ca0a2c7e7c5", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/8403f973defb62a1c2e27a4a5fa6f3c626371da5b6defc958c6fa83dcaf0b6fd7cc492465fc0a28c408df99f78c7a824fcafd91fe0bf97c4367e95fd144253b8", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5a3bca4a168bd2b91d43d3da2441de5cb56c9ce732efa4704acf7e0eb129f8fe6009a2a66d469311aa72b91a54ed31f1d76cc91fca687738215a6340de6c02d6", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/fa4432816cae2c32d17694f725df96fded694f218a62ba869afe76dc6f730535f0e8744cfffb916626536424a53b7fbee57211997ba43fcb53b6a8332a107e4f"} 12:14:17 INFO - Running post-run listener: copy_logs_to_upload_dir 12:14:17 INFO - Copying logs to upload dir... 12:14:17 INFO - mkdir: /builds/slave/test/build/upload/logs 12:14:17 INFO - Copying logs to upload dir... program finished with exit code 0 elapsedTime=646.364303 ========= master_lag: 0.03 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 10 mins, 46 secs) (at 2017-10-11 12:14:17.371021) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-11 12:14:17.373981) ========= 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=4300f881736b422476174874000001bc-1507748608.868977-205121776 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3ab5cc069bf60b0aa80fd2c25283c617e96dcb2a6b9878d932987507ade405f6d2a60c930f39bd88f09d70b2adfb655f7b66e2802018fd85951e4ca0a2c7e7c5", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/8403f973defb62a1c2e27a4a5fa6f3c626371da5b6defc958c6fa83dcaf0b6fd7cc492465fc0a28c408df99f78c7a824fcafd91fe0bf97c4367e95fd144253b8", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5a3bca4a168bd2b91d43d3da2441de5cb56c9ce732efa4704acf7e0eb129f8fe6009a2a66d469311aa72b91a54ed31f1d76cc91fca687738215a6340de6c02d6", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/fa4432816cae2c32d17694f725df96fded694f218a62ba869afe76dc6f730535f0e8744cfffb916626536424a53b7fbee57211997ba43fcb53b6a8332a107e4f"} build_url:https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011277 build_url: 'https://queue.taskcluster.net/v1/task/XHvknNjMSeC1ZgFv1mRYbw/artifacts/public/build/target.tar.bz2' blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/3ab5cc069bf60b0aa80fd2c25283c617e96dcb2a6b9878d932987507ade405f6d2a60c930f39bd88f09d70b2adfb655f7b66e2802018fd85951e4ca0a2c7e7c5", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/8403f973defb62a1c2e27a4a5fa6f3c626371da5b6defc958c6fa83dcaf0b6fd7cc492465fc0a28c408df99f78c7a824fcafd91fe0bf97c4367e95fd144253b8", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5a3bca4a168bd2b91d43d3da2441de5cb56c9ce732efa4704acf7e0eb129f8fe6009a2a66d469311aa72b91a54ed31f1d76cc91fca687738215a6340de6c02d6", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/fa4432816cae2c32d17694f725df96fded694f218a62ba869afe76dc6f730535f0e8744cfffb916626536424a53b7fbee57211997ba43fcb53b6a8332a107e4f"}' ========= master_lag: 0.02 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-10-11 12:14:17.402593) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:14:17.402900) ========= 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=4300f881736b422476174874000001bc-1507748608.868977-205121776 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004613 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-10-11 12:14:17.485363) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-11 12:14:17.485666) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-10-11 12:14:17.485926) ========= ========= Total master_lag: 0.19 =========