builder: mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s
slave: talos-linux64-ix-052
starttime: 1509589987.81
results: success (0)
revision: 0a50066b2de805de843762b9787b2b3d2d5bf93f
========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:07.812675) =========
master: http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/
========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:07.813123) =========
========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:07.813420) =========
========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:07.835709) =========
========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:07.835981) =========
bash -c 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py'
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'wget -Oarchiver_client.py --no-check-certificate --tries=10 --waitretry=3 https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
--2017-11-01 19:33:07-- 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% 227M=0s
2017-11-01 19:33:08 (227 MB/s) - `archiver_client.py' saved [12179/12179]
program finished with exit code 0
elapsedTime=0.175608
========= master_lag: 0.02 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:08.030287) =========
========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:08.030670) =========
rm -rf scripts properties
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-rf', 'scripts', 'properties']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.017754
========= master_lag: 0.03 =========
========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:08.080501) =========
========= Started 'bash -c ...' (results: 0, elapsed: 13 secs) (at 2017-11-01 19:33:08.080860) =========
bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 0a50066b2de805de843762b9787b2b3d2d5bf93f --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 0a50066b2de805de843762b9787b2b3d2d5bf93f --destination scripts --debug']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
2017-11-01 19:33:08,136 truncating revision to first 12 chars
2017-11-01 19:33:08,136 Setting DEBUG logging.
2017-11-01 19:33:08,136 attempt 1/10
2017-11-01 19:33:08,136 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/0a50066b2de8?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness
2017-11-01 19:33:08,515 attempt 1/10
2017-11-01 19:33:09,120 current task status: no status available at this point. state: STARTED
2017-11-01 19:33:09,121 sleeping for 11.00s (attempt 1/10)
2017-11-01 19:33:20,132 attempt 2/10
2017-11-01 19:33:20,552 current task status: Task completed! Check 's3_urls' for upload locations. state: SUCCESS
2017-11-01 19:33:20,741 unpacking tar archive at: mozilla-central-0a50066b2de8/testing/mozharness/
program finished with exit code 0
elapsedTime=13.208714
========= master_lag: 0.02 =========
========= Finished 'bash -c ...' (results: 0, elapsed: 13 secs) (at 2017-11-01 19:33:21.306333) =========
========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:21.306660) =========
script_repo_revision: 0a50066b2de805de843762b9787b2b3d2d5bf93f
========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:21.307104) =========
========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:21.307401) =========
========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-11-01 19:33:21.321818) =========
========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 11 secs) (at 2017-11-01 19:33:21.322088) =========
/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=826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
19:33:21 INFO - MultiFileLogger online at 20171101 19:33:21 in /builds/slave/test
19:33:21 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
19:33:21 INFO - Dumping config to /builds/slave/test/logs/localconfig.json.
19:33:21 INFO - {'append_to_log': False,
19:33:21 INFO - 'base_work_dir': '/builds/slave/test',
19:33:21 INFO - 'blob_upload_branch': 'Firefox-Non-PGO',
19:33:21 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt',
19:33:21 INFO - 'branch': 'Firefox-Non-PGO',
19:33:21 INFO - 'buildbot_json_path': 'buildprops.json',
19:33:21 INFO - 'code_coverage': False,
19:33:21 INFO - 'config_files': ('talos/linux_config.py',),
19:33:21 INFO - 'default_actions': ('clobber',
19:33:21 INFO - 'read-buildbot-config',
19:33:21 INFO - 'download-and-extract',
19:33:21 INFO - 'populate-webroot',
19:33:21 INFO - 'create-virtualenv',
19:33:21 INFO - 'install',
19:33:21 INFO - 'setup-mitmproxy',
19:33:21 INFO - 'run-tests'),
19:33:21 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',),
19:33:21 INFO - 'disable_ccov_upload': False,
19:33:21 INFO - 'disable_stylo': False,
19:33:21 INFO - 'download_minidump_stackwalk': True,
19:33:21 INFO - 'download_symbols': 'ondemand',
19:33:21 INFO - 'e10s': False,
19:33:21 INFO - 'enable_stylo': False,
19:33:21 INFO - 'enable_webrender': False,
19:33:21 INFO - 'exes': {'tooltool.py': '/tools/tooltool.py'},
19:33:21 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub',
19:33:21 INFO - 'http://pypi.pub.build.mozilla.org/pub'),
19:33:21 INFO - 'gecko_profile': False,
19:33:21 INFO - 'gecko_profile_interval': 0,
19:33:21 INFO - 'installer_path': 'installer.exe',
19:33:21 INFO - 'jsd_code_coverage': False,
19:33:21 INFO - 'log_level': 'info',
19:33:21 INFO - 'log_name': 'talos',
19:33:21 INFO - 'log_to_console': True,
19:33:21 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk',
19:33:21 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest',
19:33:21 INFO - 'opt_config_files': (),
19:33:21 INFO - 'pip_index': False,
19:33:21 INFO - 'suite': 'g4-stylo-disabled-e10s',
19:33:21 INFO - 'system_bits': '32',
19:33:21 INFO - 'talos_extra_options': ('--webServer', 'localhost'),
19:33:21 INFO - 'title': 'talos-linux64-ix-052',
19:33:21 INFO - 'tooltool_cache': '/builds/tooltool_cache',
19:33:21 INFO - 'use_talos_json': True,
19:33:21 INFO - 'verify': 'False',
19:33:21 INFO - 'virtualenv_path': '/builds/slave/test/build/venv',
19:33:21 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None},
19:33:21 INFO - 'work_dir': 'build'}
19:33:21 INFO - [mozharness: 2017-11-02 02:33:21.601426Z] Running clobber step.
19:33:21 INFO - Running pre-action listener: _resource_record_pre_action
19:33:21 INFO - Running main action method: clobber
19:33:21 INFO - rmtree: /builds/slave/test/build
19:33:21 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1
19:33:22 INFO - Running post-action listener: _resource_record_post_action
19:33:22 INFO - [mozharness: 2017-11-02 02:33:22.611907Z] Finished clobber step (success)
19:33:22 INFO - [mozharness: 2017-11-02 02:33:22.612065Z] Running read-buildbot-config step.
19:33:22 INFO - Running pre-action listener: _resource_record_pre_action
19:33:22 INFO - Running main action method: read_buildbot_config
19:33:22 INFO - Using buildbot properties:
19:33:22 INFO - {
19:33:22 INFO - "project": "",
19:33:22 INFO - "product": "firefox",
19:33:22 INFO - "who": "ffxbld@noreply.mozilla.org",
19:33:22 INFO - "installer_path": "public/build/target.tar.bz2",
19:33:22 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-g4-stylo-disabled-e10s",
19:33:22 INFO - "repository": "https://hg.mozilla.org/mozilla-central",
19:33:22 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central talos g4-stylo-disabled-e10s",
19:33:22 INFO - "stage_platform": "linux64",
19:33:22 INFO - "basedir": "/builds/slave/test",
19:33:22 INFO - "buildnumber": 150,
19:33:22 INFO - "platform": "ubuntu64_hw",
19:33:22 INFO - "master": "http://buildbot-master103.bb.releng.scl3.mozilla.com:8201/",
19:33:22 INFO - "slavebuilddir": "test",
19:33:22 INFO - "taskId": "L0IDJ364S_iZpmGxLTnu8Q",
19:33:22 INFO - "branch": "mozilla-central",
19:33:22 INFO - "script_repo_revision": "production",
19:33:22 INFO - "revision": "0a50066b2de805de843762b9787b2b3d2d5bf93f",
19:33:22 INFO - "slavename": "talos-linux64-ix-052",
19:33:22 INFO - "repo_path": "mozilla-central"
19:33:22 INFO - }
19:33:22 INFO - Finding installer, test and symbols from parent task.
19:33:22 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/L0IDJ364S_iZpmGxLTnu8Q'}, attempt #1
19:33:23 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/L0IDJ364S_iZpmGxLTnu8Q'}, attempt #1
19:33:23 INFO - Task dependencies: Yy3Wn474SyWbRd4PgOqoiw
19:33:23 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw'}, attempt #1
19:33:23 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2
19:33:23 INFO - Set test_packages_url: https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.test_packages.json
19:33:23 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.crashreporter-symbols.zip
19:33:23 INFO - Running post-action listener: _resource_record_post_action
19:33:23 INFO - [mozharness: 2017-11-02 02:33:23.975146Z] Finished read-buildbot-config step (success)
19:33:23 INFO - [mozharness: 2017-11-02 02:33:23.975369Z] Running download-and-extract step.
19:33:23 INFO - Running pre-action listener: _resource_record_pre_action
19:33:23 INFO - Running main action method: download_and_extract
19:33:23 INFO - mkdir: /builds/slave/test/build/tests
19:33:23 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')]}
19:33:23 INFO - trying https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.test_packages.json
19:33:23 INFO - Downloading https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json
19:33:23 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1
19:33:24 INFO - Downloaded 989 bytes.
19:33:24 INFO - Reading from file /builds/slave/test/build/target.test_packages.json
19:33:24 INFO - Using the following test package requirements:
19:33:24 INFO - {u'awsy': [u'target.common.tests.zip', u'target.awsy.tests.zip'],
19:33:24 INFO - u'common': [u'target.common.tests.zip'],
19:33:24 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'],
19:33:24 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'],
19:33:24 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'],
19:33:24 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'],
19:33:24 INFO - u'mozbase': [u'target.common.tests.zip'],
19:33:24 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'],
19:33:24 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'],
19:33:24 INFO - u'web-platform': [u'target.common.tests.zip',
19:33:24 INFO - u'target.web-platform.tests.tar.gz'],
19:33:24 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']}
19:33:24 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite categories: ['common', 'talos']
19:33:24 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.common.tests.zip
19:33:24 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.common.tests.zip'}, attempt #1
19:33:24 INFO - Fetch https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.common.tests.zip into memory
19:33:27 INFO - Content-Length response header: 56194565
19:33:27 INFO - Bytes received: 56194565
19:33:38 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.talos.tests.zip
19:33:38 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.talos.tests.zip'}, attempt #1
19:33:38 INFO - Fetch https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.talos.tests.zip into memory
19:33:40 INFO - Content-Length response header: 18771919
19:33:40 INFO - Bytes received: 18771919
19:33:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:33:40 INFO - trying https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2
19:33:40 INFO - Downloading https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2
19:33:40 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1
19:33:42 INFO - Downloaded 62646789 bytes.
19:33:42 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2
19:33:42 INFO - mkdir: /builds/slave/test/properties
19:33:42 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url
19:33:42 INFO - Writing to file /builds/slave/test/properties/build_url
19:33:42 INFO - Contents:
19:33:42 INFO - build_url:https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2
19:33:42 INFO - Running post-action listener: _resource_record_post_action
19:33:42 INFO - Running post-action listener: find_tests_for_verification
19:33:42 INFO - Running post-action listener: set_extra_try_arguments
19:33:42 INFO - [mozharness: 2017-11-02 02:33:42.849909Z] Finished download-and-extract step (success)
19:33:42 INFO - [mozharness: 2017-11-02 02:33:42.850003Z] Running populate-webroot step.
19:33:42 INFO - Running pre-action listener: _resource_record_pre_action
19:33:42 INFO - Running main action method: populate_webroot
19:33:42 INFO - {'suites': {'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']},
19:33:42 INFO - 'chromez-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['tresize',
19:33:42 INFO - 'tcanvasmark']},
19:33:42 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']},
19:33:42 INFO - 'dromaeojs-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['dromaeo_css',
19:33:42 INFO - 'kraken']},
19:33:42 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
19:33:42 INFO - 'g1-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['tp5o_scroll', 'glterrain']},
19:33:42 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'tests': ['damp', 'tps']},
19:33:42 INFO - 'g2-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['damp', 'tps']},
19:33:42 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']},
19:33:42 INFO - 'g3-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['dromaeo_dom']},
19:33:42 INFO - 'g4-e10s': {'tests': ['basic_compositor_video',
19:33:42 INFO - 'glvideo',
19:33:42 INFO - 'displaylist_mutate']},
19:33:42 INFO - 'g4-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['basic_compositor_video',
19:33:42 INFO - 'glvideo']},
19:33:42 INFO - 'g5-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'tests': ['ts_paint_webext', 'tp5o_webext']},
19:33:42 INFO - 'g5-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['ts_paint_webext',
19:33:42 INFO - 'tp5o_webext']},
19:33:42 INFO - 'h1-e10s': {'tests': ['ts_paint_heavy']},
19:33:42 INFO - 'h2-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip',
19:33:42 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz',
19:33:42 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz',
19:33:42 INFO - 'talos_options': ['--mitmproxy',
19:33:42 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp',
19:33:42 INFO - '--firstNonBlankPaint'],
19:33:42 INFO - 'tests': ['tp6_google_heavy',
19:33:42 INFO - 'tp6_youtube_heavy',
19:33:42 INFO - 'tp6_amazon_heavy',
19:33:42 INFO - 'tp6_facebook_heavy']},
19:33:42 INFO - 'other-e10s': {'tests': ['a11yr',
19:33:42 INFO - 'ts_paint',
19:33:42 INFO - 'tpaint',
19:33:42 INFO - 'sessionrestore',
19:33:42 INFO - 'sessionrestore_many_windows',
19:33:42 INFO - 'sessionrestore_no_auto_restore',
19:33:42 INFO - 'tabpaint',
19:33:42 INFO - 'cpstartup']},
19:33:42 INFO - 'other-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['a11yr',
19:33:42 INFO - 'ts_paint',
19:33:42 INFO - 'tpaint',
19:33:42 INFO - 'sessionrestore',
19:33:42 INFO - 'sessionrestore_many_windows',
19:33:42 INFO - 'sessionrestore_no_auto_restore',
19:33:42 INFO - 'tabpaint',
19:33:42 INFO - 'cpstartup']},
19:33:42 INFO - 'perf-reftest-e10s': {'tests': ['perf_reftest']},
19:33:42 INFO - 'perf-reftest-singletons-e10s': {'tests': ['perf_reftest_singletons']},
19:33:42 INFO - 'perf-reftest-singletons-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['perf_reftest_singletons']},
19:33:42 INFO - 'perf-reftest-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['perf_reftest']},
19:33:42 INFO - 'speedometer-e10s': {'tests': ['speedometer']},
19:33:42 INFO - 'speedometer-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['speedometer']},
19:33:42 INFO - 'svgr-e10s': {'tests': ['tsvgx',
19:33:42 INFO - 'tsvgr_opacity',
19:33:42 INFO - 'tart',
19:33:42 INFO - 'tscrollx',
19:33:42 INFO - 'tsvg_static']},
19:33:42 INFO - 'svgr-stylo-disabled-e10s': {'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['tsvgx',
19:33:42 INFO - 'tsvgr_opacity',
19:33:42 INFO - 'tart',
19:33:42 INFO - 'tscrollx',
19:33:42 INFO - 'tsvg_static']},
19:33:42 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']},
19:33:42 INFO - 'tp5o-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'talos_options': ['--disable-stylo'],
19:33:42 INFO - 'tests': ['tp5o']},
19:33:42 INFO - 'tp6-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip',
19:33:42 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz',
19:33:42 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz',
19:33:42 INFO - 'talos_options': ['--mitmproxy',
19:33:42 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp',
19:33:42 INFO - '--firstNonBlankPaint'],
19:33:42 INFO - 'tests': ['tp6_google',
19:33:42 INFO - 'tp6_youtube',
19:33:42 INFO - 'tp6_amazon',
19:33:42 INFO - 'tp6_facebook']},
19:33:42 INFO - 'tp6-stylo-disabled-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip',
19:33:42 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz',
19:33:42 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz',
19:33:42 INFO - 'talos_options': ['--disable-stylo',
19:33:42 INFO - '--mitmproxy',
19:33:42 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp',
19:33:42 INFO - '--firstNonBlankPaint'],
19:33:42 INFO - 'tests': ['tp6_google',
19:33:42 INFO - 'tp6_youtube',
19:33:42 INFO - 'tp6_amazon',
19:33:42 INFO - 'tp6_facebook']},
19:33:42 INFO - 'tp6-stylo-threads-e10s': {'mitmproxy_recording_set': 'mitmproxy-recording-set-win10.zip',
19:33:42 INFO - 'mitmproxy_release_bin_linux64': 'mitmproxy-2.0.2-linux.tar.gz',
19:33:42 INFO - 'mitmproxy_release_bin_osx': 'mitmproxy-2.0.2-osx.tar.gz',
19:33:42 INFO - 'talos_options': ['--stylo-threads=1',
19:33:42 INFO - '--mitmproxy',
19:33:42 INFO - 'mitmproxy-recording-google.mp mitmproxy-recording-youtube.mp mitmproxy-recording-amazon.mp mitmproxy-recording-facebook.mp',
19:33:42 INFO - '--firstNonBlankPaint'],
19:33:42 INFO - 'tests': ['tp6_google',
19:33:42 INFO - 'tp6_youtube',
19:33:42 INFO - 'tp6_amazon',
19:33:42 INFO - 'tp6_facebook']},
19:33:42 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'talos_options': ['--xperf_path',
19:33:42 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
19:33:42 INFO - 'tests': ['tp5n']},
19:33:42 INFO - 'xperf-stylo-disabled-e10s': {'pagesets_name': 'tp5n.zip',
19:33:42 INFO - 'talos_options': ['--disable-stylo',
19:33:42 INFO - '--xperf_path',
19:33:42 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'],
19:33:42 INFO - 'tests': ['tp5n']}}}
19:33:42 INFO - Running post-action listener: _resource_record_post_action
19:33:42 INFO - [mozharness: 2017-11-02 02:33:42.875739Z] Finished populate-webroot step (success)
19:33:42 INFO - [mozharness: 2017-11-02 02:33:42.875834Z] Running create-virtualenv step.
19:33:42 INFO - Running pre-action listener: _resource_record_pre_action
19:33:42 INFO - Running main action method: create_virtualenv
19:33:42 INFO - Creating virtualenv /builds/slave/test/build/venv
19:33:42 INFO - Running command: ['/tools/buildbot/bin/python', '/builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py', '--always-copy', '/builds/slave/test/build/venv'] in /builds/slave/test/build
19:33:42 INFO - Copy/paste: /tools/buildbot/bin/python /builds/slave/test/scripts/external_tools/virtualenv/virtualenv.py --always-copy /builds/slave/test/build/venv
19:33:42 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'}
19:33:50 INFO - Using real prefix '/usr'
19:33:50 INFO - New python executable in /builds/slave/test/build/venv/bin/python
19:33:50 INFO - Overwriting /builds/slave/test/build/venv/lib/python2.7/distutils/__init__.py with new content
19:33:52 INFO - Installing setuptools, pip, wheel...done.
19:33:52 INFO - Return code: 0
19:33:52 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv
19:33:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:33:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:33:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:33:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:33:52 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:33:52 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'pip>=1.5'] in /builds/slave/test/build
19:33:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org pip>=1.5
19:33:52 INFO - Using env: {'DISPLAY': ':0',
19:33:52 INFO - 'HOME': '/home/cltbld',
19:33:52 INFO - 'LANG': 'en_US.UTF-8',
19:33:52 INFO - 'LANGUAGE': 'en_US:en',
19:33:52 INFO - 'LOGNAME': 'cltbld',
19:33:52 INFO - 'MAIL': '/var/mail/cltbld',
19:33:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:33:52 INFO - 'MOZ_NO_REMOTE': '1',
19:33:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:33:52 INFO - 'NO_EM_RESTART': '1',
19:33:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:33:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:33:52 INFO - 'PWD': '/builds/slave/test',
19:33:52 INFO - 'SHELL': '/bin/bash',
19:33:52 INFO - 'SHLVL': '1',
19:33:52 INFO - 'TERM': 'linux',
19:33:52 INFO - 'TMOUT': '86400',
19:33:52 INFO - 'USER': 'cltbld',
19:33:52 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:33:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:33:52 INFO - '_': '/tools/buildbot/bin/python'}
19:33:52 INFO - Ignoring indexes: https://pypi.python.org/simple
19:33:52 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages
19:33:52 INFO - Return code: 0
19:33:52 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv
19:33:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:33:52 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:33:52 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:33:52 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:33:52 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'psutil>=3.1.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:33:52 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'psutil>=3.1.1'] in /builds/slave/test/build
19:33:52 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org psutil>=3.1.1
19:33:52 INFO - Using env: {'DISPLAY': ':0',
19:33:52 INFO - 'HOME': '/home/cltbld',
19:33:52 INFO - 'LANG': 'en_US.UTF-8',
19:33:52 INFO - 'LANGUAGE': 'en_US:en',
19:33:52 INFO - 'LOGNAME': 'cltbld',
19:33:52 INFO - 'MAIL': '/var/mail/cltbld',
19:33:52 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:33:52 INFO - 'MOZ_NO_REMOTE': '1',
19:33:52 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:33:52 INFO - 'NO_EM_RESTART': '1',
19:33:52 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:33:52 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:33:52 INFO - 'PWD': '/builds/slave/test',
19:33:52 INFO - 'SHELL': '/bin/bash',
19:33:52 INFO - 'SHLVL': '1',
19:33:52 INFO - 'TERM': 'linux',
19:33:52 INFO - 'TMOUT': '86400',
19:33:52 INFO - 'USER': 'cltbld',
19:33:52 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:33:52 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:33:52 INFO - '_': '/tools/buildbot/bin/python'}
19:33:53 INFO - Ignoring indexes: https://pypi.python.org/simple
19:33:53 INFO - Collecting psutil>=3.1.1
19:33:54 INFO - Installing collected packages: psutil
19:33:54 INFO - Successfully installed psutil-3.1.1
19:33:54 INFO - Return code: 0
19:33:54 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv
19:33:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:33:54 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:33:54 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:33:54 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:33:54 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:33:54 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'mozsystemmonitor==0.3'] in /builds/slave/test/build
19:33:54 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org mozsystemmonitor==0.3
19:33:54 INFO - Using env: {'DISPLAY': ':0',
19:33:54 INFO - 'HOME': '/home/cltbld',
19:33:54 INFO - 'LANG': 'en_US.UTF-8',
19:33:54 INFO - 'LANGUAGE': 'en_US:en',
19:33:54 INFO - 'LOGNAME': 'cltbld',
19:33:54 INFO - 'MAIL': '/var/mail/cltbld',
19:33:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:33:54 INFO - 'MOZ_NO_REMOTE': '1',
19:33:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:33:54 INFO - 'NO_EM_RESTART': '1',
19:33:54 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:33:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:33:54 INFO - 'PWD': '/builds/slave/test',
19:33:54 INFO - 'SHELL': '/bin/bash',
19:33:54 INFO - 'SHLVL': '1',
19:33:54 INFO - 'TERM': 'linux',
19:33:54 INFO - 'TMOUT': '86400',
19:33:54 INFO - 'USER': 'cltbld',
19:33:54 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:33:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:33:54 INFO - '_': '/tools/buildbot/bin/python'}
19:33:54 INFO - Ignoring indexes: https://pypi.python.org/simple
19:33:54 INFO - Collecting mozsystemmonitor==0.3
19:33:55 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3)
19:33:55 INFO - Installing collected packages: mozsystemmonitor
19:33:55 INFO - Successfully installed mozsystemmonitor-0.3
19:33:55 INFO - Return code: 0
19:33:55 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv
19:33: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')]}
19:33:55 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:33: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')]}
19:33:55 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:33:55 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:33:55 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema==2.5.1'] in /builds/slave/test/build
19:33:55 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema==2.5.1
19:33:55 INFO - Using env: {'DISPLAY': ':0',
19:33:55 INFO - 'HOME': '/home/cltbld',
19:33:55 INFO - 'LANG': 'en_US.UTF-8',
19:33:55 INFO - 'LANGUAGE': 'en_US:en',
19:33:55 INFO - 'LOGNAME': 'cltbld',
19:33:55 INFO - 'MAIL': '/var/mail/cltbld',
19:33:55 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:33:55 INFO - 'MOZ_NO_REMOTE': '1',
19:33:55 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:33:55 INFO - 'NO_EM_RESTART': '1',
19:33:55 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:33:55 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:33:55 INFO - 'PWD': '/builds/slave/test',
19:33:55 INFO - 'SHELL': '/bin/bash',
19:33:55 INFO - 'SHLVL': '1',
19:33:55 INFO - 'TERM': 'linux',
19:33:55 INFO - 'TMOUT': '86400',
19:33:55 INFO - 'USER': 'cltbld',
19:33:55 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:33:55 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:33:55 INFO - '_': '/tools/buildbot/bin/python'}
19:33:56 INFO - Ignoring indexes: https://pypi.python.org/simple
19:33:56 INFO - Collecting jsonschema==2.5.1
19:33:57 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/jsonschema-2.5.1-py2.py3-none-any.whl
19:33:57 INFO - Collecting functools32; python_version == "2.7" (from jsonschema==2.5.1)
19:33:58 INFO - Installing collected packages: functools32, jsonschema
19:33:58 INFO - Successfully installed functools32-3.2.3.post2 jsonschema-2.5.1
19:33:58 INFO - Return code: 0
19:33:58 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv
19:33:58 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')]}
19:33:58 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:33:58 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')]}
19:33:58 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:33:58 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:33:58 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'functools32==3.2.3-2'] in /builds/slave/test/build
19:33:58 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org functools32==3.2.3-2
19:33:58 INFO - Using env: {'DISPLAY': ':0',
19:33:58 INFO - 'HOME': '/home/cltbld',
19:33:58 INFO - 'LANG': 'en_US.UTF-8',
19:33:58 INFO - 'LANGUAGE': 'en_US:en',
19:33:58 INFO - 'LOGNAME': 'cltbld',
19:33:58 INFO - 'MAIL': '/var/mail/cltbld',
19:33:58 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:33:58 INFO - 'MOZ_NO_REMOTE': '1',
19:33:58 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:33:58 INFO - 'NO_EM_RESTART': '1',
19:33:58 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:33:58 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:33:58 INFO - 'PWD': '/builds/slave/test',
19:33:58 INFO - 'SHELL': '/bin/bash',
19:33:58 INFO - 'SHLVL': '1',
19:33:58 INFO - 'TERM': 'linux',
19:33:58 INFO - 'TMOUT': '86400',
19:33:58 INFO - 'USER': 'cltbld',
19:33:58 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:33:58 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:33:58 INFO - '_': '/tools/buildbot/bin/python'}
19:33:58 INFO - Ignoring indexes: https://pypi.python.org/simple
19:33:58 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages
19:33:59 INFO - Return code: 0
19:33:59 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv
19:33: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')]}
19:33:59 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:33: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')]}
19:33:59 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:33:59 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:33:59 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'blobuploader==1.2.4'] in /builds/slave/test/build
19:33:59 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org blobuploader==1.2.4
19:33:59 INFO - Using env: {'DISPLAY': ':0',
19:33:59 INFO - 'HOME': '/home/cltbld',
19:33:59 INFO - 'LANG': 'en_US.UTF-8',
19:33:59 INFO - 'LANGUAGE': 'en_US:en',
19:33:59 INFO - 'LOGNAME': 'cltbld',
19:33:59 INFO - 'MAIL': '/var/mail/cltbld',
19:33:59 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:33:59 INFO - 'MOZ_NO_REMOTE': '1',
19:33:59 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:33:59 INFO - 'NO_EM_RESTART': '1',
19:33:59 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:33:59 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:33:59 INFO - 'PWD': '/builds/slave/test',
19:33:59 INFO - 'SHELL': '/bin/bash',
19:33:59 INFO - 'SHLVL': '1',
19:33:59 INFO - 'TERM': 'linux',
19:33:59 INFO - 'TMOUT': '86400',
19:33:59 INFO - 'USER': 'cltbld',
19:33:59 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:33:59 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:33:59 INFO - '_': '/tools/buildbot/bin/python'}
19:33:59 INFO - Ignoring indexes: https://pypi.python.org/simple
19:33:59 INFO - Collecting blobuploader==1.2.4
19:34:00 INFO - Collecting requests==1.2.3. (from blobuploader==1.2.4)
19:34:01 INFO - Collecting docopt==0.6.1 (from blobuploader==1.2.4)
19:34:02 INFO - Installing collected packages: requests, docopt, blobuploader
19:34:02 INFO - Successfully installed blobuploader-1.2.4 docopt-0.6.1 requests-1.2.3
19:34:02 INFO - Return code: 0
19:34:02 INFO - Installing None into virtualenv /builds/slave/test/build/venv
19:34:02 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')]}
19:34:02 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:34:02 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')]}
19:34:02 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:34:02 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:34:02 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--no-deps', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config
19:34:02 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --no-deps --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org
19:34:02 INFO - Using env: {'DISPLAY': ':0',
19:34:02 INFO - 'HOME': '/home/cltbld',
19:34:02 INFO - 'LANG': 'en_US.UTF-8',
19:34:02 INFO - 'LANGUAGE': 'en_US:en',
19:34:02 INFO - 'LOGNAME': 'cltbld',
19:34:02 INFO - 'MAIL': '/var/mail/cltbld',
19:34:02 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:34:02 INFO - 'MOZ_NO_REMOTE': '1',
19:34:02 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:34:02 INFO - 'NO_EM_RESTART': '1',
19:34:02 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:34:02 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:34:02 INFO - 'PWD': '/builds/slave/test',
19:34:02 INFO - 'SHELL': '/bin/bash',
19:34:02 INFO - 'SHLVL': '1',
19:34:02 INFO - 'TERM': 'linux',
19:34:02 INFO - 'TMOUT': '86400',
19:34:02 INFO - 'USER': 'cltbld',
19:34:02 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:34:02 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:34:02 INFO - '_': '/tools/buildbot/bin/python'}
19:34:03 INFO - Ignoring indexes: https://pypi.python.org/simple
19:34:03 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser
19:34:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash
19:34:03 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug
19:34:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice
19:34:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile
19:34:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd
19:34:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo
19:34:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall
19:34:04 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak
19:34:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog
19:34:05 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork
19:34:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess
19:34:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile
19:34:05 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner
19:34:06 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot
19:34:06 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest
19:34:06 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion
19:34:06 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion
19:34:06 INFO - Running setup.py install for manifestparser: started
19:34:06 INFO - Running setup.py install for manifestparser: finished with status 'done'
19:34:06 INFO - Running setup.py install for mozcrash: started
19:34:07 INFO - Running setup.py install for mozcrash: finished with status 'done'
19:34:07 INFO - Running setup.py install for mozdebug: started
19:34:07 INFO - Running setup.py install for mozdebug: finished with status 'done'
19:34:07 INFO - Running setup.py install for mozdevice: started
19:34:07 INFO - Running setup.py install for mozdevice: finished with status 'done'
19:34:07 INFO - Running setup.py install for mozfile: started
19:34:07 INFO - Running setup.py install for mozfile: finished with status 'done'
19:34:07 INFO - Running setup.py install for mozhttpd: started
19:34:07 INFO - Running setup.py install for mozhttpd: finished with status 'done'
19:34:07 INFO - Running setup.py install for mozinfo: started
19:34:08 INFO - Running setup.py install for mozinfo: finished with status 'done'
19:34:08 INFO - Running setup.py install for mozInstall: started
19:34:08 INFO - Running setup.py install for mozInstall: finished with status 'done'
19:34:08 INFO - Running setup.py install for mozleak: started
19:34:08 INFO - Running setup.py install for mozleak: finished with status 'done'
19:34:08 INFO - Running setup.py install for mozlog: started
19:34:08 INFO - Running setup.py install for mozlog: finished with status 'done'
19:34:08 INFO - Running setup.py install for moznetwork: started
19:34:09 INFO - Running setup.py install for moznetwork: finished with status 'done'
19:34:09 INFO - Running setup.py install for mozprocess: started
19:34:09 INFO - Running setup.py install for mozprocess: finished with status 'done'
19:34:09 INFO - Running setup.py install for mozprofile: started
19:34:09 INFO - Running setup.py install for mozprofile: finished with status 'done'
19:34:09 INFO - Running setup.py install for mozrunner: started
19:34:09 INFO - Running setup.py install for mozrunner: finished with status 'done'
19:34:09 INFO - Running setup.py install for mozscreenshot: started
19:34:09 INFO - Running setup.py install for mozscreenshot: finished with status 'done'
19:34:09 INFO - Running setup.py install for moztest: started
19:34:10 INFO - Running setup.py install for moztest: finished with status 'done'
19:34:10 INFO - Running setup.py install for mozversion: started
19:34:10 INFO - Running setup.py install for mozversion: finished with status 'done'
19:34:10 INFO - Successfully installed manifestparser-1.2 mozInstall-1.14 mozcrash-1.0 mozdebug-0.1 mozdevice-0.51 mozfile-1.2 mozhttpd-0.7 mozinfo-0.10 mozleak-0.1 mozlog-3.5 moznetwork-0.27 mozprocess-0.25 mozprofile-0.29 mozrunner-6.13 mozscreenshot-0.1 moztest-0.8 mozversion-1.4
19:34:10 INFO - Return code: 0
19:34:10 INFO - Installing None into virtualenv /builds/slave/test/build/venv
19:34: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')]}
19:34:10 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:34: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')]}
19:34:10 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:34:10 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/config', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:34:10 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/config/mozbase_requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/config
19:34:10 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/config/mozbase_requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org
19:34:10 INFO - Using env: {'DISPLAY': ':0',
19:34:10 INFO - 'HOME': '/home/cltbld',
19:34:10 INFO - 'LANG': 'en_US.UTF-8',
19:34:10 INFO - 'LANGUAGE': 'en_US:en',
19:34:10 INFO - 'LOGNAME': 'cltbld',
19:34:10 INFO - 'MAIL': '/var/mail/cltbld',
19:34:10 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:34:10 INFO - 'MOZ_NO_REMOTE': '1',
19:34:10 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:34:10 INFO - 'NO_EM_RESTART': '1',
19:34:10 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:34:10 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:34:10 INFO - 'PWD': '/builds/slave/test',
19:34:10 INFO - 'SHELL': '/bin/bash',
19:34:10 INFO - 'SHLVL': '1',
19:34:10 INFO - 'TERM': 'linux',
19:34:10 INFO - 'TMOUT': '86400',
19:34:10 INFO - 'USER': 'cltbld',
19:34:10 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:34:10 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:34:10 INFO - '_': '/tools/buildbot/bin/python'}
19:34:11 INFO - Ignoring indexes: https://pypi.python.org/simple
19:34:11 INFO - Processing /builds/slave/test/build/tests/mozbase/manifestparser
19:34:11 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.2 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1))
19:34:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozcrash
19:34:11 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))
19:34:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdebug
19:34:11 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))
19:34:11 INFO - Processing /builds/slave/test/build/tests/mozbase/mozdevice
19:34:12 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.51 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4))
19:34:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozfile
19:34:12 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5))
19:34:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozhttpd
19:34:12 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6))
19:34:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinfo
19:34:12 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))
19:34:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozinstall
19:34:12 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.14 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8))
19:34:12 INFO - Processing /builds/slave/test/build/tests/mozbase/mozleak
19:34:13 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9))
19:34:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozlog
19:34:13 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.5 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
19:34:13 INFO - Processing /builds/slave/test/build/tests/mozbase/moznetwork
19:34:13 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11))
19:34:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprocess
19:34:13 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))
19:34:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozprofile
19:34:13 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.29 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13))
19:34:13 INFO - Processing /builds/slave/test/build/tests/mozbase/mozrunner
19:34:14 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.13 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14))
19:34:14 INFO - Processing /builds/slave/test/build/tests/mozbase/mozscreenshot
19:34:14 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15))
19:34:14 INFO - Processing /builds/slave/test/build/tests/mozbase/moztest
19:34:14 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.8 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16))
19:34:14 INFO - Processing /builds/slave/test/build/tests/mozbase/mozversion
19:34:14 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))
19:34:14 INFO - Collecting six>=1.10.0 (from manifestparser==1.2->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1))
19:34:15 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/six-1.10.0-py2.py3-none-any.whl
19:34:15 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))
19:34:15 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))
19:34:15 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))
19:34:15 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))
19:34:15 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))
19:34:15 INFO - Requirement already satisfied (use --upgrade to upgrade): requests in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozInstall==1.14->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8))
19:34:15 INFO - Collecting blessings>=1.3 (from mozlog==3.5->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10))
19:34:16 INFO - Installing collected packages: six, blessings
19:34:16 INFO - Successfully installed blessings-1.6 six-1.10.0
19:34:17 INFO - Return code: 0
19:34:17 INFO - Done creating virtualenv /builds/slave/test/build/venv.
19:34:17 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
19:34:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
19:34:17 INFO - Reading from file tmpfile_stdout
19:34:17 INFO - Reading from file tmpfile_stderr
19:34:17 INFO - Current package versions:
19:34:17 INFO - blessings == 1.6
19:34:17 INFO - blobuploader == 1.2.4
19:34:17 INFO - docopt == 0.6.1
19:34:17 INFO - functools32 == 3.2.3.post2
19:34:17 INFO - jsonschema == 2.5.1
19:34:17 INFO - manifestparser == 1.2
19:34:17 INFO - mozInstall == 1.14
19:34:17 INFO - mozcrash == 1.0
19:34:17 INFO - mozdebug == 0.1
19:34:17 INFO - mozdevice == 0.51
19:34:17 INFO - mozfile == 1.2
19:34:17 INFO - mozhttpd == 0.7
19:34:17 INFO - mozinfo == 0.10
19:34:17 INFO - mozleak == 0.1
19:34:17 INFO - mozlog == 3.5
19:34:17 INFO - moznetwork == 0.27
19:34:17 INFO - mozprocess == 0.25
19:34:17 INFO - mozprofile == 0.29
19:34:17 INFO - mozrunner == 6.13
19:34:17 INFO - mozscreenshot == 0.1
19:34:17 INFO - mozsystemmonitor == 0.3
19:34:17 INFO - moztest == 0.8
19:34:17 INFO - mozversion == 1.4
19:34:17 INFO - psutil == 3.1.1
19:34:17 INFO - requests == 1.2.3
19:34:17 INFO - six == 1.10.0
19:34:17 INFO - Installing None into virtualenv /builds/slave/test/build/venv
19:34:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:34:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:34:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:34:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:34:17 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build/tests/talos', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:34:17 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '-r', '/builds/slave/test/build/tests/talos/requirements.txt', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org'] in /builds/slave/test/build/tests/talos
19:34:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 -r /builds/slave/test/build/tests/talos/requirements.txt --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org
19:34:17 INFO - Using env: {'DISPLAY': ':0',
19:34:17 INFO - 'HOME': '/home/cltbld',
19:34:17 INFO - 'LANG': 'en_US.UTF-8',
19:34:17 INFO - 'LANGUAGE': 'en_US:en',
19:34:17 INFO - 'LOGNAME': 'cltbld',
19:34:17 INFO - 'MAIL': '/var/mail/cltbld',
19:34:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:34:17 INFO - 'MOZ_NO_REMOTE': '1',
19:34:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:34:17 INFO - 'NO_EM_RESTART': '1',
19:34:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:34:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:34:17 INFO - 'PWD': '/builds/slave/test',
19:34:17 INFO - 'SHELL': '/bin/bash',
19:34:17 INFO - 'SHLVL': '1',
19:34:17 INFO - 'TERM': 'linux',
19:34:17 INFO - 'TMOUT': '86400',
19:34:17 INFO - 'USER': 'cltbld',
19:34:17 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:34:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:34:17 INFO - '_': '/tools/buildbot/bin/python'}
19:34:17 INFO - Ignoring indexes: https://pypi.python.org/simple
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8))
19:34:18 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 9))
19:34:18 INFO - Collecting simplejson>=2.1.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 10))
19:34:19 INFO - Collecting requests>=2.9.1 (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 11))
19:34:20 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/requests-2.18.3-py2.py3-none-any.whl (88kB)
19:34:20 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1))
19:34:20 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 4))
19:34:20 INFO - Requirement already satisfied (use --upgrade to upgrade): six>=1.10.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozprofile>=0.25->-r /builds/slave/test/build/tests/talos/requirements.txt (line 8))
19:34:20 INFO - Collecting chardet<3.1.0,>=3.0.2 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11))
19:34:21 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/chardet-3.0.4-py2.py3-none-any.whl (133kB)
19:34:21 INFO - Collecting urllib3<1.23,>=1.21.1 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11))
19:34:22 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/urllib3-1.22-py2.py3-none-any.whl (132kB)
19:34:22 INFO - Collecting certifi>=2017.4.17 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11))
19:34:23 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/certifi-2017.7.27.1-py2.py3-none-any.whl (349kB)
19:34:23 INFO - Collecting idna<2.6,>=2.5 (from requests>=2.9.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 11))
19:34:24 INFO - Downloading http://pypi.pvt.build.mozilla.org/pub/idna-2.5-py2.py3-none-any.whl (55kB)
19:34:25 INFO - Installing collected packages: simplejson, chardet, urllib3, certifi, idna, requests
19:34:25 INFO - Found existing installation: requests 1.2.3
19:34:25 INFO - Uninstalling requests-1.2.3:
19:34:25 INFO - Successfully uninstalled requests-1.2.3
19:34:25 INFO - Successfully installed certifi-2017.7.27.1 chardet-3.0.4 idna-2.5 requests-2.18.3 simplejson-3.3.0 urllib3-1.22
19:34:25 INFO - Return code: 0
19:34:25 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv
19:34:25 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:34:25 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org
19:34:25 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]}
19:34:25 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org
19:34:25 INFO - retry: Calling run_command with args: [['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x264d2d0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x2825a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x29c8bc0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'LANG': 'en_US.UTF-8', 'TERM': 'linux', 'SHELL': '/bin/bash', 'MOZ_NO_REMOTE': '1', 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977', '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
19:34:25 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', '--trusted-host', 'pypi.pub.build.mozilla.org', '--trusted-host', 'pypi.pvt.build.mozilla.org', 'jsonschema'] in /builds/slave/test/build
19:34:25 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub --trusted-host pypi.pub.build.mozilla.org --trusted-host pypi.pvt.build.mozilla.org jsonschema
19:34:25 INFO - Using env: {'DISPLAY': ':0',
19:34:25 INFO - 'HOME': '/home/cltbld',
19:34:25 INFO - 'LANG': 'en_US.UTF-8',
19:34:25 INFO - 'LANGUAGE': 'en_US:en',
19:34:25 INFO - 'LOGNAME': 'cltbld',
19:34:25 INFO - 'MAIL': '/var/mail/cltbld',
19:34:25 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:34:25 INFO - 'MOZ_NO_REMOTE': '1',
19:34:25 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:34:25 INFO - 'NO_EM_RESTART': '1',
19:34:25 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:34:25 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:34:25 INFO - 'PWD': '/builds/slave/test',
19:34:25 INFO - 'SHELL': '/bin/bash',
19:34:25 INFO - 'SHLVL': '1',
19:34:25 INFO - 'TERM': 'linux',
19:34:25 INFO - 'TMOUT': '86400',
19:34:25 INFO - 'USER': 'cltbld',
19:34:25 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:34:25 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:34:25 INFO - '_': '/tools/buildbot/bin/python'}
19:34:26 INFO - Ignoring indexes: https://pypi.python.org/simple
19:34:26 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages
19:34:26 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32; python_version == "2.7" in ./venv/lib/python2.7/site-packages (from jsonschema)
19:34:26 INFO - Return code: 0
19:34:26 INFO - Running post-action listener: _resource_record_post_action
19:34:26 INFO - Running post-action listener: _start_resource_monitoring
19:34:26 INFO - Starting resource monitoring.
19:34:26 INFO - [mozharness: 2017-11-02 02:34:26.146640Z] Finished create-virtualenv step (success)
19:34:26 INFO - [mozharness: 2017-11-02 02:34:26.147251Z] Running install step.
19:34:26 INFO - Running pre-action listener: _resource_record_pre_action
19:34:26 INFO - Running main action method: install
19:34:26 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze']
19:34:26 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze
19:34:26 INFO - Reading from file tmpfile_stdout
19:34:26 INFO - Reading from file tmpfile_stderr
19:34:26 INFO - Detecting whether we're running mozinstall >=1.0...
19:34:26 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h']
19:34:26 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h
19:34:26 INFO - Reading from file tmpfile_stdout
19:34:26 INFO - Output received:
19:34:26 INFO - Usage: mozinstall [options] installer
19:34:26 INFO - Options:
19:34:26 INFO - -h, --help show this help message and exit
19:34:26 INFO - -d DEST, --destination=DEST
19:34:26 INFO - Directory to install application into. [default:
19:34:26 INFO - "/builds/slave/test"]
19:34:26 INFO - --app=APP Application being installed. [default: firefox]
19:34:26 INFO - mkdir: /builds/slave/test/build/application
19:34:26 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/target.tar.bz2', '--destination', '/builds/slave/test/build/application']
19:34:26 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application
19:34:45 INFO - Reading from file tmpfile_stdout
19:34:45 INFO - Output received:
19:34:45 INFO - /builds/slave/test/build/application/firefox/firefox
19:34:45 INFO - Running post-action listener: _resource_record_post_action
19:34:45 INFO - [mozharness: 2017-11-02 02:34:45.083142Z] Finished install step (success)
19:34:45 INFO - [mozharness: 2017-11-02 02:34:45.083389Z] Running setup-mitmproxy step.
19:34:45 INFO - Running pre-action listener: _resource_record_pre_action
19:34:45 INFO - Running main action method: setup_mitmproxy
19:34:45 INFO - Skipping: mitmproxy is not required
19:34:45 INFO - Running post-action listener: _resource_record_post_action
19:34:45 INFO - [mozharness: 2017-11-02 02:34:45.084487Z] Finished setup-mitmproxy step (success)
19:34:45 INFO - [mozharness: 2017-11-02 02:34:45.084702Z] Running run-tests step.
19:34:45 INFO - Running pre-action listener: _resource_record_pre_action
19:34:45 INFO - Running pre-action listener: _set_gcov_prefix
19:34:45 INFO - Running main action method: run_tests
19:34:45 WARNING - Try message not found.
19:34:45 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version']
19:34:45 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version
19:34:45 INFO - Python 2.7.3
19:34:45 INFO - Return code: 0
19:34:45 INFO - grabbing minidump binary from tooltool
19:34:45 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')]}
19:34:45 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 0x29c5da0>, '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 0x29c6ca0>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x29c7130>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1
19:34:45 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
19:34:45 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
19:34:45 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
19:34:45 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache
19:34:45 INFO - Return code: 0
19:34:45 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755
19:34:45 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir
19:34:45 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir
19:34:45 INFO - ENV: RUST_BACKTRACE is now full
19:34:45 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk
19:34:45 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir
19:34:45 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/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-052', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-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
19:34:45 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/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-052 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log
19:34:45 INFO - Using env: {'DISPLAY': ':0',
19:34:45 INFO - 'HOME': '/home/cltbld',
19:34:45 INFO - 'LANG': 'en_US.UTF-8',
19:34:45 INFO - 'LANGUAGE': 'en_US:en',
19:34:45 INFO - 'LOGNAME': 'cltbld',
19:34:45 INFO - 'MAIL': '/var/mail/cltbld',
19:34:45 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
19:34:45 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk',
19:34:45 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:34:45 INFO - 'MOZ_NO_REMOTE': '1',
19:34:45 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
19:34:45 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:34:45 INFO - 'NO_EM_RESTART': '1',
19:34:45 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:34:45 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:34:45 INFO - 'PWD': '/builds/slave/test',
19:34:45 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
19:34:45 INFO - 'RUST_BACKTRACE': 'full',
19:34:45 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts',
19:34:45 INFO - 'SHELL': '/bin/bash',
19:34:45 INFO - 'SHLVL': '1',
19:34:45 INFO - 'TERM': 'linux',
19:34:45 INFO - 'TMOUT': '86400',
19:34:45 INFO - 'USER': 'cltbld',
19:34:45 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:34:45 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:34:45 INFO - '_': '/tools/buildbot/bin/python'}
19:34:45 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/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-052', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log'] with output_timeout 3600
19:34:45 INFO - mozversion application_buildid: 20171102013847
19:34:45 INFO - mozversion application_changeset: 0a50066b2de805de843762b9787b2b3d2d5bf93f
19:34:45 INFO - mozversion application_display_name: Nightly
19:34:45 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384}
19:34:45 INFO - mozversion application_name: Firefox
19:34:45 INFO - mozversion application_remotingname: firefox
19:34:45 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central
19:34:45 INFO - mozversion application_vendor: Mozilla
19:34:45 INFO - mozversion application_version: 58.0a1
19:34:45 INFO - mozversion platform_buildid: 20171102013847
19:34:45 INFO - mozversion platform_changeset: 0a50066b2de805de843762b9787b2b3d2d5bf93f
19:34:45 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central
19:34:45 INFO - mozversion platform_version: 58.0a1
19:34:45 INFO - using testdate: 1509590085
19:34:45 INFO - actual date: 1509590085
19:34:45 INFO - starting webserver on 'localhost:44356'
19:34:45 INFO - SUITE-START | Running 2 tests
19:34:45 INFO - TEST-START | basic_compositor_video
19:34:45 INFO - Initialising browser for basic_compositor_video test...
19:34:45 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:44356/getInfo.html -profile /tmp/tmpwryfS3/profile
19:34:45 INFO - TEST-INFO | started process 3722 (/builds/slave/test/build/application/firefox/firefox http://localhost:44356/getInfo.html)
19:34:54 INFO - TEST-INFO | 3722: exit 0
19:34:54 INFO - Browser initialized.
19:34:54 INFO - Running cycle 1/1 for basic_compositor_video test...
19:34:54 INFO - Using env: {'DISPLAY': ':0',
19:34:54 INFO - 'HOME': '/home/cltbld',
19:34:54 INFO - 'JSGC_DISABLE_POISONING': '1',
19:34:54 INFO - 'LANG': 'en_US.UTF-8',
19:34:54 INFO - 'LANGUAGE': 'en_US:en',
19:34:54 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox',
19:34:54 INFO - 'LOGNAME': 'cltbld',
19:34:54 INFO - 'MAIL': '/var/mail/cltbld',
19:34:54 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
19:34:54 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk',
19:34:54 INFO - 'MOZ_CRASHREPORTER': '1',
19:34:54 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:34:54 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1',
19:34:54 INFO - 'MOZ_NO_REMOTE': '1',
19:34:54 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
19:34:54 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:34:54 INFO - 'NO_EM_RESTART': '1',
19:34:54 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:34:54 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:34:54 INFO - 'PWD': '/builds/slave/test',
19:34:54 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
19:34:54 INFO - 'RUST_BACKTRACE': 'full',
19:34:54 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts',
19:34:54 INFO - 'SHELL': '/bin/bash',
19:34:54 INFO - 'SHLVL': '1',
19:34:54 INFO - 'STYLO_FORCE_DISABLED': '1',
19:34:54 INFO - 'TERM': 'linux',
19:34:54 INFO - 'TMOUT': '86400',
19:34:54 INFO - 'USER': 'cltbld',
19:34:54 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:34:54 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:34:54 INFO - '_': '/tools/buildbot/bin/python'}
19:34:54 INFO - TEST-INFO | started process 3998 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwryfS3/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/video/video.manifest.develop -tpnoisy -tpcycles 1 -tppagecycles 12)
19:34:55 INFO - PID 3998 |
19:34:55 INFO - PID 3998 | (/builds/slave/test/build/application/firefox/firefox:4049): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied
19:34:55 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.689349662162162 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6673208333333331 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7404727378190255 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.752896581945662 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.087656675749319 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.1856380753138085 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.5096842105263164 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4558203799654548 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.577760223048325 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.602703081232495 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.205659509202448 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.619663461538476 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.195317164179109 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.529894736842106 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.000739999999992 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.494683908046001 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.279624060150393 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.812081081081084 ms/frame
19:35:42 INFO - PID 3998 |
19:35:42 INFO - PID 3998 | Cycle 1(1): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:36:28 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6818553811659191 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6725459866220742 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7487441724941721 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7183333333333344 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.099528688524592 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.142318840579709 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.530623529411763 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4438123924268496 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.692931688804553 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.572952646239551 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 10.138902027027033 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.571722488038267 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.871920289855078 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.473795811518338 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.001799999999989 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.630639534883727 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.113185185185204 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.582539682539675 ms/frame
19:36:28 INFO - PID 3998 |
19:36:28 INFO - PID 3998 | Cycle 1(2): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:37:14 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.67935086737549 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6718379281537177 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7404321345707656 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.71731330472103 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.202233893557423 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.19308176100629 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.5425265643447466 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.449181034482761 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.556351851851852 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.527417127071821 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.55695859872611 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.57090909090909 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.99190476190478 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.529157894736846 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.298586065573783 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.36622159090906 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.408307984790882 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.990274725274743 ms/frame
19:37:14 INFO - PID 3998 |
19:37:14 INFO - PID 3998 | Cycle 1(3): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:38:00 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6810420168067228 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6713032581453635 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7304238754325256 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7188831615120272 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.110178082191779 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.203371848739496 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.672588739290087 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5853494623655915 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.694345351043647 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.651355932203384 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.773094462540705 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 8.89366666666667 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.071678966789678 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.418984374999999 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.097782258064516 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.630668604651154 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.279191729323307 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.811945945945942 ms/frame
19:38:00 INFO - PID 3998 |
19:38:00 INFO - PID 3998 | Cycle 1(4): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:38:46 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6893975225225226 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6659741881765195 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7672055359246173 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.765269196822595 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.20773492286115 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.099149590163935 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.576781883194279 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4915183246073287 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.705275665399244 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.634211267605624 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.231646153846153 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.22018433179723 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.949817518248162 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585555555555585 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.049618473895595 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.628779069767408 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.237921348314584 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.933497267759572 ms/frame
19:38:46 INFO - PID 3998 |
19:38:46 INFO - PID 3998 | Cycle 1(5): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:39:32 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6858455056179777 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6682944120100085 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.741755658734765 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.708343296327925 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.2023389355742315 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 3.7181691449814127 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.576436233611441 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.5098859649122844 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.725868320610687 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.6191853932584275 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.711569579288026 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.574593301435407 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.115981481481477 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.583095238095247 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.09963709677419 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.83517751479288 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.155111524163564 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.696978609625702 ms/frame
19:39:32 INFO - PID 3998 |
19:39:32 INFO - PID 3998 | Cycle 1(6): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:39:55 INFO - PID 3998 |
19:39:55 INFO - PID 3998 | (/builds/slave/test/build/application/firefox/firefox:4118): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied
19:39:55 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6781739373601792 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6675791666666668 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7783135743924128 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7640520282186953 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.203123249299721 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.017851405622489 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.6587195121951237 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.618019891500903 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.545415896487992 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.376545698924724 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.71116504854369 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.13742009132419 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.323188679245298 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.528210526315755 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.299323770491817 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.698713450292374 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.03167279411764 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.639574468085096 ms/frame
19:40:19 INFO - PID 3998 |
19:40:19 INFO - PID 3998 | Cycle 1(7): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:41:05 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6831968592260236 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.66826105087573 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7699852507374632 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7428135888501735 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.196237762237762 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.134163223140499 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.5592170818505338 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.509561403508773 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.547033271719038 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.54198060941829 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.616121794871793 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.093386363636355 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.03104779411766 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.472670157068057 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.195569105691058 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.698947368421035 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.031029411764715 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.931639344262283 ms/frame
19:41:05 INFO - PID 3998 |
19:41:05 INFO - PID 3998 | Cycle 1(8): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:41:51 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.68078431372549 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6718295739348374 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7254715353651526 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7023957446808515 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.255872340425531 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.228720930232557 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.658987804878052 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.624320652173913 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.737026768642448 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.635816901408451 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.23213846153846 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.525333333333332 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.194421641791044 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.640984042553178 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.296741803278683 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.767558823529415 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.197835820895511 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.812432432432448 ms/frame
19:41:51 INFO - PID 3998 |
19:41:51 INFO - PID 3998 | Cycle 1(9): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:42:37 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6765782122905026 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6723411371237462 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7433178384660082 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7339991334488742 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.172684283727399 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.107094455852158 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.6955172413793105 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.6440163934426204 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.715780952380952 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.633971830985919 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.618253205128207 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.094090909090912 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.070387453874542 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.754973118279546 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 11.767019607843123 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.701871345029264 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.281315789473691 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.811972972972955 ms/frame
19:42:37 INFO - PID 3998 |
19:42:37 INFO - PID 3998 | Cycle 1(10): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:43:23 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.6849915777653006 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6725209030100332 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7667844522968204 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7243663793103443 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.1450897790055246 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.141749482401656 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.722940446650125 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.6313793103448266 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.758685220729363 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.634985915492963 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.58632587859425 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.574210526315781 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 11.031783088235295 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.585449735449743 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.09975806451612 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.36761363636362 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 11.19589552238806 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.932513661202194 ms/frame
19:43:23 INFO - PID 3998 |
19:43:23 INFO - PID 3998 | Cycle 1(11): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:44:10 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_startup = 1.679135422495803 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1_inclip = 1.6726672240802674 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_startup = 1.7433788495061013 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_1.1_inclip = 1.7363454861111114 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_startup = 4.197062937062936 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.240p.120fps.mp4_scale_2_inclip = 4.292736051502148 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_startup = 3.510046783625733 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1_inclip = 3.4791130434782573 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_startup = 5.791882239382239 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_1.1_inclip = 5.465150273224041 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_startup = 9.967043189368765 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.480p.60fps.webm_scale_2_inclip = 9.805416666666668 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_startup = 10.952664233576638 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1_inclip = 10.582619047619076 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_startup = 12.097620967741932 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_1.1_inclip = 11.63438953488371 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_startup = 10.952481751824829 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | testsrc.1080p.60fps.mp4_scale_2_inclip = 10.474267015706802 ms/frame
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | Cycle 1(12): loaded http://localhost:44356/tests/video/video_playback.html (next: http://localhost:44356/tests/video/video_playback.html)
19:44:10 INFO - PID 3998 | __start_tp_report
19:44:10 INFO - PID 3998 | _x_x_mozilla_page_load
19:44:10 INFO - PID 3998 | _x_x_mozilla_page_load_details
19:44:10 INFO - PID 3998 | |i|pagename|runs|
19:44:10 INFO - PID 3998 | |0;240p.120fps.mp4_scale_1_startup;1.689349662162162;1.6818553811659191;1.67935086737549;1.6810420168067228;1.6893975225225226;1.6858455056179777;1.6781739373601792;1.6831968592260236;1.68078431372549;1.6765782122905026;1.6849915777653006;1.679135422495803
19:44:10 INFO - PID 3998 | |1;240p.120fps.mp4_scale_1_inclip;1.6673208333333331;1.6725459866220742;1.6718379281537177;1.6713032581453635;1.6659741881765195;1.6682944120100085;1.6675791666666668;1.66826105087573;1.6718295739348374;1.6723411371237462;1.6725209030100332;1.6726672240802674
19:44:10 INFO - PID 3998 | |2;240p.120fps.mp4_scale_1.1_startup;1.7404727378190255;1.7487441724941721;1.7404321345707656;1.7304238754325256;1.7672055359246173;1.741755658734765;1.7783135743924128;1.7699852507374632;1.7254715353651526;1.7433178384660082;1.7667844522968204;1.7433788495061013
19:44:10 INFO - PID 3998 | |3;240p.120fps.mp4_scale_1.1_inclip;1.752896581945662;1.7183333333333344;1.71731330472103;1.7188831615120272;1.765269196822595;1.708343296327925;1.7640520282186953;1.7428135888501735;1.7023957446808515;1.7339991334488742;1.7243663793103443;1.7363454861111114
19:44:10 INFO - PID 3998 | |4;240p.120fps.mp4_scale_2_startup;4.087656675749319;4.099528688524592;4.202233893557423;4.110178082191779;4.20773492286115;4.2023389355742315;4.203123249299721;4.196237762237762;4.255872340425531;4.172684283727399;4.1450897790055246;4.197062937062936
19:44:10 INFO - PID 3998 | |5;240p.120fps.mp4_scale_2_inclip;4.1856380753138085;4.142318840579709;4.19308176100629;4.203371848739496;4.099149590163935;3.7181691449814127;4.017851405622489;4.134163223140499;4.228720930232557;4.107094455852158;4.141749482401656;4.292736051502148
19:44:10 INFO - PID 3998 | |6;480p.60fps.webm_scale_1_startup;3.5096842105263164;3.530623529411763;3.5425265643447466;3.672588739290087;3.576781883194279;3.576436233611441;3.6587195121951237;3.5592170818505338;3.658987804878052;3.6955172413793105;3.722940446650125;3.510046783625733
19:44:10 INFO - PID 3998 | |7;480p.60fps.webm_scale_1_inclip;3.4558203799654548;3.4438123924268496;3.449181034482761;3.5853494623655915;3.4915183246073287;3.5098859649122844;3.618019891500903;3.509561403508773;3.624320652173913;3.6440163934426204;3.6313793103448266;3.4791130434782573
19:44:10 INFO - PID 3998 | |8;480p.60fps.webm_scale_1.1_startup;5.577760223048325;5.692931688804553;5.556351851851852;5.694345351043647;5.705275665399244;5.725868320610687;5.545415896487992;5.547033271719038;5.737026768642448;5.715780952380952;5.758685220729363;5.791882239382239
19:44:10 INFO - PID 3998 | |9;480p.60fps.webm_scale_1.1_inclip;5.602703081232495;5.572952646239551;5.527417127071821;5.651355932203384;5.634211267605624;5.6191853932584275;5.376545698924724;5.54198060941829;5.635816901408451;5.633971830985919;5.634985915492963;5.465150273224041
19:44:10 INFO - PID 3998 | |10;480p.60fps.webm_scale_2_startup;9.205659509202448;10.138902027027033;9.55695859872611;9.773094462540705;9.231646153846153;9.711569579288026;9.71116504854369;9.616121794871793;9.23213846153846;9.618253205128207;9.58632587859425;9.967043189368765
19:44:10 INFO - PID 3998 | |11;480p.60fps.webm_scale_2_inclip;9.619663461538476;9.571722488038267;9.57090909090909;8.89366666666667;9.22018433179723;9.574593301435407;9.13742009132419;9.093386363636355;9.525333333333332;9.094090909090912;9.574210526315781;9.805416666666668
19:44:10 INFO - PID 3998 | |12;1080p.60fps.mp4_scale_1_startup;11.195317164179109;10.871920289855078;10.99190476190478;11.071678966789678;10.949817518248162;11.115981481481477;11.323188679245298;11.03104779411766;11.194421641791044;11.070387453874542;11.031783088235295;10.952664233576638
19:44:10 INFO - PID 3998 | |13;1080p.60fps.mp4_scale_1_inclip;10.529894736842106;10.473795811518338;10.529157894736846;10.418984374999999;10.585555555555585;10.583095238095247;10.528210526315755;10.472670157068057;10.640984042553178;10.754973118279546;10.585449735449743;10.582619047619076
19:44:10 INFO - PID 3998 | |14;1080p.60fps.mp4_scale_1.1_startup;12.000739999999992;12.001799999999989;12.298586065573783;12.097782258064516;12.049618473895595;12.09963709677419;12.299323770491817;12.195569105691058;12.296741803278683;11.767019607843123;12.09975806451612;12.097620967741932
19:44:10 INFO - PID 3998 | |15;1080p.60fps.mp4_scale_1.1_inclip;11.494683908046001;11.630639534883727;11.36622159090906;11.630668604651154;11.628779069767408;11.83517751479288;11.698713450292374;11.698947368421035;11.767558823529415;11.701871345029264;11.36761363636362;11.63438953488371
19:44:10 INFO - PID 3998 | |16;1080p.60fps.mp4_scale_2_startup;11.279624060150393;11.113185185185204;11.408307984790882;11.279191729323307;11.237921348314584;11.155111524163564;11.03167279411764;11.031029411764715;11.197835820895511;11.281315789473691;11.19589552238806;10.952481751824829
19:44:10 INFO - PID 3998 | |17;1080p.60fps.mp4_scale_2_inclip;10.812081081081084;10.582539682539675;10.990274725274743;10.811945945945942;10.933497267759572;10.696978609625702;10.639574468085096;10.931639344262283;10.812432432432448;10.811972972972955;10.932513661202194;10.474267015706802
19:44:10 INFO - PID 3998 | __end_tp_report
19:44:10 INFO - PID 3998 | __start_cc_report
19:44:10 INFO - PID 3998 | _x_x_mozilla_cycle_collect,605
19:44:10 INFO - PID 3998 | __end_cc_report
19:44:10 INFO - PID 3998 | __startTimestamp1509590650263__endTimestamp
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | ------- Summary: start -------
19:44:10 INFO - PID 3998 | Number of tests: 18
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#0] 240p.120fps.mp4_scale_1_startup Cycles:12 Average:1.68 Median:1.68 stddev:0.00 (0.2%) stddev-sans-first:0.00
19:44:10 INFO - PID 3998 | 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
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#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
19:44:10 INFO - PID 3998 | 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
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#2] 240p.120fps.mp4_scale_1.1_startup Cycles:12 Average:1.75 Median:1.75 stddev:0.02 (1.0%) stddev-sans-first:0.02
19:44:10 INFO - PID 3998 | Values: 1.7 1.7 1.7 1.7 1.8 1.7 1.8 1.8 1.7 1.7 1.8 1.7
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#3] 240p.120fps.mp4_scale_1.1_inclip Cycles:12 Average:1.73 Median:1.74 stddev:0.02 (1.2%) stddev-sans-first:0.02
19:44:10 INFO - PID 3998 | Values: 1.8 1.7 1.7 1.7 1.8 1.7 1.8 1.7 1.7 1.7 1.7 1.7
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#4] 240p.120fps.mp4_scale_2_startup Cycles:12 Average:4.17 Median:4.20 stddev:0.05 (1.2%) stddev-sans-first:0.05
19:44:10 INFO - PID 3998 | Values: 4.1 4.1 4.2 4.1 4.2 4.2 4.2 4.2 4.3 4.2 4.1 4.2
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#5] 240p.120fps.mp4_scale_2_inclip Cycles:12 Average:4.12 Median:4.16 stddev:0.15 (3.5%) stddev-sans-first:0.15
19:44:10 INFO - PID 3998 | Values: 4.2 4.1 4.2 4.2 4.1 3.7 4.0 4.1 4.2 4.1 4.1 4.3
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#6] 480p.60fps.webm_scale_1_startup Cycles:12 Average:3.60 Median:3.62 stddev:0.08 (2.1%) stddev-sans-first:0.07
19:44:10 INFO - PID 3998 | Values: 3.5 3.5 3.5 3.7 3.6 3.6 3.7 3.6 3.7 3.7 3.7 3.5
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#7] 480p.60fps.webm_scale_1_inclip Cycles:12 Average:3.54 Median:3.55 stddev:0.08 (2.2%) stddev-sans-first:0.08
19:44:10 INFO - PID 3998 | Values: 3.5 3.4 3.4 3.6 3.5 3.5 3.6 3.5 3.6 3.6 3.6 3.5
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#8] 480p.60fps.webm_scale_1.1_startup Cycles:12 Average:5.67 Median:5.71 stddev:0.09 (1.6%) stddev-sans-first:0.09
19:44:10 INFO - PID 3998 | Values: 5.6 5.7 5.6 5.7 5.7 5.7 5.5 5.5 5.7 5.7 5.8 5.8
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#9] 480p.60fps.webm_scale_1.1_inclip Cycles:12 Average:5.57 Median:5.63 stddev:0.08 (1.5%) stddev-sans-first:0.09
19:44:10 INFO - PID 3998 | Values: 5.6 5.6 5.5 5.7 5.6 5.6 5.4 5.5 5.6 5.6 5.6 5.5
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#10] 480p.60fps.webm_scale_2_startup Cycles:12 Average:9.61 Median:9.62 stddev:0.29 (3.0%) stddev-sans-first:0.27
19:44:10 INFO - PID 3998 | Values: 9.2 10.1 9.6 9.8 9.2 9.7 9.7 9.6 9.2 9.6 9.6 10.0
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#11] 480p.60fps.webm_scale_2_inclip Cycles:12 Average:9.39 Median:9.57 stddev:0.28 (3.0%) stddev-sans-first:0.29
19:44:10 INFO - PID 3998 | Values: 9.6 9.6 9.6 8.9 9.2 9.6 9.1 9.1 9.5 9.1 9.6 9.8
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#12] 1080p.60fps.mp4_scale_1_startup Cycles:12 Average:11.07 Median:11.07 stddev:0.13 (1.1%) stddev-sans-first:0.12
19:44:10 INFO - PID 3998 | Values: 11.2 10.9 11.0 11.1 10.9 11.1 11.3 11.0 11.2 11.1 11.0 11.0
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#13] 1080p.60fps.mp4_scale_1_inclip Cycles:12 Average:10.56 Median:10.58 stddev:0.09 (0.8%) stddev-sans-first:0.09
19:44:10 INFO - PID 3998 | Values: 10.5 10.5 10.5 10.4 10.6 10.6 10.5 10.5 10.6 10.8 10.6 10.6
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#14] 1080p.60fps.mp4_scale_1.1_startup Cycles:12 Average:12.11 Median:12.10 stddev:0.15 (1.3%) stddev-sans-first:0.16
19:44:10 INFO - PID 3998 | Values: 12.0 12.0 12.3 12.1 12.0 12.1 12.3 12.2 12.3 11.8 12.1 12.1
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#15] 1080p.60fps.mp4_scale_1.1_inclip Cycles:12 Average:11.62 Median:11.67 stddev:0.15 (1.2%) stddev-sans-first:0.15
19:44:10 INFO - PID 3998 | Values: 11.5 11.6 11.4 11.6 11.6 11.8 11.7 11.7 11.8 11.7 11.4 11.6
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#16] 1080p.60fps.mp4_scale_2_startup Cycles:12 Average:11.18 Median:11.22 stddev:0.13 (1.2%) stddev-sans-first:0.13
19:44:10 INFO - PID 3998 | Values: 11.3 11.1 11.4 11.3 11.2 11.2 11.0 11.0 11.2 11.3 11.2 11.0
19:44:10 INFO - PID 3998 |
19:44:10 INFO - PID 3998 | [#17] 1080p.60fps.mp4_scale_2_inclip Cycles:12 Average:10.79 Median:10.81 stddev:0.16 (1.5%) stddev-sans-first:0.17
19:44:10 INFO - PID 3998 | Values: 10.8 10.6 11.0 10.8 10.9 10.7 10.6 10.9 10.8 10.8 10.9 10.5
19:44:10 INFO - PID 3998 | -------- Summary: end --------
19:44:10 INFO - PID 3998 |
19:44:10 INFO - TEST-INFO | 3998: exit 0
19:44:10 INFO - TEST-OK | basic_compositor_video | took 565034ms
19:44:10 INFO - TEST-START | glvideo
19:44:10 INFO - Initialising browser for glvideo test...
19:44:10 INFO - Application command: /builds/slave/test/build/application/firefox/firefox http://localhost:44356/getInfo.html -profile /tmp/tmpU_XPkX/profile
19:44:10 INFO - TEST-INFO | started process 5313 (/builds/slave/test/build/application/firefox/firefox http://localhost:44356/getInfo.html)
19:44:16 INFO - TEST-INFO | 5313: exit 0
19:44:16 INFO - Browser initialized.
19:44:16 INFO - Running cycle 1/1 for glvideo test...
19:44:16 INFO - Using env: {'DISPLAY': ':0',
19:44:16 INFO - 'HOME': '/home/cltbld',
19:44:16 INFO - 'JSGC_DISABLE_POISONING': '1',
19:44:16 INFO - 'LANG': 'en_US.UTF-8',
19:44:16 INFO - 'LANGUAGE': 'en_US:en',
19:44:16 INFO - 'LD_LIBRARY_PATH': '/builds/slave/test/build/application/firefox',
19:44:16 INFO - 'LOGNAME': 'cltbld',
19:44:16 INFO - 'MAIL': '/var/mail/cltbld',
19:44:16 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir',
19:44:16 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk',
19:44:16 INFO - 'MOZ_CRASHREPORTER': '1',
19:44:16 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1',
19:44:16 INFO - 'MOZ_DISABLE_NONLOCAL_CONNECTIONS': '1',
19:44:16 INFO - 'MOZ_NO_REMOTE': '1',
19:44:16 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir',
19:44:16 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript',
19:44:16 INFO - 'NO_EM_RESTART': '1',
19:44:16 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games',
19:44:16 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json',
19:44:16 INFO - 'PWD': '/builds/slave/test',
19:44:16 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos',
19:44:16 INFO - 'RUST_BACKTRACE': 'full',
19:44:16 INFO - 'SCRIPTSPATH': '/builds/slave/test/scripts',
19:44:16 INFO - 'SHELL': '/bin/bash',
19:44:16 INFO - 'SHLVL': '1',
19:44:16 INFO - 'STYLO_FORCE_DISABLED': '1',
19:44:16 INFO - 'TERM': 'linux',
19:44:16 INFO - 'TMOUT': '86400',
19:44:16 INFO - 'USER': 'cltbld',
19:44:16 INFO - 'XDG_SESSION_COOKIE': '826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977',
19:44:16 INFO - 'XPCOM_DEBUG_BREAK': 'warn',
19:44:16 INFO - '_': '/tools/buildbot/bin/python'}
19:44:16 INFO - TEST-INFO | started process 5582 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpU_XPkX/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/webgl/glvideo.manifest.develop -tpnoisy -tploadnocache -tpcycles 1 -tppagecycles 5)
19:44:17 INFO - PID 5582 |
19:44:17 INFO - PID 5582 | (/builds/slave/test/build/application/firefox/firefox:5633): Pango-WARNING **: error opening config file '/home/cltbld/.pangorc': Permission denied
19:44:17 INFO - PID 5582 |
19:44:19 INFO - PID 5582 | [talos glvideo result] Mean tick time across 100 ticks: 7.607349999999999 ms
19:44:19 INFO - PID 5582 | Cycle 1(1): loaded http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html)
19:44:20 INFO - PID 5582 | [talos glvideo result] Mean tick time across 100 ticks: 6.5602 ms
19:44:20 INFO - PID 5582 | Cycle 1(2): loaded http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html)
19:44:22 INFO - PID 5582 | [talos glvideo result] Mean tick time across 100 ticks: 6.568300000000001 ms
19:44:22 INFO - PID 5582 | Cycle 1(3): loaded http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html)
19:44:23 INFO - PID 5582 | [talos glvideo result] Mean tick time across 100 ticks: 6.600649999999999 ms
19:44:23 INFO - PID 5582 | Cycle 1(4): loaded http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html)
19:44:24 INFO - PID 5582 | [talos glvideo result] Mean tick time across 100 ticks: 6.606700000000001 ms
19:44:24 INFO - PID 5582 | Cycle 1(5): loaded http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html (next: http://localhost:44356/tests/webgl/benchmarks/video/video_upload.html)
19:44:25 INFO - PID 5582 | __start_tp_report
19:44:25 INFO - PID 5582 | _x_x_mozilla_page_load
19:44:25 INFO - PID 5582 | _x_x_mozilla_page_load_details
19:44:25 INFO - PID 5582 | |i|pagename|runs|
19:44:25 INFO - PID 5582 | |0;Mean tick time across 100 ticks: ;7.607349999999999;6.5602;6.568300000000001;6.600649999999999;6.606700000000001
19:44:25 INFO - PID 5582 | __end_tp_report
19:44:25 INFO - PID 5582 | __start_cc_report
19:44:25 INFO - PID 5582 | _x_x_mozilla_cycle_collect,285
19:44:25 INFO - PID 5582 | __end_cc_report
19:44:25 INFO - PID 5582 | __startTimestamp1509590665141__endTimestamp
19:44:25 INFO - PID 5582 |
19:44:25 INFO - PID 5582 | ------- Summary: start -------
19:44:25 INFO - PID 5582 | Number of tests: 1
19:44:25 INFO - PID 5582 |
19:44:25 INFO - PID 5582 | [#0] Mean tick time across 100 ticks: Cycles:5 Average:6.79 Median:6.60 stddev:0.46 (6.9%) stddev-sans-first:0.02
19:44:25 INFO - PID 5582 | Values: 7.6 6.6 6.6 6.6 6.6
19:44:25 INFO - PID 5582 | -------- Summary: end --------
19:44:25 INFO - PID 5582 |
19:44:25 INFO - PID 5582 | *** UTM:SVC TimerManager:registerTimer called after profile-before-change notification. Ignoring timer registration for id: telemetry_modules_ping
19:44:25 INFO - TEST-INFO | 5582: exit 0
19:44:25 INFO - TEST-OK | glvideo | took 14948ms
19:44:25 INFO - SUITE-END | took 579s
19:44:26 INFO - Completed test suite (00:09:40)
19:44:26 INFO - PERFHERDER_DATA: {"framework": {"name": "talos"}, "suites": [{"extraOptions": ["e10s", "stylo_disabled"], "name": "basic_compositor_video", "lowerIsBetter": true, "alertThreshold": 2.0, "value": 5.5457377991633265, "subtests": [{"name": "240p.120fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.689349662162162, 1.6818553811659191, 1.67935086737549, 1.6810420168067228, 1.6893975225225226, 1.6858455056179777, 1.6781739373601792, 1.6831968592260236, 1.68078431372549, 1.6765782122905026, 1.6849915777653006, 1.679135422495803], "value": 1.6810420168067228, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.6673208333333331, 1.6725459866220742, 1.6718379281537177, 1.6713032581453635, 1.6659741881765195, 1.6682944120100085, 1.6675791666666668, 1.66826105087573, 1.6718295739348374, 1.6723411371237462, 1.6725209030100332, 1.6726672240802674], "value": 1.6718295739348374, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.7404727378190255, 1.7487441724941721, 1.7404321345707656, 1.7304238754325256, 1.7672055359246173, 1.741755658734765, 1.7783135743924128, 1.7699852507374632, 1.7254715353651526, 1.7433178384660082, 1.7667844522968204, 1.7433788495061013], "value": 1.7433788495061013, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [1.752896581945662, 1.7183333333333344, 1.71731330472103, 1.7188831615120272, 1.765269196822595, 1.708343296327925, 1.7640520282186953, 1.7428135888501735, 1.7023957446808515, 1.7339991334488742, 1.7243663793103443, 1.7363454861111114], "value": 1.7243663793103443, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.087656675749319, 4.099528688524592, 4.202233893557423, 4.110178082191779, 4.20773492286115, 4.2023389355742315, 4.203123249299721, 4.196237762237762, 4.255872340425531, 4.172684283727399, 4.1450897790055246, 4.197062937062936], "value": 4.197062937062936, "unit": "ms/frame"}, {"name": "240p.120fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [4.1856380753138085, 4.142318840579709, 4.19308176100629, 4.203371848739496, 4.099149590163935, 3.7181691449814127, 4.017851405622489, 4.134163223140499, 4.228720930232557, 4.107094455852158, 4.141749482401656, 4.292736051502148], "value": 4.141749482401656, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.5096842105263164, 3.530623529411763, 3.5425265643447466, 3.672588739290087, 3.576781883194279, 3.576436233611441, 3.6587195121951237, 3.5592170818505338, 3.658987804878052, 3.6955172413793105, 3.722940446650125, 3.510046783625733], "value": 3.576781883194279, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [3.4558203799654548, 3.4438123924268496, 3.449181034482761, 3.5853494623655915, 3.4915183246073287, 3.5098859649122844, 3.618019891500903, 3.509561403508773, 3.624320652173913, 3.6440163934426204, 3.6313793103448266, 3.4791130434782573], "value": 3.5098859649122844, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.577760223048325, 5.692931688804553, 5.556351851851852, 5.694345351043647, 5.705275665399244, 5.725868320610687, 5.545415896487992, 5.547033271719038, 5.737026768642448, 5.715780952380952, 5.758685220729363, 5.791882239382239], "value": 5.705275665399244, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [5.602703081232495, 5.572952646239551, 5.527417127071821, 5.651355932203384, 5.634211267605624, 5.6191853932584275, 5.376545698924724, 5.54198060941829, 5.635816901408451, 5.633971830985919, 5.634985915492963, 5.465150273224041], "value": 5.6191853932584275, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.205659509202448, 10.138902027027033, 9.55695859872611, 9.773094462540705, 9.231646153846153, 9.711569579288026, 9.71116504854369, 9.616121794871793, 9.23213846153846, 9.618253205128207, 9.58632587859425, 9.967043189368765], "value": 9.618253205128207, "unit": "ms/frame"}, {"name": "480p.60fps.webm_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [9.619663461538476, 9.571722488038267, 9.57090909090909, 8.89366666666667, 9.22018433179723, 9.574593301435407, 9.13742009132419, 9.093386363636355, 9.525333333333332, 9.094090909090912, 9.574210526315781, 9.805416666666668], "value": 9.525333333333332, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.195317164179109, 10.871920289855078, 10.99190476190478, 11.071678966789678, 10.949817518248162, 11.115981481481477, 11.323188679245298, 11.03104779411766, 11.194421641791044, 11.070387453874542, 11.031783088235295, 10.952664233576638], "value": 11.031783088235295, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.529894736842106, 10.473795811518338, 10.529157894736846, 10.418984374999999, 10.585555555555585, 10.583095238095247, 10.528210526315755, 10.472670157068057, 10.640984042553178, 10.754973118279546, 10.585449735449743, 10.582619047619076], "value": 10.582619047619076, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [12.000739999999992, 12.001799999999989, 12.298586065573783, 12.097782258064516, 12.049618473895595, 12.09963709677419, 12.299323770491817, 12.195569105691058, 12.296741803278683, 11.767019607843123, 12.09975806451612, 12.097620967741932], "value": 12.09963709677419, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_1.1_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.494683908046001, 11.630639534883727, 11.36622159090906, 11.630668604651154, 11.628779069767408, 11.83517751479288, 11.698713450292374, 11.698947368421035, 11.767558823529415, 11.701871345029264, 11.36761363636362, 11.63438953488371], "value": 11.63438953488371, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_startup", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [11.279624060150393, 11.113185185185204, 11.408307984790882, 11.279191729323307, 11.237921348314584, 11.155111524163564, 11.03167279411764, 11.031029411764715, 11.197835820895511, 11.281315789473691, 11.19589552238806, 10.952481751824829], "value": 11.19589552238806, "unit": "ms/frame"}, {"name": "1080p.60fps.mp4_scale_2_inclip", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [10.812081081081084, 10.582539682539675, 10.990274725274743, 10.811945945945942, 10.933497267759572, 10.696978609625702, 10.639574468085096, 10.931639344262283, 10.812432432432448, 10.811972972972955, 10.932513661202194, 10.474267015706802], "value": 10.811972972972955, "unit": "ms/frame"}]}, {"lowerIsBetter": true, "subtests": [{"name": "Mean tick time across 100 ticks: ", "lowerIsBetter": true, "alertThreshold": 2.0, "replicates": [7.607349999999999, 6.5602, 6.568300000000001, 6.600649999999999, 6.606700000000001], "value": 6.584474999999999, "unit": "ms"}], "extraOptions": ["e10s", "stylo_disabled"], "name": "glvideo", "alertThreshold": 2.0}]}
19:44:26 INFO - Return code: 0
19:44:26 INFO - Validating PERFHERDER_DATA against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json
19:44:26 INFO - # TBPL SUCCESS #
19:44:26 INFO - Running post-action listener: _package_coverage_data
19:44:26 INFO - Running post-action listener: _resource_record_post_action
19:44:26 INFO - [mozharness: 2017-11-02 02:44:26.296599Z] Finished run-tests step (success)
19:44:26 INFO - Running post-run listener: _resource_record_post_run
19:44:26 INFO - Total resource usage - Wall time: 600s; CPU: 39.0%; Read bytes: 17326080; Write bytes: 316334080; Read time: 4072; Write time: 296472
19:44:26 INFO - TinderboxPrint: CPU usage
38.7%
19:44:26 INFO - TinderboxPrint: I/O read bytes / time
17,326,080 / 4,072
19:44:26 INFO - TinderboxPrint: I/O write bytes / time
316,334,080 / 296,472
19:44:26 INFO - TinderboxPrint: CPU idle
2,886.2 (61.3%)
19:44:26 INFO - TinderboxPrint: CPU system
307.0 (6.5%)
19:44:26 INFO - TinderboxPrint: CPU user
1,492.8 (31.7%)
19:44:26 INFO - TinderboxPrint: Swap in / out
0 / 0
19:44:26 INFO - install - Wall time: 19s; CPU: 13.0%; Read bytes: 0; Write bytes: 4284416; Read time: 0; Write time: 344
19:44:26 INFO - setup-mitmproxy - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
19:44:26 INFO - run-tests - Wall time: 581s; CPU: 40.0%; Read bytes: 17305600; Write bytes: 311840768; Read time: 4052; Write time: 296108
19:44:26 INFO - Running post-run listener: _upload_blobber_files
19:44:26 INFO - Blob upload gear active.
19:44:26 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir.
19:44:26 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
19:44:26 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']
19:44:26 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
19:44:26 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:339: SNIMissingWarning: An HTTPS request has been made, but the SNI (Subject Name Indication) extension to TLS is not available on this platform. This may cause the server to present an incorrect TLS certificate, which can cause validation failures. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:26 INFO - SNIMissingWarning
19:44:26 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:26 INFO - InsecurePlatformWarning
19:44:26 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.)
19:44:26 INFO - SubjectAltNameWarning
19:44:27 INFO - (blobuploader) - INFO - Open directory for files ...
19:44:27 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/perfherder-data.json ...
19:44:27 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
19:44:27 INFO - (blobuploader) - INFO - Uploading, attempt #1.
19:44:27 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:27 INFO - InsecurePlatformWarning
19:44:27 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.)
19:44:27 INFO - SubjectAltNameWarning
19:44:27 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:27 INFO - InsecurePlatformWarning
19:44:27 INFO - (blobuploader) - INFO - TinderboxPrint: perfherder-data.json: uploaded
19:44:27 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded!
19:44:27 INFO - (blobuploader) - INFO - Done attempting.
19:44:27 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_raw.log ...
19:44:27 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
19:44:27 INFO - (blobuploader) - INFO - Uploading, attempt #1.
19:44:28 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:28 INFO - InsecurePlatformWarning
19:44:28 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.)
19:44:28 INFO - SubjectAltNameWarning
19:44:28 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:28 INFO - InsecurePlatformWarning
19:44:28 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_raw.log: uploaded
19:44:28 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded!
19:44:28 INFO - (blobuploader) - INFO - Done attempting.
19:44:28 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/g4-stylo-disabled-e10s_errorsummary.log ...
19:44:28 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
19:44:28 INFO - (blobuploader) - INFO - Uploading, attempt #1.
19:44:28 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:28 INFO - InsecurePlatformWarning
19:44:29 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.)
19:44:29 INFO - SubjectAltNameWarning
19:44:29 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:29 INFO - InsecurePlatformWarning
19:44:29 INFO - (blobuploader) - INFO - TinderboxPrint: g4-stylo-disabled-e10s_errorsummary.log: uploaded
19:44:29 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded!
19:44:29 INFO - (blobuploader) - INFO - Done attempting.
19:44:29 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ...
19:44:29 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com
19:44:29 INFO - (blobuploader) - INFO - Uploading, attempt #1.
19:44:29 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:29 INFO - InsecurePlatformWarning
19:44:30 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/connection.py:344: SubjectAltNameWarning: Certificate for blobupload.elasticbeanstalk.com has no `subjectAltName`, falling back to check for a `commonName` for now. This feature is being removed by major browsers and deprecated by RFC 2818. (See https://github.com/shazow/urllib3/issues/497 for details.)
19:44:30 INFO - SubjectAltNameWarning
19:44:32 INFO - /builds/slave/test/build/venv/lib/python2.7/site-packages/urllib3/util/ssl_.py:137: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. You can upgrade to a newer version of Python to solve this. For more information, see https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
19:44:32 INFO - InsecurePlatformWarning
19:44:32 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded
19:44:32 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded!
19:44:32 INFO - (blobuploader) - INFO - Done attempting.
19:44:32 INFO - (blobuploader) - INFO - Iteration through files over.
19:44:32 INFO - Return code: 0
19:44:32 INFO - rmtree: /builds/slave/test/build/uploaded_files.json
19:44:32 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1
19:44:32 INFO - Setting buildbot property blobber_files to {"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/d47c503933c75149a0d979211764f20c8258849b98bf0432e27c64e6d24a3c665e15a3454a0bbee0bec682d4af8d74f5c0a6e074d26f14425ed58c4f6496a501", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/2cab909688bd55ccfe390cd2fadc2723a1c64215a6e862401ea0b66f2bba3baa23b93b4fc1e6377733595bd12ce95b7e38a5967df3565c47ce1770de061b9405", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/d32ec166f7c747aa1e314a850b2d000bae8c9e2b553bfbcaa063b993aeb102392d68be90c59b8ada5f189a9dba80408db017079a35324659df03d68c1bed54db", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5095a80d8ddd4cdc118e58c0414006caa8d65d35c6b91a14d9977354db7fc963aa401a16d9f1d776cd4bac4f2b1b9cc4e64bd75da9d7d026489d2b6d1ccfeced"}
19:44:32 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files
19:44:32 INFO - Writing to file /builds/slave/test/properties/blobber_files
19:44:32 INFO - Contents:
19:44:32 INFO - blobber_files:{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/d47c503933c75149a0d979211764f20c8258849b98bf0432e27c64e6d24a3c665e15a3454a0bbee0bec682d4af8d74f5c0a6e074d26f14425ed58c4f6496a501", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/2cab909688bd55ccfe390cd2fadc2723a1c64215a6e862401ea0b66f2bba3baa23b93b4fc1e6377733595bd12ce95b7e38a5967df3565c47ce1770de061b9405", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/d32ec166f7c747aa1e314a850b2d000bae8c9e2b553bfbcaa063b993aeb102392d68be90c59b8ada5f189a9dba80408db017079a35324659df03d68c1bed54db", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5095a80d8ddd4cdc118e58c0414006caa8d65d35c6b91a14d9977354db7fc963aa401a16d9f1d776cd4bac4f2b1b9cc4e64bd75da9d7d026489d2b6d1ccfeced"}
19:44:32 INFO - Running post-run listener: copy_logs_to_upload_dir
19:44:32 INFO - Copying logs to upload dir...
19:44:32 INFO - mkdir: /builds/slave/test/build/upload/logs
19:44:32 INFO - Copying logs to upload dir...
program finished with exit code 0
elapsedTime=671.364072
========= master_lag: 0.03 =========
========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' (results: 0, elapsed: 11 mins, 11 secs) (at 2017-11-01 19:44:32.718792) =========
========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-01 19:44:32.722601) =========
bash -c 'for file in `ls -1`; do cat $file; done'
in dir /builds/slave/test/properties (timeout 1200 secs)
watching logfiles {}
argv: ['bash', '-c', 'for file in `ls -1`; do cat $file; done']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test/properties
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977
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/d47c503933c75149a0d979211764f20c8258849b98bf0432e27c64e6d24a3c665e15a3454a0bbee0bec682d4af8d74f5c0a6e074d26f14425ed58c4f6496a501", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/2cab909688bd55ccfe390cd2fadc2723a1c64215a6e862401ea0b66f2bba3baa23b93b4fc1e6377733595bd12ce95b7e38a5967df3565c47ce1770de061b9405", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/d32ec166f7c747aa1e314a850b2d000bae8c9e2b553bfbcaa063b993aeb102392d68be90c59b8ada5f189a9dba80408db017079a35324659df03d68c1bed54db", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5095a80d8ddd4cdc118e58c0414006caa8d65d35c6b91a14d9977354db7fc963aa401a16d9f1d776cd4bac4f2b1b9cc4e64bd75da9d7d026489d2b6d1ccfeced"}
build_url:https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2
program finished with exit code 0
elapsedTime=0.011234
build_url: 'https://queue.taskcluster.net/v1/task/Yy3Wn474SyWbRd4PgOqoiw/artifacts/public/build/target.tar.bz2'
blobber_files: '{"perfherder-data.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/d47c503933c75149a0d979211764f20c8258849b98bf0432e27c64e6d24a3c665e15a3454a0bbee0bec682d4af8d74f5c0a6e074d26f14425ed58c4f6496a501", "g4-stylo-disabled-e10s_raw.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/2cab909688bd55ccfe390cd2fadc2723a1c64215a6e862401ea0b66f2bba3baa23b93b4fc1e6377733595bd12ce95b7e38a5967df3565c47ce1770de061b9405", "g4-stylo-disabled-e10s_errorsummary.log": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/d32ec166f7c747aa1e314a850b2d000bae8c9e2b553bfbcaa063b993aeb102392d68be90c59b8ada5f189a9dba80408db017079a35324659df03d68c1bed54db", "resource-usage.json": "https://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox-Non-PGO/sha512/5095a80d8ddd4cdc118e58c0414006caa8d65d35c6b91a14d9977354db7fc963aa401a16d9f1d776cd4bac4f2b1b9cc4e64bd75da9d7d026489d2b6d1ccfeced"}'
========= master_lag: 0.02 =========
========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-11-01 19:44:32.751896) =========
========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-01 19:44:32.752245) =========
rm -f oauth.txt
in dir /builds/slave/test/. (timeout 1200 secs)
watching logfiles {}
argv: ['rm', '-f', 'oauth.txt']
environment:
DISPLAY=:0
HOME=/home/cltbld
LANG=en_US.UTF-8
LANGUAGE=en_US:en
LOGNAME=cltbld
MAIL=/var/mail/cltbld
MOZ_CRASHREPORTER_NO_REPORT=1
MOZ_NO_REMOTE=1
NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript
NO_EM_RESTART=1
PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
PWD=/builds/slave/test
SHELL=/bin/bash
SHLVL=1
TERM=linux
TMOUT=86400
USER=cltbld
XDG_SESSION_COOKIE=826874ccc97bd7bf541b4875000001d5-1509589986.412319-37270977
XPCOM_DEBUG_BREAK=warn
_=/tools/buildbot/bin/python
using PTY: False
program finished with exit code 0
elapsedTime=0.004656
========= master_lag: 0.08 =========
========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-11-01 19:44:32.837534) =========
========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-01 19:44:32.838021) =========
========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-11-01 19:44:32.838499) =========
========= Total master_lag: 0.20 =========