builder: mozilla-central_ubuntu64_hw_test-dromaeojs-pgo slave: talos-linux64-ix-015 starttime: 1487335477.16 results: retry (5) revision: 975ce5d8f7d818cc3cd32b134e4010577d3208cd ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.161056) ========= master: http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.161489) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.161793) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.179095) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.179457) ========= 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=20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False --2017-02-17 04:44:37-- 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% 35.7M=0s 2017-02-17 04:44:37 (35.7 MB/s) - `archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.094645 ========= master_lag: 0.01 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.288377) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.288738) ========= 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=20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.015228 ========= master_lag: 0.04 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.339768) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:37.340242) ========= bash -c 'python archiver_client.py mozharness --repo mozilla-central --rev 975ce5d8f7d818cc3cd32b134e4010577d3208cd --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 975ce5d8f7d818cc3cd32b134e4010577d3208cd --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=20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 2017-02-17 04:44:37,450 truncating revision to first 12 chars 2017-02-17 04:44:37,451 Setting DEBUG logging. 2017-02-17 04:44:37,451 attempt 1/10 2017-02-17 04:44:37,451 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/mozilla-central/975ce5d8f7d8?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-02-17 04:44:37,864 unpacking tar archive at: mozilla-central-975ce5d8f7d8/testing/mozharness/ program finished with exit code 0 elapsedTime=0.686320 ========= master_lag: 0.04 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:38.070783) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:38.071118) ========= script_repo_revision: 975ce5d8f7d818cc3cd32b134e4010577d3208cd ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:38.071479) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:38.071738) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-02-17 04:44:38.082053) ========= ========= Started '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' failed (results: 5, elapsed: 19 mins, 58 secs) (at 2017-02-17 04:44:38.082404) ========= /tools/buildbot/bin/python scripts/scripts/talos_script.py --suite dromaeojs --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox in dir /builds/slave/test/. (timeout 3600 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', 'scripts/scripts/talos_script.py', '--suite', 'dromaeojs', '--add-option', '--webServer,localhost', '--branch-name', 'Firefox', '--cfg', 'talos/linux_config.py', '--download-symbols', 'ondemand', '--use-talos-json', '--blob-upload-branch', 'Firefox'] environment: DISPLAY=:0 HOME=/home/cltbld LANG=en_US.UTF-8 LANGUAGE=en_US:en LOGNAME=cltbld MAIL=/var/mail/cltbld MOZ_CRASHREPORTER_NO_REPORT=1 MOZ_NO_REMOTE=1 NODE_PATH=/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript NO_EM_RESTART=1 PATH=/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test SHELL=/bin/bash SHLVL=1 TERM=linux TMOUT=86400 USER=cltbld XDG_SESSION_COOKIE=20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False 04:44:38 INFO - MultiFileLogger online at 20170217 04:44:38 in /builds/slave/test 04:44:38 INFO - Run as scripts/scripts/talos_script.py --suite dromaeojs --add-option --webServer,localhost --branch-name Firefox --cfg talos/linux_config.py --download-symbols ondemand --use-talos-json --blob-upload-branch Firefox 04:44:38 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 04:44:38 INFO - {'append_to_log': False, 04:44:38 INFO - 'base_work_dir': '/builds/slave/test', 04:44:38 INFO - 'blob_upload_branch': 'Firefox', 04:44:38 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 04:44:38 INFO - 'branch': 'Firefox', 04:44:38 INFO - 'buildbot_json_path': 'buildprops.json', 04:44:38 INFO - 'config_files': ('talos/linux_config.py',), 04:44:38 INFO - 'default_actions': ('clobber', 04:44:38 INFO - 'read-buildbot-config', 04:44:38 INFO - 'download-and-extract', 04:44:38 INFO - 'populate-webroot', 04:44:38 INFO - 'create-virtualenv', 04:44:38 INFO - 'install', 04:44:38 INFO - 'run-tests'), 04:44:38 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 04:44:38 INFO - 'download_minidump_stackwalk': True, 04:44:38 INFO - 'download_symbols': 'ondemand', 04:44:38 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 04:44:38 INFO - 'tooltool.py': '/tools/tooltool.py', 04:44:38 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 04:44:38 INFO - '/tools/misc-python/virtualenv.py')}, 04:44:38 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 04:44:38 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 04:44:38 INFO - 'installer_path': 'installer.exe', 04:44:38 INFO - 'log_level': 'info', 04:44:38 INFO - 'log_name': 'talos', 04:44:38 INFO - 'log_to_console': True, 04:44:38 INFO - 'minidump_stackwalk_path': 'linux64-minidump_stackwalk', 04:44:38 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/linux64/releng.manifest', 04:44:38 INFO - 'opt_config_files': (), 04:44:38 INFO - 'pip_index': False, 04:44:38 INFO - 'sps_profile': False, 04:44:38 INFO - 'sps_profile_interval': 0, 04:44:38 INFO - 'suite': 'dromaeojs', 04:44:38 INFO - 'system_bits': '32', 04:44:38 INFO - 'talos_extra_options': ('--webServer', 'localhost'), 04:44:38 INFO - 'title': 'talos-linux64-ix-015', 04:44:38 INFO - 'tooltool_cache': '/builds/tooltool_cache', 04:44:38 INFO - 'use_talos_json': True, 04:44:38 INFO - 'virtualenv_path': '/builds/slave/test/build/venv', 04:44:38 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 04:44:38 INFO - 'work_dir': 'build'} 04:44:38 INFO - [mozharness: 2017-02-17 12:44:38.290740Z] Running clobber step. 04:44:38 INFO - Running pre-action listener: _resource_record_pre_action 04:44:38 INFO - Running main action method: clobber 04:44:38 INFO - rmtree: /builds/slave/test/build 04:44:38 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 04:44:39 INFO - Running post-action listener: _resource_record_post_action 04:44:39 INFO - [mozharness: 2017-02-17 12:44:39.215689Z] Finished clobber step (success) 04:44:39 INFO - [mozharness: 2017-02-17 12:44:39.215790Z] Running read-buildbot-config step. 04:44:39 INFO - Running pre-action listener: _resource_record_pre_action 04:44:39 INFO - Running main action method: read_buildbot_config 04:44:39 INFO - Using buildbot properties: 04:44:39 INFO - { 04:44:39 INFO - "project": "", 04:44:39 INFO - "product": "firefox", 04:44:39 INFO - "who": "cbook@mozilla.com", 04:44:39 INFO - "installer_path": "public/build/target.tar.bz2", 04:44:39 INFO - "builddir": "mozilla-central_ubuntu64_hw_test-dromaeojs", 04:44:39 INFO - "repository": "https://hg.mozilla.org/mozilla-central/", 04:44:39 INFO - "buildername": "Ubuntu HW 12.04 x64 mozilla-central pgo talos dromaeojs", 04:44:39 INFO - "stage_platform": "linux64-pgo", 04:44:39 INFO - "basedir": "/builds/slave/test", 04:44:39 INFO - "buildnumber": 36, 04:44:39 INFO - "platform": "ubuntu64_hw", 04:44:39 INFO - "master": "http://buildbot-master105.bb.releng.scl3.mozilla.com:8201/", 04:44:39 INFO - "slavebuilddir": "test", 04:44:39 INFO - "taskId": "L4yqJfFbTgaWQ1lx1vkyfw", 04:44:39 INFO - "branch": "mozilla-central", 04:44:39 INFO - "script_repo_revision": "production", 04:44:39 INFO - "revision": "975ce5d8f7d818cc3cd32b134e4010577d3208cd", 04:44:39 INFO - "slavename": "talos-linux64-ix-015", 04:44:39 INFO - "repo_path": "mozilla-central" 04:44:39 INFO - } 04:44:39 INFO - Finding installer, test and symbols from parent task. 04:44:39 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/L4yqJfFbTgaWQ1lx1vkyfw'}, attempt #1 04:44:39 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/L4yqJfFbTgaWQ1lx1vkyfw'}, attempt #1 04:44:40 INFO - Task dependencies: bkheuIwGQzWQeKLtfoJKuA 04:44:40 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA'}, attempt #1 04:44:40 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2 04:44:40 INFO - Set test_url: https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/test_packages.json 04:44:40 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.crashreporter-symbols.zip 04:44:40 INFO - Running post-action listener: _resource_record_post_action 04:44:40 INFO - [mozharness: 2017-02-17 12:44:40.625677Z] Finished read-buildbot-config step (success) 04:44:40 INFO - [mozharness: 2017-02-17 12:44:40.625897Z] Running download-and-extract step. 04:44:40 INFO - Running pre-action listener: _resource_record_pre_action 04:44:40 INFO - Running main action method: download_and_extract 04:44:40 INFO - mkdir: /builds/slave/test/build/tests 04:44:40 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:44:40 INFO - trying https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.test_packages.json 04:44:40 INFO - Downloading https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.test_packages.json to /builds/slave/test/build/target.test_packages.json 04:44:40 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.test_packages.json', 'file_name': '/builds/slave/test/build/target.test_packages.json'}, attempt #1 04:44:41 INFO - Downloaded 896 bytes. 04:44:41 INFO - Reading from file /builds/slave/test/build/target.test_packages.json 04:44:41 INFO - Using the following test package requirements: 04:44:41 INFO - {u'common': [u'target.common.tests.zip'], 04:44:41 INFO - u'cppunittest': [u'target.common.tests.zip', u'target.cppunittest.tests.zip'], 04:44:41 INFO - u'gtest': [u'target.common.tests.zip', u'target.gtest.tests.zip'], 04:44:41 INFO - u'jittest': [u'target.common.tests.zip', u'target.jsshell.zip'], 04:44:41 INFO - u'mochitest': [u'target.common.tests.zip', u'target.mochitest.tests.zip'], 04:44:41 INFO - u'mozbase': [u'target.common.tests.zip'], 04:44:41 INFO - u'reftest': [u'target.common.tests.zip', u'target.reftest.tests.zip'], 04:44:41 INFO - u'talos': [u'target.common.tests.zip', u'target.talos.tests.zip'], 04:44:41 INFO - u'web-platform': [u'target.common.tests.zip', 04:44:41 INFO - u'target.web-platform.tests.zip'], 04:44:41 INFO - u'xpcshell': [u'target.common.tests.zip', u'target.xpcshell.tests.zip']} 04:44:41 INFO - Downloading packages: [u'target.common.tests.zip'] for test suite category: common 04:44:41 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.common.tests.zip 04:44:41 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.common.tests.zip'}, attempt #1 04:44:41 INFO - Fetch https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.common.tests.zip into memory 04:44:42 INFO - Expected file size: 59050200 04:44:42 INFO - Obtained file size: 59050200 04:44:52 INFO - Downloading packages: [u'target.common.tests.zip', u'target.talos.tests.zip'] for test suite category: talos 04:44:52 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.common.tests.zip 04:44:52 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.common.tests.zip'}, attempt #1 04:44:52 INFO - Fetch https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.common.tests.zip into memory 04:44:53 INFO - Expected file size: 59050200 04:44:53 INFO - Obtained file size: 59050200 04:45:03 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs * from https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.talos.tests.zip 04:45:03 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.talos.tests.zip'}, attempt #1 04:45:03 INFO - Fetch https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.talos.tests.zip into memory 04:45:04 INFO - Expected file size: 14403647 04:45:04 INFO - Obtained file size: 14403647 04:45:04 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:04 INFO - trying https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2 04:45:04 INFO - Downloading https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2 to /builds/slave/test/build/target.tar.bz2 04:45:04 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2', 'file_name': '/builds/slave/test/build/target.tar.bz2'}, attempt #1 04:45:05 INFO - Downloaded 66776632 bytes. 04:45:05 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2 04:45:05 INFO - mkdir: /builds/slave/test/properties 04:45:05 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 04:45:05 INFO - Writing to file /builds/slave/test/properties/build_url 04:45:05 INFO - Contents: 04:45:05 INFO - build_url:https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2 04:45:05 INFO - Running post-action listener: _resource_record_post_action 04:45:05 INFO - Running post-action listener: set_extra_try_arguments 04:45:05 INFO - [mozharness: 2017-02-17 12:45:05.968386Z] Finished download-and-extract step (success) 04:45:05 INFO - [mozharness: 2017-02-17 12:45:05.968483Z] Running populate-webroot step. 04:45:05 INFO - Running pre-action listener: _resource_record_pre_action 04:45:05 INFO - Running main action method: populate_webroot 04:45:05 INFO - {'extra_options': {'android': ['--apkPath=%(apk_path)s']}, 04:45:05 INFO - 'mobile-suites': {'remote-tp4m_nochrome': {'tests': ['tp4m']}, 04:45:05 INFO - 'remote-tsvgx': {'talos_options': ['--noChrome', 04:45:05 INFO - '--tppagecycles', 04:45:05 INFO - '7'], 04:45:05 INFO - 'tests': ['tsvgm']}}, 04:45:05 INFO - 'suites': {'chromez': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['tresize', 'tcanvasmark']}, 04:45:05 INFO - 'chromez-e10s': {'tests': ['tresize', 'tcanvasmark']}, 04:45:05 INFO - 'dromaeojs': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['dromaeo_css', 'kraken']}, 04:45:05 INFO - 'dromaeojs-e10s': {'tests': ['dromaeo_css', 'kraken']}, 04:45:05 INFO - 'g1': {'pagesets_name': 'tp5n.zip', 04:45:05 INFO - 'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:45:05 INFO - 'g1-e10s': {'pagesets_name': 'tp5n.zip', 04:45:05 INFO - 'tests': ['tp5o_scroll', 'glterrain']}, 04:45:05 INFO - 'g2': {'pagesets_name': 'tp5n.zip', 04:45:05 INFO - 'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['damp', 'tps']}, 04:45:05 INFO - 'g2-e10s': {'pagesets_name': 'tp5n.zip', 04:45:05 INFO - 'tests': ['damp', 'tps']}, 04:45:05 INFO - 'g3': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['dromaeo_dom']}, 04:45:05 INFO - 'g3-e10s': {'tests': ['dromaeo_dom']}, 04:45:05 INFO - 'g4': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['basic_compositor_video']}, 04:45:05 INFO - 'g4-e10s': {'tests': ['basic_compositor_video']}, 04:45:05 INFO - 'other': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['a11yr', 04:45:05 INFO - 'ts_paint', 04:45:05 INFO - 'tpaint', 04:45:05 INFO - 'sessionrestore', 04:45:05 INFO - 'sessionrestore_no_auto_restore', 04:45:05 INFO - 'tabpaint']}, 04:45:05 INFO - 'other-e10s': {'tests': ['a11yr', 04:45:05 INFO - 'ts_paint', 04:45:05 INFO - 'tpaint', 04:45:05 INFO - 'sessionrestore', 04:45:05 INFO - 'sessionrestore_no_auto_restore', 04:45:05 INFO - 'tabpaint']}, 04:45:05 INFO - 'other-e10s_l64': {'tests': ['a11yr', 04:45:05 INFO - 'ts_paint', 04:45:05 INFO - 'tpaint', 04:45:05 INFO - 'sessionrestore', 04:45:05 INFO - 'sessionrestore_no_auto_restore', 04:45:05 INFO - 'tabpaint']}, 04:45:05 INFO - 'other-e10s_nol64': {'tests': ['a11yr', 04:45:05 INFO - 'ts_paint', 04:45:05 INFO - 'tpaint', 04:45:05 INFO - 'sessionrestore', 04:45:05 INFO - 'sessionrestore_no_auto_restore', 04:45:05 INFO - 'tabpaint']}, 04:45:05 INFO - 'other_l64': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['a11yr', 04:45:05 INFO - 'ts_paint', 04:45:05 INFO - 'tpaint', 04:45:05 INFO - 'sessionrestore', 04:45:05 INFO - 'sessionrestore_no_auto_restore', 04:45:05 INFO - 'tabpaint']}, 04:45:05 INFO - 'other_nol64': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['a11yr', 04:45:05 INFO - 'ts_paint', 04:45:05 INFO - 'tpaint', 04:45:05 INFO - 'sessionrestore', 04:45:05 INFO - 'sessionrestore_no_auto_restore', 04:45:05 INFO - 'tabpaint']}, 04:45:05 INFO - 'svgr': {'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['tsvgx', 04:45:05 INFO - 'tsvgr_opacity', 04:45:05 INFO - 'tart', 04:45:05 INFO - 'tscrollx', 04:45:05 INFO - 'cart', 04:45:05 INFO - 'tsvg_static']}, 04:45:05 INFO - 'svgr-e10s': {'tests': ['tsvgx', 04:45:05 INFO - 'tsvgr_opacity', 04:45:05 INFO - 'tart', 04:45:05 INFO - 'tscrollx', 04:45:05 INFO - 'cart', 04:45:05 INFO - 'tsvg_static']}, 04:45:05 INFO - 'tp5o': {'pagesets_name': 'tp5n.zip', 04:45:05 INFO - 'talos_options': ['--disable-e10s'], 04:45:05 INFO - 'tests': ['tp5o']}, 04:45:05 INFO - 'tp5o-e10s': {'pagesets_name': 'tp5n.zip', 'tests': ['tp5o']}, 04:45:05 INFO - 'xperf': {'pagesets_name': 'tp5n.zip', 04:45:05 INFO - 'talos_options': ['--disable-e10s', 04:45:05 INFO - '--xperf_path', 04:45:05 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:45:05 INFO - 'tests': ['tp5n']}, 04:45:05 INFO - 'xperf-e10s': {'pagesets_name': 'tp5n.zip', 04:45:05 INFO - 'talos_options': ['--xperf_path', 04:45:05 INFO - '"c:/Program Files/Microsoft Windows Performance Toolkit/xperf.exe"'], 04:45:05 INFO - 'tests': ['tp5n']}}, 04:45:05 INFO - 'talos.zip': {'path': '', 04:45:05 INFO - 'url': 'http://talos-bundles.pvt.build.mozilla.org/zips/talos.a6052c33d420.zip'}} 04:45:05 INFO - Running post-action listener: _resource_record_post_action 04:45:05 INFO - [mozharness: 2017-02-17 12:45:05.983623Z] Finished populate-webroot step (success) 04:45:05 INFO - [mozharness: 2017-02-17 12:45:05.983717Z] Running create-virtualenv step. 04:45:05 INFO - Running pre-action listener: _resource_record_pre_action 04:45:05 INFO - Running main action method: create_virtualenv 04:45:05 INFO - Creating virtualenv /builds/slave/test/build/venv 04:45:05 INFO - Running command: ['/tools/buildbot/bin/python', '/tools/misc-python/virtualenv.py', '--no-site-packages', '--distribute', '/builds/slave/test/build/venv'] in /builds/slave/test/build 04:45:05 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 04:45:06 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 04:45:06 INFO - Using real prefix '/usr' 04:45:06 INFO - New python executable in /builds/slave/test/build/venv/bin/python 04:45:06 INFO - Installing distribute.............................................................................................................................................................................................done. 04:45:08 INFO - Installing pip.................done. 04:45:08 INFO - Return code: 0 04:45:08 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 04:45:08 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 04:45:08 INFO - Reading from file tmpfile_stdout 04:45:08 INFO - Output received: 04:45:08 INFO - pip 1.5.5 from /builds/slave/test/build/venv/local/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg (python 2.7) 04:45:08 INFO - Installing pip>=1.5 into virtualenv /builds/slave/test/build/venv 04:45:08 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:08 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:08 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:08 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:08 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:08 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:08 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:08 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'pip>=1.5'] in /builds/slave/test/build 04:45:08 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub pip>=1.5 04:45:08 INFO - Using env: {'DISPLAY': ':0', 04:45:08 INFO - 'HOME': '/home/cltbld', 04:45:08 INFO - 'LANG': 'en_US.UTF-8', 04:45:08 INFO - 'LANGUAGE': 'en_US:en', 04:45:08 INFO - 'LOGNAME': 'cltbld', 04:45:08 INFO - 'MAIL': '/var/mail/cltbld', 04:45:08 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:08 INFO - 'MOZ_NO_REMOTE': '1', 04:45:08 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:08 INFO - 'NO_EM_RESTART': '1', 04:45:08 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:08 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:08 INFO - 'PWD': '/builds/slave/test', 04:45:08 INFO - 'SHELL': '/bin/bash', 04:45:08 INFO - 'SHLVL': '1', 04:45:08 INFO - 'TERM': 'linux', 04:45:08 INFO - 'TMOUT': '86400', 04:45:08 INFO - 'USER': 'cltbld', 04:45:08 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:08 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:08 INFO - '_': '/tools/buildbot/bin/python'} 04:45:08 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:08 INFO - Requirement already satisfied (use --upgrade to upgrade): pip>=1.5 in ./venv/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg 04:45:08 INFO - Cleaning up... 04:45:08 INFO - Return code: 0 04:45:08 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 04:45:08 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:08 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:08 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:08 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:08 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:08 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:09 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:09 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1'] in /builds/slave/test/build 04:45:09 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=3.1.1 04:45:09 INFO - Using env: {'DISPLAY': ':0', 04:45:09 INFO - 'HOME': '/home/cltbld', 04:45:09 INFO - 'LANG': 'en_US.UTF-8', 04:45:09 INFO - 'LANGUAGE': 'en_US:en', 04:45:09 INFO - 'LOGNAME': 'cltbld', 04:45:09 INFO - 'MAIL': '/var/mail/cltbld', 04:45:09 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:09 INFO - 'MOZ_NO_REMOTE': '1', 04:45:09 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:09 INFO - 'NO_EM_RESTART': '1', 04:45:09 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:09 INFO - 'PWD': '/builds/slave/test', 04:45:09 INFO - 'SHELL': '/bin/bash', 04:45:09 INFO - 'SHLVL': '1', 04:45:09 INFO - 'TERM': 'linux', 04:45:09 INFO - 'TMOUT': '86400', 04:45:09 INFO - 'USER': 'cltbld', 04:45:09 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:09 INFO - '_': '/tools/buildbot/bin/python'} 04:45:09 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:09 INFO - Downloading/unpacking psutil>=3.1.1 04:45:09 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:09 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:09 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:09 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:09 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:09 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 04:45:11 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 04:45:11 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 04:45:11 INFO - Installing collected packages: psutil 04:45:11 INFO - Running setup.py install for psutil 04:45:11 INFO - building 'psutil._psutil_linux' extension 04:45:11 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -DPSUTIL_VERSION=311 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o 04:45:11 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so 04:45:11 INFO - building 'psutil._psutil_posix' extension 04:45:11 INFO - gcc -pthread -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fPIC -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o 04:45:11 INFO - gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so 04:45:11 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 04:45:11 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects ... 04:45:11 INFO - Successfully installed psutil 04:45:11 INFO - Cleaning up... 04:45:11 INFO - Return code: 0 04:45:11 INFO - Installing mozsystemmonitor==0.3 into virtualenv /builds/slave/test/build/venv 04:45:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:11 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:11 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:11 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:11 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:11 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:11 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:11 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'mozsystemmonitor==0.3'] in /builds/slave/test/build 04:45:11 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub mozsystemmonitor==0.3 04:45:11 INFO - Using env: {'DISPLAY': ':0', 04:45:11 INFO - 'HOME': '/home/cltbld', 04:45:11 INFO - 'LANG': 'en_US.UTF-8', 04:45:11 INFO - 'LANGUAGE': 'en_US:en', 04:45:11 INFO - 'LOGNAME': 'cltbld', 04:45:11 INFO - 'MAIL': '/var/mail/cltbld', 04:45:11 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:11 INFO - 'MOZ_NO_REMOTE': '1', 04:45:11 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:11 INFO - 'NO_EM_RESTART': '1', 04:45:11 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:11 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:11 INFO - 'PWD': '/builds/slave/test', 04:45:11 INFO - 'SHELL': '/bin/bash', 04:45:11 INFO - 'SHLVL': '1', 04:45:11 INFO - 'TERM': 'linux', 04:45:11 INFO - 'TMOUT': '86400', 04:45:11 INFO - 'USER': 'cltbld', 04:45:11 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:11 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:11 INFO - '_': '/tools/buildbot/bin/python'} 04:45:12 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:12 INFO - Downloading/unpacking mozsystemmonitor==0.3 04:45:12 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:12 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:12 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:12 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:12 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:12 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:14 INFO - Downloading mozsystemmonitor-0.3.tar.gz 04:45:14 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/mozsystemmonitor/setup.py) egg_info for package mozsystemmonitor 04:45:14 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in ./venv/lib/python2.7/site-packages (from mozsystemmonitor==0.3) 04:45:14 INFO - Installing collected packages: mozsystemmonitor 04:45:14 INFO - Running setup.py install for mozsystemmonitor 04:45:14 INFO - Successfully installed mozsystemmonitor 04:45:14 INFO - Cleaning up... 04:45:14 INFO - Return code: 0 04:45:14 INFO - Installing jsonschema==2.5.1 into virtualenv /builds/slave/test/build/venv 04:45:14 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:14 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:14 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:14 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:14 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:14 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:14 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:14 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema==2.5.1'] in /builds/slave/test/build 04:45:14 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema==2.5.1 04:45:14 INFO - Using env: {'DISPLAY': ':0', 04:45:14 INFO - 'HOME': '/home/cltbld', 04:45:14 INFO - 'LANG': 'en_US.UTF-8', 04:45:14 INFO - 'LANGUAGE': 'en_US:en', 04:45:14 INFO - 'LOGNAME': 'cltbld', 04:45:14 INFO - 'MAIL': '/var/mail/cltbld', 04:45:14 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:14 INFO - 'MOZ_NO_REMOTE': '1', 04:45:14 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:14 INFO - 'NO_EM_RESTART': '1', 04:45:14 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:14 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:14 INFO - 'PWD': '/builds/slave/test', 04:45:14 INFO - 'SHELL': '/bin/bash', 04:45:14 INFO - 'SHLVL': '1', 04:45:14 INFO - 'TERM': 'linux', 04:45:14 INFO - 'TMOUT': '86400', 04:45:14 INFO - 'USER': 'cltbld', 04:45:14 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:14 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:14 INFO - '_': '/tools/buildbot/bin/python'} 04:45:14 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:14 INFO - Downloading/unpacking jsonschema==2.5.1 04:45:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:14 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:14 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:14 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:14 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:16 INFO - Downloading jsonschema-2.5.1-py2.py3-none-any.whl 04:45:16 INFO - Downloading/unpacking functools32 (from jsonschema==2.5.1) 04:45:16 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:16 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:16 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:16 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:16 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:16 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:16 INFO - Downloading functools32-3.2.3-2.tar.gz 04:45:16 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/functools32/setup.py) egg_info for package functools32 04:45:16 INFO - warning: no files found matching '*.txt' 04:45:16 INFO - no previously-included directories found matching 'build' 04:45:16 INFO - no previously-included directories found matching 'dist' 04:45:16 INFO - no previously-included directories found matching '.git*' 04:45:16 INFO - Installing collected packages: jsonschema, functools32 04:45:16 INFO - Running setup.py install for functools32 04:45:16 INFO - warning: no files found matching '*.txt' 04:45:16 INFO - no previously-included directories found matching 'build' 04:45:16 INFO - no previously-included directories found matching 'dist' 04:45:16 INFO - no previously-included directories found matching '.git*' 04:45:16 INFO - Successfully installed jsonschema functools32 04:45:16 INFO - Cleaning up... 04:45:17 INFO - Return code: 0 04:45:17 INFO - Installing functools32==3.2.3-2 into virtualenv /builds/slave/test/build/venv 04:45:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:17 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:17 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:17 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'functools32==3.2.3-2']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:17 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'functools32==3.2.3-2'] in /builds/slave/test/build 04:45:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub functools32==3.2.3-2 04:45:17 INFO - Using env: {'DISPLAY': ':0', 04:45:17 INFO - 'HOME': '/home/cltbld', 04:45:17 INFO - 'LANG': 'en_US.UTF-8', 04:45:17 INFO - 'LANGUAGE': 'en_US:en', 04:45:17 INFO - 'LOGNAME': 'cltbld', 04:45:17 INFO - 'MAIL': '/var/mail/cltbld', 04:45:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:17 INFO - 'MOZ_NO_REMOTE': '1', 04:45:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:17 INFO - 'NO_EM_RESTART': '1', 04:45:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:17 INFO - 'PWD': '/builds/slave/test', 04:45:17 INFO - 'SHELL': '/bin/bash', 04:45:17 INFO - 'SHLVL': '1', 04:45:17 INFO - 'TERM': 'linux', 04:45:17 INFO - 'TMOUT': '86400', 04:45:17 INFO - 'USER': 'cltbld', 04:45:17 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:17 INFO - '_': '/tools/buildbot/bin/python'} 04:45:17 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:17 INFO - Requirement already satisfied (use --upgrade to upgrade): functools32==3.2.3-2 in ./venv/lib/python2.7/site-packages 04:45:17 INFO - Cleaning up... 04:45:17 INFO - Return code: 0 04:45:17 INFO - Installing blobuploader==1.2.4 into virtualenv /builds/slave/test/build/venv 04:45:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:17 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:17 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:17 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:17 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:17 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:17 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:17 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'blobuploader==1.2.4'] in /builds/slave/test/build 04:45:17 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub blobuploader==1.2.4 04:45:17 INFO - Using env: {'DISPLAY': ':0', 04:45:17 INFO - 'HOME': '/home/cltbld', 04:45:17 INFO - 'LANG': 'en_US.UTF-8', 04:45:17 INFO - 'LANGUAGE': 'en_US:en', 04:45:17 INFO - 'LOGNAME': 'cltbld', 04:45:17 INFO - 'MAIL': '/var/mail/cltbld', 04:45:17 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:17 INFO - 'MOZ_NO_REMOTE': '1', 04:45:17 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:17 INFO - 'NO_EM_RESTART': '1', 04:45:17 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:17 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:17 INFO - 'PWD': '/builds/slave/test', 04:45:17 INFO - 'SHELL': '/bin/bash', 04:45:17 INFO - 'SHLVL': '1', 04:45:17 INFO - 'TERM': 'linux', 04:45:17 INFO - 'TMOUT': '86400', 04:45:17 INFO - 'USER': 'cltbld', 04:45:17 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:17 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:17 INFO - '_': '/tools/buildbot/bin/python'} 04:45:17 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:17 INFO - Downloading/unpacking blobuploader==1.2.4 04:45:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:17 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:17 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:17 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:17 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:19 INFO - Downloading blobuploader-1.2.4.tar.gz 04:45:19 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blobuploader/setup.py) egg_info for package blobuploader 04:45:19 INFO - Downloading/unpacking requests==1.2.3. (from blobuploader==1.2.4) 04:45:19 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:19 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:19 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:19 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:19 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:19 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:19 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/requests/setup.py) egg_info for package requests 04:45:19 INFO - Downloading/unpacking docopt==0.6.1 (from blobuploader==1.2.4) 04:45:19 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:19 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:19 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:19 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:19 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:19 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:20 INFO - Downloading docopt-0.6.1.tar.gz 04:45:20 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/docopt/setup.py) egg_info for package docopt 04:45:20 INFO - Installing collected packages: blobuploader, requests, docopt 04:45:20 INFO - Running setup.py install for blobuploader 04:45:20 INFO - changing mode of build/scripts-2.7/blobberc.py from 664 to 775 04:45:20 INFO - changing mode of /builds/slave/test/build/venv/bin/blobberc.py to 775 04:45:20 INFO - Running setup.py install for requests 04:45:20 INFO - Running setup.py install for docopt 04:45:20 INFO - Successfully installed blobuploader requests docopt 04:45:20 INFO - Cleaning up... 04:45:20 INFO - Return code: 0 04:45:20 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:45:20 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:20 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:20 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:20 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:20 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:20 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:20 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:20 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 04:45:20 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.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 04:45:20 INFO - Using env: {'DISPLAY': ':0', 04:45:20 INFO - 'HOME': '/home/cltbld', 04:45:20 INFO - 'LANG': 'en_US.UTF-8', 04:45:20 INFO - 'LANGUAGE': 'en_US:en', 04:45:20 INFO - 'LOGNAME': 'cltbld', 04:45:20 INFO - 'MAIL': '/var/mail/cltbld', 04:45:20 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:20 INFO - 'MOZ_NO_REMOTE': '1', 04:45:20 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:20 INFO - 'NO_EM_RESTART': '1', 04:45:20 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:20 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:20 INFO - 'PWD': '/builds/slave/test', 04:45:20 INFO - 'SHELL': '/bin/bash', 04:45:20 INFO - 'SHLVL': '1', 04:45:20 INFO - 'TERM': 'linux', 04:45:20 INFO - 'TMOUT': '86400', 04:45:20 INFO - 'USER': 'cltbld', 04:45:20 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:20 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:20 INFO - '_': '/tools/buildbot/bin/python'} 04:45:21 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 04:45:21 INFO - Running setup.py (path:/tmp/pip-iu3IBZ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 04:45:21 INFO - Running setup.py (path:/tmp/pip-MSm_UM-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 04:45:21 INFO - Running setup.py (path:/tmp/pip-lA87IA-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 04:45:21 INFO - Running setup.py (path:/tmp/pip-DbHwIl-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 04:45:21 INFO - Running setup.py (path:/tmp/pip-ZSr0Wc-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 04:45:21 INFO - Running setup.py (path:/tmp/pip-4xQc_C-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 04:45:21 INFO - Running setup.py (path:/tmp/pip-bArDjo-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 04:45:21 INFO - Running setup.py (path:/tmp/pip-jbUt4I-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 04:45:21 INFO - Running setup.py (path:/tmp/pip-J2rtPY-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 04:45:21 INFO - Running setup.py (path:/tmp/pip-uqrK1O-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 04:45:21 INFO - Running setup.py (path:/tmp/pip-F8LbIG-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 04:45:21 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 04:45:21 INFO - Running setup.py (path:/tmp/pip-6ieHOw-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 04:45:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 04:45:22 INFO - Running setup.py (path:/tmp/pip-LZ69zv-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 04:45:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 04:45:22 INFO - Running setup.py (path:/tmp/pip-IDUAIF-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 04:45:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 04:45:22 INFO - Running setup.py (path:/tmp/pip-HR7gxj-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 04:45:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 04:45:22 INFO - Running setup.py (path:/tmp/pip-myesf2-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 04:45:22 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 04:45:22 INFO - Running setup.py (path:/tmp/pip-o44Xnd-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 04:45:22 INFO - Installing collected packages: manifestparser, mozcrash, mozdebug, mozdevice, mozfile, mozhttpd, mozinfo, mozInstall, mozleak, mozlog, moznetwork, mozprocess, mozprofile, mozrunner, mozscreenshot, moztest, mozversion 04:45:22 INFO - Running setup.py install for manifestparser 04:45:22 INFO - Installing manifestparser script to /builds/slave/test/build/venv/bin 04:45:22 INFO - Running setup.py install for mozcrash 04:45:22 INFO - Running setup.py install for mozdebug 04:45:22 INFO - Running setup.py install for mozdevice 04:45:22 INFO - Installing sutini script to /builds/slave/test/build/venv/bin 04:45:22 INFO - Installing dm script to /builds/slave/test/build/venv/bin 04:45:22 INFO - Running setup.py install for mozfile 04:45:22 INFO - Running setup.py install for mozhttpd 04:45:23 INFO - Installing mozhttpd script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Running setup.py install for mozinfo 04:45:23 INFO - Installing mozinfo script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Running setup.py install for mozInstall 04:45:23 INFO - Installing moz_remove_from_system script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Installing mozuninstall script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Installing mozinstall script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Installing moz_add_to_system script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Running setup.py install for mozleak 04:45:23 INFO - Running setup.py install for mozlog 04:45:23 INFO - Installing structlog script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Running setup.py install for moznetwork 04:45:23 INFO - Installing moznetwork script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Running setup.py install for mozprocess 04:45:23 INFO - Running setup.py install for mozprofile 04:45:23 INFO - Installing mozprofile script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Installing diff-profiles script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Installing view-profile script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Running setup.py install for mozrunner 04:45:23 INFO - Installing mozrunner script to /builds/slave/test/build/venv/bin 04:45:23 INFO - Running setup.py install for mozscreenshot 04:45:23 INFO - Running setup.py install for moztest 04:45:24 INFO - Running setup.py install for mozversion 04:45:24 INFO - Installing mozversion script to /builds/slave/test/build/venv/bin 04:45:24 INFO - Successfully installed manifestparser mozcrash mozdebug mozdevice mozfile mozhttpd mozinfo mozInstall mozleak mozlog moznetwork mozprocess mozprofile mozrunner mozscreenshot moztest mozversion 04:45:24 INFO - Cleaning up... 04:45:24 INFO - Return code: 0 04:45:24 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:45:24 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:24 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:24 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:24 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:24 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:24 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:24 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:24 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/config 04:45:24 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.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 04:45:24 INFO - Using env: {'DISPLAY': ':0', 04:45:24 INFO - 'HOME': '/home/cltbld', 04:45:24 INFO - 'LANG': 'en_US.UTF-8', 04:45:24 INFO - 'LANGUAGE': 'en_US:en', 04:45:24 INFO - 'LOGNAME': 'cltbld', 04:45:24 INFO - 'MAIL': '/var/mail/cltbld', 04:45:24 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:24 INFO - 'MOZ_NO_REMOTE': '1', 04:45:24 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:24 INFO - 'NO_EM_RESTART': '1', 04:45:24 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:24 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:24 INFO - 'PWD': '/builds/slave/test', 04:45:24 INFO - 'SHELL': '/bin/bash', 04:45:24 INFO - 'SHLVL': '1', 04:45:24 INFO - 'TERM': 'linux', 04:45:24 INFO - 'TMOUT': '86400', 04:45:24 INFO - 'USER': 'cltbld', 04:45:24 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:24 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:24 INFO - '_': '/tools/buildbot/bin/python'} 04:45:24 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/manifestparser 04:45:24 INFO - Running setup.py (path:/tmp/pip-L_dCb7-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/manifestparser 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): manifestparser==1.1 from file:///builds/slave/test/build/tests/mozbase/manifestparser in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 1)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozcrash 04:45:24 INFO - Running setup.py (path:/tmp/pip-5l8O8G-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozcrash 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash==1.0 from file:///builds/slave/test/build/tests/mozbase/mozcrash in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdebug 04:45:24 INFO - Running setup.py (path:/tmp/pip-aiI3_I-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdebug 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdebug==0.1 from file:///builds/slave/test/build/tests/mozbase/mozdebug in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozdevice 04:45:24 INFO - Running setup.py (path:/tmp/pip-Q0_CIf-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozdevice 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozdevice==0.49 from file:///builds/slave/test/build/tests/mozbase/mozdevice in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozfile 04:45:24 INFO - Running setup.py (path:/tmp/pip-aNUh7z-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozfile 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile==1.2 from file:///builds/slave/test/build/tests/mozbase/mozfile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 5)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozhttpd 04:45:24 INFO - Running setup.py (path:/tmp/pip-yGWopC-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozhttpd 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd==0.7 from file:///builds/slave/test/build/tests/mozbase/mozhttpd in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 6)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinfo 04:45:24 INFO - Running setup.py (path:/tmp/pip-b89NxR-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinfo 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo==0.9 from file:///builds/slave/test/build/tests/mozbase/mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 7)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozinstall 04:45:24 INFO - Running setup.py (path:/tmp/pip-9V1fGk-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozinstall 04:45:24 INFO - Requirement already satisfied (use --upgrade to upgrade): mozInstall==1.12 from file:///builds/slave/test/build/tests/mozbase/mozinstall in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 8)) 04:45:24 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozleak 04:45:24 INFO - Running setup.py (path:/tmp/pip-g9tbWO-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozleak 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozleak==0.1 from file:///builds/slave/test/build/tests/mozbase/mozleak in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 9)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozlog 04:45:25 INFO - Running setup.py (path:/tmp/pip-TuwXRD-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozlog 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog==3.4 from file:///builds/slave/test/build/tests/mozbase/mozlog in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moznetwork 04:45:25 INFO - Running setup.py (path:/tmp/pip-QSK7uQ-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moznetwork 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork==0.27 from file:///builds/slave/test/build/tests/mozbase/moznetwork in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 11)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprocess 04:45:25 INFO - Running setup.py (path:/tmp/pip-IL4Un_-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprocess 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess==0.24 from file:///builds/slave/test/build/tests/mozbase/mozprocess in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 12)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozprofile 04:45:25 INFO - Running setup.py (path:/tmp/pip-Kq1ief-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozprofile 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile==0.28 from file:///builds/slave/test/build/tests/mozbase/mozprofile in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 13)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozrunner 04:45:25 INFO - Running setup.py (path:/tmp/pip-gNh5YV-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozrunner 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozrunner==6.13 from file:///builds/slave/test/build/tests/mozbase/mozrunner in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 14)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozscreenshot 04:45:25 INFO - Running setup.py (path:/tmp/pip-xbkjux-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozscreenshot 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozscreenshot==0.1 from file:///builds/slave/test/build/tests/mozbase/mozscreenshot in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 15)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/moztest 04:45:25 INFO - Running setup.py (path:/tmp/pip-V1K9mm-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/moztest 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): moztest==0.8 from file:///builds/slave/test/build/tests/mozbase/moztest in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 16)) 04:45:25 INFO - Unpacking /builds/slave/test/build/tests/mozbase/mozversion 04:45:25 INFO - Running setup.py (path:/tmp/pip-uQ0dig-build/setup.py) egg_info for package from file:///builds/slave/test/build/tests/mozbase/mozversion 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion==1.4 from file:///builds/slave/test/build/tests/mozbase/mozversion in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 17)) 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.0 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozcrash==1.0->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 2)) 04:45:25 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozdebug==0.1->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 3)) 04:45:25 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.49->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:45:25 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.49->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 4)) 04:45:25 INFO - Downloading/unpacking blessings>=1.3 (from mozlog==3.4->-r /builds/slave/test/build/tests/config/mozbase_requirements.txt (line 10)) 04:45:25 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:25 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:25 INFO - http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:25 INFO - http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com has it available 04:45:25 INFO - http://pypi.pvt.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pvt.build.mozilla.org has it available 04:45:25 INFO - http://pypi.pub.build.mozilla.org/pub uses an insecure transport scheme (http). Consider using https if pypi.pub.build.mozilla.org has it available 04:45:28 INFO - Downloading blessings-1.6.tar.gz 04:45:28 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/blessings/setup.py) egg_info for package blessings 04:45:28 INFO - Installing collected packages: blessings 04:45:28 INFO - Running setup.py install for blessings 04:45:28 INFO - Successfully installed blessings 04:45:28 INFO - Cleaning up... 04:45:28 INFO - Return code: 0 04:45:28 INFO - Done creating virtualenv /builds/slave/test/build/venv. 04:45:28 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:45:28 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:45:29 INFO - Reading from file tmpfile_stdout 04:45:29 INFO - Current package versions: 04:45:29 INFO - argparse == 1.2.1 04:45:29 INFO - blessings == 1.6 04:45:29 INFO - blobuploader == 1.2.4 04:45:29 INFO - docopt == 0.6.1 04:45:29 INFO - functools32 == 3.2.3-2 04:45:29 INFO - jsonschema == 2.5.1 04:45:29 INFO - manifestparser == 1.1 04:45:29 INFO - mozInstall == 1.12 04:45:29 INFO - mozcrash == 1.0 04:45:29 INFO - mozdebug == 0.1 04:45:29 INFO - mozdevice == 0.49 04:45:29 INFO - mozfile == 1.2 04:45:29 INFO - mozhttpd == 0.7 04:45:29 INFO - mozinfo == 0.9 04:45:29 INFO - mozleak == 0.1 04:45:29 INFO - mozlog == 3.4 04:45:29 INFO - moznetwork == 0.27 04:45:29 INFO - mozprocess == 0.24 04:45:29 INFO - mozprofile == 0.28 04:45:29 INFO - mozrunner == 6.13 04:45:29 INFO - mozscreenshot == 0.1 04:45:29 INFO - mozsystemmonitor == 0.3 04:45:29 INFO - moztest == 0.8 04:45:29 INFO - mozversion == 1.4 04:45:29 INFO - psutil == 3.1.1 04:45:29 INFO - requests == 1.2.3 04:45:29 INFO - wsgiref == 0.1.2 04:45:29 INFO - Installing None into virtualenv /builds/slave/test/build/venv 04:45:29 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:29 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:29 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:29 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:29 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:29 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:29 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:29 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub'] in /builds/slave/test/build/tests/talos 04:45:29 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.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub 04:45:29 INFO - Using env: {'DISPLAY': ':0', 04:45:29 INFO - 'HOME': '/home/cltbld', 04:45:29 INFO - 'LANG': 'en_US.UTF-8', 04:45:29 INFO - 'LANGUAGE': 'en_US:en', 04:45:29 INFO - 'LOGNAME': 'cltbld', 04:45:29 INFO - 'MAIL': '/var/mail/cltbld', 04:45:29 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:29 INFO - 'MOZ_NO_REMOTE': '1', 04:45:29 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:29 INFO - 'NO_EM_RESTART': '1', 04:45:29 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:29 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:29 INFO - 'PWD': '/builds/slave/test', 04:45:29 INFO - 'SHELL': '/bin/bash', 04:45:29 INFO - 'SHLVL': '1', 04:45:29 INFO - 'TERM': 'linux', 04:45:29 INFO - 'TMOUT': '86400', 04:45:29 INFO - 'USER': 'cltbld', 04:45:29 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:29 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:29 INFO - '_': '/tools/buildbot/bin/python'} 04:45:29 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozlog>=3.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozcrash>=0.15 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 2)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozfile>=1.2 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 3)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozhttpd>=0.7 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozinfo>=0.8 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 5)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprocess>=0.22 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 6)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozversion>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 7)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): mozprofile>=0.25 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 8)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): psutil>=3.1.1 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from -r /builds/slave/test/build/tests/talos/requirements.txt (line 9)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): blessings>=1.3 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozlog>=3.1->-r /builds/slave/test/build/tests/talos/requirements.txt (line 1)) 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): moznetwork>=0.24 in /builds/slave/test/build/venv/lib/python2.7/site-packages (from mozhttpd>=0.7->-r /builds/slave/test/build/tests/talos/requirements.txt (line 4)) 04:45:29 INFO - Cleaning up... 04:45:29 INFO - Return code: 0 04:45:29 INFO - Installing jsonschema into virtualenv /builds/slave/test/build/venv 04:45:29 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:29 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 04:45:29 INFO - URL Candidate: http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:29 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:29 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 04:45:29 INFO - URL Candidate: http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub 04:45:29 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.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema']], kwargs: {'error_level': 'warning', 'error_list': [{'substr': 'not found or a compiler error:', 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1a3d1f0>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1b37a80>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x1cdded0>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, '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': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 'LANGUAGE': 'en_US:en', 'MAIL': '/var/mail/cltbld', 'SHLVL': '1', 'XPCOM_DEBUG_BREAK': 'warn', 'MOZ_CRASHREPORTER_NO_REPORT': '1', 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 'TMOUT': '86400', 'PWD': '/builds/slave/test', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 'NO_EM_RESTART': '1', 'HOME': '/home/cltbld', 'DISPLAY': ':0', '_': '/tools/buildbot/bin/python'}}, attempt #1 04:45:29 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'jsonschema'] in /builds/slave/test/build 04:45:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pub.build.mozilla.org.proxxy1.srv.releng.scl3.mozilla.com/pub --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub jsonschema 04:45:29 INFO - Using env: {'DISPLAY': ':0', 04:45:29 INFO - 'HOME': '/home/cltbld', 04:45:29 INFO - 'LANG': 'en_US.UTF-8', 04:45:29 INFO - 'LANGUAGE': 'en_US:en', 04:45:29 INFO - 'LOGNAME': 'cltbld', 04:45:29 INFO - 'MAIL': '/var/mail/cltbld', 04:45:29 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:29 INFO - 'MOZ_NO_REMOTE': '1', 04:45:29 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:29 INFO - 'NO_EM_RESTART': '1', 04:45:29 INFO - 'PATH': '/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:29 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:29 INFO - 'PWD': '/builds/slave/test', 04:45:29 INFO - 'SHELL': '/bin/bash', 04:45:29 INFO - 'SHLVL': '1', 04:45:29 INFO - 'TERM': 'linux', 04:45:29 INFO - 'TMOUT': '86400', 04:45:29 INFO - 'USER': 'cltbld', 04:45:29 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:29 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:29 INFO - '_': '/tools/buildbot/bin/python'} 04:45:29 INFO - Ignoring indexes: https://pypi.python.org/simple/ 04:45:29 INFO - Requirement already satisfied (use --upgrade to upgrade): jsonschema in ./venv/lib/python2.7/site-packages 04:45:29 INFO - Cleaning up... 04:45:29 INFO - Return code: 0 04:45:29 INFO - Running post-action listener: _resource_record_post_action 04:45:29 INFO - Running post-action listener: _start_resource_monitoring 04:45:29 INFO - Starting resource monitoring. 04:45:29 INFO - [mozharness: 2017-02-17 12:45:29.624932Z] Finished create-virtualenv step (success) 04:45:29 INFO - [mozharness: 2017-02-17 12:45:29.625456Z] Running install step. 04:45:29 INFO - Running pre-action listener: _resource_record_pre_action 04:45:29 INFO - Running main action method: install 04:45:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', 'freeze'] 04:45:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip freeze 04:45:29 INFO - Reading from file tmpfile_stdout 04:45:29 INFO - Detecting whether we're running mozinstall >=1.0... 04:45:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '-h'] 04:45:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall -h 04:45:29 INFO - Reading from file tmpfile_stdout 04:45:29 INFO - Output received: 04:45:29 INFO - Usage: mozinstall [options] installer 04:45:29 INFO - Options: 04:45:29 INFO - -h, --help show this help message and exit 04:45:29 INFO - -d DEST, --destination=DEST 04:45:29 INFO - Directory to install application into. [default: 04:45:29 INFO - "/builds/slave/test"] 04:45:29 INFO - --app=APP Application being installed. [default: firefox] 04:45:29 INFO - mkdir: /builds/slave/test/build/application 04:45:29 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/mozinstall', '/builds/slave/test/build/target.tar.bz2', '--destination', '/builds/slave/test/build/application'] 04:45:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/mozinstall /builds/slave/test/build/target.tar.bz2 --destination /builds/slave/test/build/application 04:45:46 INFO - Reading from file tmpfile_stdout 04:45:46 INFO - Output received: 04:45:46 INFO - /builds/slave/test/build/application/firefox/firefox 04:45:46 INFO - Running post-action listener: _resource_record_post_action 04:45:46 INFO - [mozharness: 2017-02-17 12:45:46.584666Z] Finished install step (success) 04:45:46 INFO - [mozharness: 2017-02-17 12:45:46.584813Z] Running run-tests step. 04:45:46 INFO - Running pre-action listener: _resource_record_pre_action 04:45:46 INFO - Running main action method: run_tests 04:45:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '--version'] 04:45:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python --version 04:45:46 INFO - Python 2.7.3 04:45:46 INFO - Return code: 0 04:45:46 INFO - grabbing minidump binary from tooltool 04:45:46 INFO - proxxy config: {'regions': ['.use1.', '.usw2.', '.scl3'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com', 'proxxy1.srv.releng.scl3.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 04:45:46 INFO - retry: Calling run_command with args: (['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--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 0x1d67540>, '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 0x1cdbf70>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x1cdc400>, 'level': 'critical'}, {'substr': 'ERROR - ', 'level': 'error'}], 'cwd': '/builds/slave/test/build', 'privileged': False}, attempt #1 04:45:46 INFO - Running command: ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] in /builds/slave/test/build 04:45:46 INFO - Copy/paste: /tools/tooltool.py --url https://api.pub.build.mozilla.org/tooltool/ --authentication-file /builds/relengapi.tok fetch -m /builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest -o -c /builds/tooltool_cache 04:45:46 INFO - Calling ['/tools/tooltool.py', '--url', 'https://api.pub.build.mozilla.org/tooltool/', '--authentication-file', '/builds/relengapi.tok', 'fetch', '-m', '/builds/slave/test/build/tests/config/tooltool-manifests/linux64/releng.manifest', '-o', '-c', '/builds/tooltool_cache'] with output_timeout 600 04:45:46 INFO - INFO - File linux64-minidump_stackwalk retrieved from local cache /builds/tooltool_cache 04:45:46 INFO - Return code: 0 04:45:46 INFO - Chmoding /builds/slave/test/build/linux64-minidump_stackwalk to 0755 04:45:46 INFO - mkdir: /builds/slave/test/build/blobber_upload_dir 04:45:46 INFO - ENV: MOZ_UPLOAD_DIR is now /builds/slave/test/build/blobber_upload_dir 04:45:46 INFO - ENV: RUST_BACKTRACE is now 1 04:45:46 INFO - ENV: MINIDUMP_STACKWALK is now /builds/slave/test/build/linux64-minidump_stackwalk 04:45:46 INFO - ENV: MINIDUMP_SAVE_PATH is now /builds/slave/test/build/blobber_upload_dir 04:45:46 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'dromaeojs', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-015', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/dromaeojs_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/dromaeojs_raw.log'] in /builds/slave/test/build 04:45:46 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/tests/talos/talos/run_tests.py --branchName Firefox --suite dromaeojs --executablePath /builds/slave/test/build/application/firefox/firefox --symbolsPath https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.crashreporter-symbols.zip --title talos-linux64-ix-015 --webServer localhost --log-tbpl-level=debug --log-errorsummary=/builds/slave/test/build/blobber_upload_dir/dromaeojs_errorsummary.log --log-raw=/builds/slave/test/build/blobber_upload_dir/dromaeojs_raw.log 04:45:46 INFO - Using env: {'DISPLAY': ':0', 04:45:46 INFO - 'HOME': '/home/cltbld', 04:45:46 INFO - 'LANG': 'en_US.UTF-8', 04:45:46 INFO - 'LANGUAGE': 'en_US:en', 04:45:46 INFO - 'LOGNAME': 'cltbld', 04:45:46 INFO - 'MAIL': '/var/mail/cltbld', 04:45:46 INFO - 'MINIDUMP_SAVE_PATH': '/builds/slave/test/build/blobber_upload_dir', 04:45:46 INFO - 'MINIDUMP_STACKWALK': '/builds/slave/test/build/linux64-minidump_stackwalk', 04:45:46 INFO - 'MOZ_CRASHREPORTER_NO_REPORT': '1', 04:45:46 INFO - 'MOZ_NO_REMOTE': '1', 04:45:46 INFO - 'MOZ_UPLOAD_DIR': '/builds/slave/test/build/blobber_upload_dir', 04:45:46 INFO - 'NODE_PATH': '/usr/lib/nodejs:/usr/lib/node_modules:/usr/share/javascript', 04:45:46 INFO - 'NO_EM_RESTART': '1', 04:45:46 INFO - 'PATH': '/builds/slave/test/build/venv/bin:/usr/local/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games', 04:45:46 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 04:45:46 INFO - 'PWD': '/builds/slave/test', 04:45:46 INFO - 'PYTHONPATH': '/builds/slave/test/build/tests/talos', 04:45:46 INFO - 'RUST_BACKTRACE': '1', 04:45:46 INFO - 'SHELL': '/bin/bash', 04:45:46 INFO - 'SHLVL': '1', 04:45:46 INFO - 'TERM': 'linux', 04:45:46 INFO - 'TMOUT': '86400', 04:45:46 INFO - 'USER': 'cltbld', 04:45:46 INFO - 'XDG_SESSION_COOKIE': '20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232', 04:45:46 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 04:45:46 INFO - '_': '/tools/buildbot/bin/python'} 04:45:46 INFO - Calling ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/tests/talos/talos/run_tests.py', '--branchName', 'Firefox', '--suite', 'dromaeojs', '--executablePath', '/builds/slave/test/build/application/firefox/firefox', '--symbolsPath', 'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.crashreporter-symbols.zip', '--title', 'talos-linux64-ix-015', '--webServer', 'localhost', '--log-tbpl-level=debug', '--log-errorsummary=/builds/slave/test/build/blobber_upload_dir/dromaeojs_errorsummary.log', '--log-raw=/builds/slave/test/build/blobber_upload_dir/dromaeojs_raw.log'] with output_timeout 3600 04:45:46 INFO - mozversion application_buildid: 20170217114148 04:45:46 INFO - mozversion application_changeset: 975ce5d8f7d818cc3cd32b134e4010577d3208cd 04:45:46 INFO - mozversion application_display_name: Nightly 04:45:46 INFO - mozversion application_id: {ec8030f7-c20a-464f-9b0e-13a3a9e97384} 04:45:46 INFO - mozversion application_name: Firefox 04:45:46 INFO - mozversion application_remotingname: firefox 04:45:46 INFO - mozversion application_repository: https://hg.mozilla.org/mozilla-central 04:45:46 INFO - mozversion application_vendor: Mozilla 04:45:46 INFO - mozversion application_version: 54.0a1 04:45:46 INFO - mozversion platform_buildid: 20170217114148 04:45:46 INFO - mozversion platform_changeset: 975ce5d8f7d818cc3cd32b134e4010577d3208cd 04:45:46 INFO - mozversion platform_repository: https://hg.mozilla.org/mozilla-central 04:45:46 INFO - mozversion platform_version: 54.0a1 04:45:46 INFO - using testdate: 1487335546 04:45:46 INFO - actual date: 1487335546 04:45:46 INFO - starting webserver on 'localhost:55338' 04:45:46 INFO - SUITE-START | Running 2 tests 04:45:46 INFO - TEST-START | dromaeo_css 04:45:46 INFO - operating with platform_type : linux_ 04:45:46 INFO - Initialising browser for dromaeo_css test... 04:45:46 INFO - TEST-INFO | started process 5389 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwSizVc/profile http://localhost:55338/getInfo.html) 04:45:49 INFO - PROCESS | 5389 | Iterating over profile /tmp/tmpwSizVc/profile 04:45:50 INFO - PROCESS | 5389 | __metrics Screen width/height:1600/1200 04:45:50 INFO - PROCESS | 5389 | colorDepth:24 04:45:50 INFO - PROCESS | 5389 | Browser inner width/height: 1024/697 04:45:50 INFO - PROCESS | 5389 | __metrics 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/crashes = Fri Feb 17 2017 04:45:46 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/pluginreg.dat = Fri Feb 17 2017 04:45:49 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/extensions.json = Fri Feb 17 2017 04:45:49 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/places.sqlite-wal = Fri Feb 17 2017 04:45:50 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/blocklist.xml = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/frequencyCap.json = Fri Feb 17 2017 04:45:49 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/places.sqlite = Fri Feb 17 2017 04:45:50 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/minidumps = Fri Feb 17 2017 04:45:46 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/startupCache = Fri Feb 17 2017 04:45:46 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/cert8.db = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/extensions = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/secmod.db = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/prefs.js = Fri Feb 17 2017 04:45:04 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/directoryLinks.json = Fri Feb 17 2017 04:45:49 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/thumbnails = Fri Feb 17 2017 04:45:49 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/localstore.rdf = Fri Feb 17 2017 04:45:04 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/gmp = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/content-prefs.sqlite = Fri Feb 17 2017 04:45:48 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/places.sqlite-shm = Fri Feb 17 2017 04:45:48 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | Stat failure 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/.parentlock = Fri Feb 17 2017 04:45:46 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/extensions.ini = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/permissions.sqlite = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/cache2 = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/compatibility.ini = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/safebrowsing = Fri Feb 17 2017 04:45:50 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/bookmarkbackups = Fri Feb 17 2017 04:45:49 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/user.js = Fri Feb 17 2017 04:45:46 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/addons.json = Fri Feb 17 2017 04:45:49 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/key3.db = Fri Feb 17 2017 04:45:47 GMT-0800 (PST) 04:45:50 INFO - PROCESS | 5389 | No birth date. Using mtime. 04:45:50 INFO - PROCESS | 5389 | Using date: /tmp/tmpwSizVc/profile/sessionCheckpoints.json = Fri Feb 17 2017 04:45:50 GMT-0800 (PST) 04:45:51 INFO - PROCESS | 5389 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 692: Error: Phase "quit-application-granted" is finished, it is too late to register completion condition "SessionStore: flushing all windows" 04:45:51 INFO - PROCESS | 5389 | JavaScript error: resource://app/modules/BrowserUsageTelemetry.jsm, line 303: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 04:45:52 INFO - TEST-INFO | 5389: exit 0 04:45:52 INFO - Browser initialized. 04:45:52 INFO - Running cycle 1/1 for dromaeo_css test... 04:45:52 INFO - TEST-INFO | started process 5483 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmpwSizVc/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/dromaeo/css.manifest.develop -tpchrome -tpnoisy -tpcycles 1 -tppagecycles 1) 04:46:04 INFO - PROCESS | 5483 | RSS: Main: 142221312 04:46:04 INFO - PROCESS | 5483 | 04:49:05 INFO - PROCESS | 5483 | Cycle 1(1): loaded http://localhost:55338/tests/dromaeo/cssquery-dojo.html (next: http://localhost:55338/tests/dromaeo/cssquery-ext.html) 04:49:07 INFO - PROCESS | 5483 | RSS: Main: 285138944 04:49:07 INFO - PROCESS | 5483 | 04:50:54 INFO - PROCESS | 5483 | ************************* 04:50:54 INFO - PROCESS | 5483 | A coding exception was thrown and uncaught in a Task. 04:50:54 INFO - PROCESS | 5483 | 04:50:54 ERROR - PROCESS | 5483 | Full message: TypeError: NetworkError when attempting to fetch resource. 04:50:54 INFO - PROCESS | 5483 | Full stack: 04:50:54 INFO - PROCESS | 5483 | ************************* 04:52:09 INFO - PROCESS | 5483 | Cycle 1(1): loaded http://localhost:55338/tests/dromaeo/cssquery-ext.html (next: http://localhost:55338/tests/dromaeo/cssquery-jquery.html) 04:52:10 INFO - PROCESS | 5483 | RSS: Main: 251166720 04:52:10 INFO - PROCESS | 5483 | 04:55:12 INFO - PROCESS | 5483 | Cycle 1(1): loaded http://localhost:55338/tests/dromaeo/cssquery-jquery.html (next: http://localhost:55338/tests/dromaeo/cssquery-mootools.html) 04:55:13 INFO - PROCESS | 5483 | RSS: Main: 179560448 04:55:13 INFO - PROCESS | 5483 | 04:58:15 INFO - PROCESS | 5483 | Cycle 1(1): loaded http://localhost:55338/tests/dromaeo/cssquery-mootools.html (next: http://localhost:55338/tests/dromaeo/cssquery-prototype.html) 04:58:15 INFO - PROCESS | 5483 | RSS: Main: 188522496 04:58:15 INFO - PROCESS | 5483 | 05:01:18 INFO - PROCESS | 5483 | Cycle 1(1): loaded http://localhost:55338/tests/dromaeo/cssquery-prototype.html (next: http://localhost:55338/tests/dromaeo/cssquery-yui.html) 05:01:19 INFO - PROCESS | 5483 | RSS: Main: 181932032 05:01:19 INFO - PROCESS | 5483 | 05:04:21 INFO - PROCESS | 5483 | Cycle 1(1): loaded http://localhost:55338/tests/dromaeo/cssquery-yui.html (next: http://localhost:55338/tests/dromaeo/cssquery-dojo.html) 05:04:22 INFO - PROCESS | 5483 | RSS: Main: 291893248 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | __start_tp_report 05:04:22 INFO - PROCESS | 5483 | _x_x_mozilla_page_load 05:04:22 INFO - PROCESS | 5483 | _x_x_mozilla_page_load_details 05:04:22 INFO - PROCESS | 5483 | |i|pagename|runs| 05:04:22 INFO - PROCESS | 5483 | |0;dojo.html;3111.128883912504;3153.4323821712082;3164.050784764571;3181.9045428637132;3187.8565464554094;5186.766595503202;5187.19598462238;5251.291075704784;5251.527362537371;5255.264263003182;5203.375594928604;5212.921806172911;5221.216817477371;5248.580113590913;5268.5521730652845;4419.62433193179;4628.028114096035;4849.224124140138;4850.07848508784;4859.514048595148;4624.884377890563;4668.2997550367545;4744.525547445262;4776.092542416947;4776.832810851621;4662.463816661077;4702.153612349775;4714.952850471485;4722.787474563653;4787.377640906695;4699.530046995307;4721.811127554894;4724.385829842133;4764.452088009889;4778.832740854054;4676.158291507527;4704.059188162347;4721.905561888777;4723.409573803275;4736.83421080264;5042.294078828967;5067.949320506785;5073.619478539124;5137.255098010804;5203.869903252411;5584.664920104807;5688;5691.800786972436;5696.316442026983;5696.8860622787315;5668.943310566883;5693.402192769782;5703.942960570383;5713.228714123582;5738.971305143489;5310.097283461821;5313.734313284359;5316.069687804657;5324.1747529133045;5356.946430535722;5544.91682624761;5585;5591.636543624732;5736;5752.827415177468;5556.138798486241;5632.5212356950115;5637.210790489335;5641.492265696025;5649.06790379591;5699.230603868425;5702.885942281131;5706.514946229534;5715.199872017921;5744.281964754406;5609.214709940612;5653.689047102449;5668.234788303609;5669.716514174274;5682.914756278659;5439.537639300704;5479.808206712746;5484.506394424441;5547.33431988164;5679;4365.367021781887;4365.825366985285;4400.933985990213;4408.338749187584;4455.086707225011;3954.090559171349;3957.683385329167;3958.940615890764;3983.521977362735;3992.740471869319;5311.415744268127;5353.732313384393;5360.222767698662;5366.463353664602;5387.703676297841;5448.509634132947;5495.835124946258;5497.39528651848;5543.473370029841;5704.201411802351;5215.061288967946;5282.656627319288;5287.629865909426;5300.231466437345;5310.495502927216;4819.879503012383;4825.1555977703765;4825.613950883921;4855.36880205571;4856.247281671346;5798.739056742373;5830.766769329264;5860.2967643883;5863.677497737665;5871.178035075093;5448.4006759257245;5472.452754724496;5474.233607295061;5524.337079550319;5610.5231055360755;5764.59647824665;5994.160817485643;6075;6077.088436734525;6079.3008803988105;5683.658980461186;5683.829485115453;5689.175069614966;5694.088945768823;5734.197212390185;5713.342965559014;5759.856003599776;5767.7981270657;5772.682502462405;5778.711064446845;5324.8136315228785;5351.625386222927;5352.625316227983;5433.293671822637;5620.437956204347;5423.078076727044;5586.329640443173;5587.944120558905;5602.13166959122;5604.943950560442;5546.833594992157;5556.416576259435;5557.499825015768;5557.527610153183;5561.304836895388;5346.411894691503;5477.561795056466;5603;5604.355499117653;5609.803656872153;5222.451642577475;5296.867578310573;5445.646033007842;5458.808941687022;5470.070088084955 05:04:22 INFO - PROCESS | 5483 | |1;ext.html;551.2145193099832;585.4993980146977;591.7839988404234;606.0938896349958;607.1045208317732;29694.703052969464;32921.67078329216;32955.83522082392;43139;44376.3343549847;45905.540944590546;46313;46377.30434043492;46403;46431.76784116075;9037.81924361514;9220.30847686423;9234.307426942973;9235.168834804866;9238.58426370815;7535.51019183754;7689.807754806118;9048.049954754755;10601.257911946166;10822.67531974042;10946.890531094667;11018.063464605519;11019.118470522339;11026.117910567136;11030.50362733675;10620.203484738637;10663.946680266627;10674.199435042403;10686.038256556947;10691.037806597406;10291.845622315672;10364.844527332096;10365.06714395708;10375.273730838844;10729.678109656723;42984.570154298366;43014.56985430137;43180.568194318286;43344;43406.348904766455;3763.303788799081;3809.6952243820706;3820.9235815283537;3830.693544516432;3924.50943632046;30780.8460957696;31750.682493175234;31847;31986.20034499156;31989.840050799598;3492.947605785915;3578.4274516077303;3595.0652830264057;3603.081214290339;3718.9442158367647;288567;289327;289831;291145;292177;60056.39943600595;60121.398786012454;60211.397886021456;60584.394156057875;60709;62011.37988620056;62296.68851655713;62326.37673623297;62351.6882415585;62354.688226558574;16132;16370;16383.83616163847;16385.50843474698;16392.344306227616;10740.462976851126;12590.559330423574;12646.494140234288;12669.113162078565;12671.556495522796;14168.291585420893;16400.671986560203;16739.07935063583;16769.66460670804;17485.47543573695;5237.973810131001;5880.8235752927485;5970.970145149333;6052.848678783065;6061.818145455643;853.1085016158006;872.5942436766934;900.5497251374313;916.2349438219162;916.6241840845355;29504.262393440335;29673.554896676567;29834.850825745732;30845.228869278;31009.844950775554;1028.5525796278644;1081.978360432787;1088.967330980072;1089.6077412131626;1102.4377567440663;16075.517734467985;16125.435609753602;16145.59636009109;16260.918695406684;16335.918320408322;439715;440446;443735;445247;446148;48338.583070847024;49723;56343.71828140833;57445.71277143671;57455;1368.8973327000515;1373.0731756064617;1396.5042409944526;1405.4518737692308;1408.2888141488484;29876.75244934044;31465.8426707865;31910.70321716417;31981.840090799396;32282.35435291328;49802;51473.48526514687;51615;51668.83311668803;51673.224901627254;366969;367985.1205207805;368720;369519;369876;38040.631061166496;38800;39286.41070383889;39290.80354598323;39370.40944385894;44194.33708494311;44331.55668443274;44766.77616611896;45956.310655340865;46004.76997615124;34981.47527787034;37839.62160378471;38200;38765.22469550537;39767.20465590614;37137.442938356486;37265.25469490649;37811.81094094512;39028.219435611696;39106.4134037984;38181.618183818915;38520;39297.2140557193;39408.40887386634;39426.40860387154;29497;32110.518342225354;33062.66937330692;33174.336513270086;33345;25376.619350710123;25701;25747.356316092246;25757;26236 05:04:22 INFO - PROCESS | 5483 | |2;jquery.html;388.32625394939794;410.4848415238875;417.6554342667299;423.74575254847093;446.1678968723332;12820.423080961356;14313.642158946019;19041.809581904196;19492.70760938587;19841.900790496027;19407.902960485215;19581.412557623295;19699.113539890703;19934.302299419523;20095.397138085846;5868.3838196989345;5941.138534912435;5958.13607026983;6031.788887388942;6062.302835173968;3707.7775333480076;5883.235179426669;5982.43166899146;5982.491488223506;5994.730237139339;3908.17928235071;6385.521085918552;6623.437007854314;6638.1370421845095;6758;6546.607203567777;6674.432673222782;6731.326867313279;6740.292269311701;6757;5954.136650185742;5965.28416590012;5969.970150149265;5985.790497332616;5987.940120598825;22582.209622663293;23110;23172;23248.53502929932;23334;3129.264622813637;3129.5462157986963;3136.372725454918;3141.2932090279733;3224.1617179533255;14231.928840355835;14481.203533805636;14522.782158267635;14538.418463261456;14845.183514906676;1845.9353922612645;1915.186045930474;1953.335865805633;1956.1979588368702;1976.6145601607548;65628.67185664088;82220.58889705573;84357;87766.12233877707;87786.5610671949;10810.29733067348;10954.616588419527;11010.284331518425;11057.447127643585;11164.441777911072;15673.216339182994;15709.528714138594;15776.211189440712;15828.366865325488;15842.366305347658;8147.307478864244;8180.386471014698;8190.467619604707;8306.875396869053;8489.660413583511;7719.228077192348;7808.687652493837;8014.358851291882;8015.519068855887;8025.117237103914;6917.9308206918295;7083;7121.394681452135;7165.534240274365;7176.96411517939;1960.362882063335;1980.4949737816764;1999.2702663527707;2038.4699978005826;2052.7639321478223;871.1375738019316;879.8196369744187;889.8843150390408;897.8473659477773;904.7150147703452;18490.537736556693;18609.627807444045;19537.804621953597;19860.801391986184;19950.401487955383;873.7815546113471;887.6848718704896;892.0187793427178;898.510311880027;903.0740401100387;10623.946880265548;11113.333200008025;11146.944265278622;11149.275297105662;11228;541148.9448924423;543258;546579;556757;557525;89305.55347223222;90512.54743726239;91732.54133729289;92024;93194.53402732943;1011.5751384418709;1024.4775164666073;1048.2819268800895;1051.7791263834526;1056.5087234436023;16291.674166516366;16580.502584922473;17134.742978855076;17252.827471725122;17479.213435395184;40871.978200544036;41269.793651032756;41660;41864.95337616462;43404.56595434131;53706.73146634398;54939.45060549343;55608.721956389956;56322.43677563336;56763.71618141883;8293.170682931659;8359.623816928375;8371.539565323965;8518.829623407373;8661.956690216508;13609.591712248648;13645.931770341085;13739.793903091662;13770.449182032606;13779.311034448438;11184.384858832842;11197.38414387184;11213.943930280297;11321.547138114383;11694.181407301407;11251.943740281573;11432.885671143182;11451.141164412536;11913.880861191277;12217.389130543259;11494.54021839117;11572.074234061423;11667.241629294069;11704.590339338423;11965.641030769091;8311.16888311164;8540.74377768668;8594.871076933727;8622;8629.705544168173;11578.71053223676;11720.41397930083;11725.472353743931;11771.176017679023;12105.515779368727 05:04:22 INFO - PROCESS | 5483 | |3;mootools.html;1422.8150340455738;1428.7071150414165;1434.5911415246653;1437.396293556706;1446.9493567725126;8092.959535202323;8479;8548.786280342994;8554.486730796156;8561.657533698644;8350.83298334033;8539.615717292721;8771.605277762501;8788.384813063089;8790.824183516326;2185.158713895154;2205.470687035108;2219.7225346831647;2221.822254219667;2222.5888210680996;2146.2917237311726;2240.574290884727;2242;2244.2818298144603;2244.663300504921;1826.9634607307846;1891.215145714527;2142.282335417637;2234.2626933112033;2237.429455488848;2151.66649169379;2163.9891800540895;2190.9561808763897;2193.473566344074;2203.8787866667326;2170.641844095738;2212.811910987568;2219.944501387462;2222.3221917315213;2225.265662331443;8552.48685078891;8566.871496927552;8604.8709269361;8605.913940860573;8609.870851937227;4936;5064.9746751266375;5065.898682026375;5082.847514574569;5084;3007.1429642551766;3116.9844150779327;3223.113643747988;3230.2893363460003;3272.96727032729;1270.333075135552;1317.5506942363324;1346.4210389532498;1348.6763176837587;1379.3034517568665;11535.134864885167;11801.232919860182;11837.88162118385;11852.822207666892;11865.40672966357;4072.450219220427;4307.956920430755;4352.107817897323;4361.1495758327455;4380.080183161572;10035.749106272402;10036.046575575308;10037.397756134655;10038.548265328078;10040.598376065022;5051.949480505222;5052.444231134572;5056.140456122468;5068.037072956126;5072.721000345016;4452.265376212953;4510.887227819265;4608.516105808909;4610.147122782296;4610.262358022767;3567.7324200685052;3654.6710796028483;3660.7803531787645;3683.90790230241;3731.164315120528;1088.5210507376728;1093.8960798724108;1105.5080489182396;1114.7157474843864;1120.9943950280197;762.4700832921177;778.1284960843891;780.4692808889896;794.4994653368457;795.2246559604339;5423.891522169613;5424.945750542444;5430.70131142791;5542;5702.942970570241;918.6233644205844;966.3622009473713;969.8593703913034;975.5951280218771;983.9901600984042;3677.5035370224678;3692.5568931728367;3952.822123004472;3989.2221016901426;4017.5178978522763;10004.749881252881;10038;10198.694039178836;10341.844872326921;10354.741131471774;10034.849477257847;10099.646512372032;10137.64518241858;10147.289689721796;10149.188064954786;7634.274743899321;7817;7829.569373684502;7869.685212591432;7873.133955264916;5430.456954304538;5575.330960284792;5601.663900166003;5620.971895140498;5772.2207501986695;9208.539573021188;9444.52777361143;9483.620655173716;9565.473898935625;9604.807903841744;9481.241500680067;9499.667511637335;9617.663381781604;9755.609775608897;9760.267979901393;7317.597532135784;7409.481336306407;7431.256874312526;7454.962725186339;7471.252874712485;7993.6003199838615;7996.3602911768085;8004.5597492138495;8007.199280071946;8009.639566219417;6896.586204827727;7055.894161587683;7217.097862767154;7223.819404514719;7410.666520006721;6917.51273476205;7098.716051358095;7106.786796396116;7341.045664063638;7353.191148973501;6330.39861213184;6332.746690132527;6355.428011478989;6371.74513019474;6373.490120790419;4641.791119399702;4654.674172808006;4710.010897711519;4763.666543342071;4768.094062128184;4720.173969555382;4808.61531077506;4845.6608037437045;4947.703137811743;5079.009593129304 05:04:22 INFO - PROCESS | 5483 | |4;prototype.html;371.92189640175565;397.4455634390024;399.2892651081075;402.30200601955613;406.7844042657391;5087.465816089303;5221.817236396727;5297.973510132449;5327.147656374986;5340.305760251167;5111.156659151245;5182.792688292464;5235.214717792323;5243.68537887727;5257.579393648509;4138.834446622139;4153.584641535837;4175.64291605228;4177.51958524769;4206.894827629303;3819.9618003819883;4177.3107437272965;4187.769672668002;4198.160367926412;4205.663546916255;4098.6516146127615;4133.1527036957505;4141.855035073773;4165.458490396244;4171.958280417188;4101.958980410188;4109.6506796922295;4112.3420252759715;4118.4028315894175;4156.667466602665;3731.7014638828828;3734.1038150843874;3757.928990237769;3765.9623403765886;3788.8673896413493;5022.618779835538;5095.286659867622;5138.897222055538;5140.408852981917;5161.7161056141895;4772.880677983078;4792.616590672737;4842.201036828919;4853.466118726938;4867.7100568349415;5402.243685883979;5555.611107222496;5571.275734154575;5595.545158258841;5601.439856014406;4145.652662884575;4147.751134931884;4149.875503734863;4165.396017577465;4190.224808410454;5675.262215911905;5700.489370316869;5741;5744.597878148531;5779.508741756956;4271.893202669896;4285.571442855689;4288.635465985364;4290.120525292307;4313.439252897103;4152.8338866445;4317.438732964694;4325.113351762881;4325.767156360485;4349.108137959997;4765.404324459442;4796.352492413549;4811.518848115231;4828.251620998751;4831.284893862628;5533.6403133796175;5538.556915446755;5557.249771280906;5569.096757437049;5618.00560800918;1384.6953670192543;1438.2592964623018;1449.239149446528;1455.3596417576232;1465.8932505957935;1003.4079892863246;1046.5238316565944;1051.5793682526898;1065.3607835298915;1072.6299426697776;5094.7962081516325;5095.617828662865;5144.54996428087;5150.48495150482;5180.870478238075;5433.483819037185;5435.211894275308;5479.726013699299;5485.341758988947;5487.807926722546;4930.323689945436;5055.848324550269;5059.747012649353;5153.2785410042625;5170.870728231825;2902.0278206800535;2930.6190195274476;2935.2515108647585;2936.841421555155;2944.6466424028827;5613.382527921925;5702;5724.370319264877;5736.5410767139365;5749.511291540266;5336.653117547347;5432.91850622241;5505.174223866452;5586.910552442316;5596.97201513998;5670.744816483186;5685.289338832646;5733.627314224562;5773.653580785251;5816.069428891357;5309.36287645485;5377.704226267593;5495.477929596682;5525.696086715108;5532.391436942014;5605.066252143004;5633.0987042073075;5635.830925072254;5640.4077571856005;5683.77264909399;5922.7927022554;5942.762289508544;5948.256467941507;5967.313758917607;6010.797840431844;3900.7464514806447;4026.5570787212796;4042.959570404258;4051.4125451809914;4082.632563069338;5594.944050559605;5612.102063669793;5636.239107720406;5655.4344565543115;5689.516391106637;5502.614816962774;5542.806001789918;5613.719314034363;5621.100623900156;5627.606067575231;5419.295491586068;5469.316335458067;5491.505764481216;5528.419515950767;5533.944660553504;5473.233747275464;5480.150576660624;5509.834704958857;5514.944850551443;5523.392426833126;5281.313429254173;5501.312335958005;5541.445855414427;5599.552035837205;5601.551875850004;5405.324334458192;5431.891362172813;5446.537044351275;5453.64551304164;5467.097928841856 05:04:22 INFO - PROCESS | 5483 | |5;yui.html;674.0664180110548;704.2464562917673;736.8784150615148;809.4455298120788;811.4968719393975;14269.215193164371;16054.678906421865;16691.749623755655;17236.827631723678;17317.22072506737;16509.752353714674;16760.580985475368;16795.32818687251;16909.661806763856;16941.745873811902;782.5734974438944;792.3265224559121;813.0690359538326;814.6008455856647;816.8243827577099;791.6833266693311;806.7458750493576;809.1665584448028;810.3314765318606;810.4245985350408;852.7910661887846;854.4318028511033;854.5897968974896;855.0765173612483;855.2730179347536;848.7114381110421;849.7663142635763;850.2220468271555;851.3912552524974;852.0414533649645;619.0961196652892;623.5167744997618;624.322609968185;624.687656171914;626.9529785266124;15277.770833437507;15416;15466.690666186725;15488.148151851643;15795.921020394939;13839.760605247164;14445.71108577833;14485;14552.927235363755;14645.121292722471;12265.509379624804;12328.938355308166;12362.814557781641;12467.812982805266;12504.874951250553;3640.4903313536124;3704.9259014819822;3772.471853940423;3776.2258736958856;3779.4141908004303;77163;78074;78579.21420785776;79266.60366698129;79529.20470795275;10659.4137322448;10937.212482904231;10943.398113103856;10977;11309.264897781617;19489.90255048744;21511.46221344479;21835.781642183694;21917.780822191893;22167.556648866932;7693.961530192425;7906.525608463396;7945.602719863984;8029;8058.556779377191;4317.654587632982;4377.78111094444;4384.780760961939;4392.629031618207;4457.888552786207;3636.5090712753968;3755.511783468132;3761.5110035695734;3767;3800.315943130208;716.874546954281;723.8805597076423;730.2660825870073;741.1772932045425;750.4259241680119;640.4364159539668;652.7682672651235;672.4922683374119;677.4884961853769;696.1263614164293;9116.225120864801;9301.90698093024;9383.718488445358;9534.046595340411;9867.259955503367;655.4723447624613;682.4335801284922;687.5049964025893;693.3759616345329;694.5416025423197;4307.7415355078165;4600.792964316547;4653.441587009513;5264.710440925785;5420.91868621971;71689.64155179191;72735;72763.63618181876;72864;73959;55861;61028.38971610316;61272.387276127556;61457.38542614516;61761.38238617646;54001.76956645568;55458;55856.486458110296;55903;56046.15930761042;10084;10134.543945522617;10367;10641.255112142077;10675.199360047873;38903.61096389113;39728;39784.403233950936;40918;41983.790081049396;46771.76614116908;47312.7634361826;47532.52467475419;47830.521694784;50395;12283.631491055283;12482.438290277141;12574.874251257736;12585.496580136693;13046.934765326112;14114.576562703136;14132.364043617856;14140.717185656435;14207;14570.781438278222;13317.400716967953;13384.93307533456;13558.93220533891;13573.679867166591;14273.57179284623;13293.80059299092;13422.328883555978;13513.797293040809;14151.867850572135;14153.929230354193;12402.13185077036;12740.490380384681;13165.012624053043;13204.537841175512;13678.726425471634;10611;10735.677929662123;10992.835107473555;11073.667789966314;11092.279001864854;9865.802683946424;10703.101625611038;10817.242793004414;10883.891161088288;10963.616273430393 05:04:22 INFO - PROCESS | 5483 | __end_tp_report 05:04:22 INFO - PROCESS | 5483 | __start_cc_report 05:04:22 INFO - PROCESS | 5483 | _x_x_mozilla_cycle_collect,1479 05:04:22 INFO - PROCESS | 5483 | __end_cc_report 05:04:22 INFO - PROCESS | 5483 | __startTimestamp1487336662063__endTimestamp 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | ------- Summary: start ------- 05:04:22 INFO - PROCESS | 5483 | Number of tests: 6 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | [#0] dojo.html Cycles:165 Average:5236.78 Median:5433.29 stddev:590.33 (10.9%) stddev-sans-first:568.10 05:04:22 INFO - PROCESS | 5483 | Values: 3111.1 3153.4 3164.1 3181.9 3187.9 5186.8 5187.2 5251.3 5251.5 5255.3 5203.4 5212.9 5221.2 5248.6 5268.6 4419.6 4628.0 4849.2 4850.1 4859.5 4624.9 4668.3 4744.5 4776.1 4776.8 4662.5 4702.2 4715.0 4722.8 4787.4 4699.5 4721.8 4724.4 4764.5 4778.8 4676.2 4704.1 4721.9 4723.4 4736.8 5042.3 5067.9 5073.6 5137.3 5203.9 5584.7 5688.0 5691.8 5696.3 5696.9 5668.9 5693.4 5703.9 5713.2 5739.0 5310.1 5313.7 5316.1 5324.2 5356.9 5544.9 5585.0 5591.6 5736.0 5752.8 5556.1 5632.5 5637.2 5641.5 5649.1 5699.2 5702.9 5706.5 5715.2 5744.3 5609.2 5653.7 5668.2 5669.7 5682.9 5439.5 5479.8 5484.5 5547.3 5679.0 4365.4 4365.8 4400.9 4408.3 4455.1 3954.1 3957.7 3958.9 3983.5 3992.7 5311.4 5353.7 5360.2 5366.5 5387.7 5448.5 5495.8 5497.4 5543.5 5704.2 5215.1 5282.7 5287.6 5300.2 5310.5 4819.9 4825.2 4825.6 4855.4 4856.2 5798.7 5830.8 5860.3 5863.7 5871.2 5448.4 5472.5 5474.2 5524.3 5610.5 5764.6 5994.2 6075.0 6077.1 6079.3 5683.7 5683.8 5689.2 5694.1 5734.2 5713.3 5759.9 5767.8 5772.7 5778.7 5324.8 5351.6 5352.6 5433.3 5620.4 5423.1 5586.3 5587.9 5602.1 5604.9 5546.8 5556.4 5557.5 5557.5 5561.3 5346.4 5477.6 5603.0 5604.4 5609.8 5222.5 5296.9 5445.6 5458.8 5470.1 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | [#1] ext.html Cycles:180 Average:53742.69 Median:20428.19 stddev:98163.45 (480.5%) stddev-sans-first:98357.59 05:04:22 INFO - PROCESS | 5483 | Values: 551.2 585.5 591.8 606.1 607.1 29694.7 32921.7 32955.8 43139.0 44376.3 45905.5 46313.0 46377.3 46403.0 46431.8 9037.8 9220.3 9234.3 9235.2 9238.6 7535.5 7689.8 9048.0 10601.3 10822.7 10946.9 11018.1 11019.1 11026.1 11030.5 10620.2 10663.9 10674.2 10686.0 10691.0 10291.8 10364.8 10365.1 10375.3 10729.7 42984.6 43014.6 43180.6 43344.0 43406.3 3763.3 3809.7 3820.9 3830.7 3924.5 30780.8 31750.7 31847.0 31986.2 31989.8 3492.9 3578.4 3595.1 3603.1 3718.9 288567.0 289327.0 289831.0 291145.0 292177.0 60056.4 60121.4 60211.4 60584.4 60709.0 62011.4 62296.7 62326.4 62351.7 62354.7 16132.0 16370.0 16383.8 16385.5 16392.3 10740.5 12590.6 12646.5 12669.1 12671.6 14168.3 16400.7 16739.1 16769.7 17485.5 5238.0 5880.8 5971.0 6052.8 6061.8 853.1 872.6 900.5 916.2 916.6 29504.3 29673.6 29834.9 30845.2 31009.8 1028.6 1082.0 1089.0 1089.6 1102.4 16075.5 16125.4 16145.6 16260.9 16335.9 439715.0 440446.0 443735.0 445247.0 446148.0 48338.6 49723.0 56343.7 57445.7 57455.0 1368.9 1373.1 1396.5 1405.5 1408.3 29876.8 31465.8 31910.7 31981.8 32282.4 49802.0 51473.5 51615.0 51668.8 51673.2 366969.0 367985.1 368720.0 369519.0 369876.0 38040.6 38800.0 39286.4 39290.8 39370.4 44194.3 44331.6 44766.8 45956.3 46004.8 34981.5 37839.6 38200.0 38765.2 39767.2 37137.4 37265.3 37811.8 39028.2 39106.4 38181.6 38520.0 39297.2 39408.4 39426.4 29497.0 32110.5 33062.7 33174.3 33345.0 25376.6 25701.0 25747.4 25757.0 26236.0 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | [#2] jquery.html Cycles:180 Average:30796.83 Median:2048.05 stddev:90173.77 (4402.9%) stddev-sans-first:90397.82 05:04:22 INFO - PROCESS | 5483 | Values: 388.3 410.5 417.7 423.7 446.2 12820.4 14313.6 19041.8 19492.7 19841.9 19407.9 19581.4 19699.1 19934.3 20095.4 5868.4 5941.1 5958.1 6031.8 6062.3 3707.8 5883.2 5982.4 5982.5 5994.7 3908.2 6385.5 6623.4 6638.1 6758.0 6546.6 6674.4 6731.3 6740.3 6757.0 5954.1 5965.3 5970.0 5985.8 5987.9 22582.2 23110.0 23172.0 23248.5 23334.0 3129.3 3129.5 3136.4 3141.3 3224.2 14231.9 14481.2 14522.8 14538.4 14845.2 1845.9 1915.2 1953.3 1956.2 1976.6 65628.7 82220.6 84357.0 87766.1 87786.6 10810.3 10954.6 11010.3 11057.4 11164.4 15673.2 15709.5 15776.2 15828.4 15842.4 8147.3 8180.4 8190.5 8306.9 8489.7 7719.2 7808.7 8014.4 8015.5 8025.1 6917.9 7083.0 7121.4 7165.5 7177.0 1960.4 1980.5 1999.3 2038.5 2052.8 871.1 879.8 889.9 897.8 904.7 18490.5 18609.6 19537.8 19860.8 19950.4 873.8 887.7 892.0 898.5 903.1 10623.9 11113.3 11146.9 11149.3 11228.0 541148.9 543258.0 546579.0 556757.0 557525.0 89305.6 90512.5 91732.5 92024.0 93194.5 1011.6 1024.5 1048.3 1051.8 1056.5 16291.7 16580.5 17134.7 17252.8 17479.2 40872.0 41269.8 41660.0 41865.0 43404.6 53706.7 54939.5 55608.7 56322.4 56763.7 8293.2 8359.6 8371.5 8518.8 8662.0 13609.6 13645.9 13739.8 13770.4 13779.3 11184.4 11197.4 11213.9 11321.5 11694.2 11251.9 11432.9 11451.1 11913.9 12217.4 11494.5 11572.1 11667.2 11704.6 11965.6 8311.2 8540.7 8594.9 8622.0 8629.7 11578.7 11720.4 11725.5 11771.2 12105.5 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | [#3] mootools.html Cycles:180 Average:5490.09 Median:4788.35 stddev:3137.52 (65.5%) stddev-sans-first:3131.44 05:04:22 INFO - PROCESS | 5483 | Values: 1422.8 1428.7 1434.6 1437.4 1446.9 8093.0 8479.0 8548.8 8554.5 8561.7 8350.8 8539.6 8771.6 8788.4 8790.8 2185.2 2205.5 2219.7 2221.8 2222.6 2146.3 2240.6 2242.0 2244.3 2244.7 1827.0 1891.2 2142.3 2234.3 2237.4 2151.7 2164.0 2191.0 2193.5 2203.9 2170.6 2212.8 2219.9 2222.3 2225.3 8552.5 8566.9 8604.9 8605.9 8609.9 4936.0 5065.0 5065.9 5082.8 5084.0 3007.1 3117.0 3223.1 3230.3 3273.0 1270.3 1317.6 1346.4 1348.7 1379.3 11535.1 11801.2 11837.9 11852.8 11865.4 4072.5 4308.0 4352.1 4361.1 4380.1 10035.7 10036.0 10037.4 10038.5 10040.6 5051.9 5052.4 5056.1 5068.0 5072.7 4452.3 4510.9 4608.5 4610.1 4610.3 3567.7 3654.7 3660.8 3683.9 3731.2 1088.5 1093.9 1105.5 1114.7 1121.0 762.5 778.1 780.5 794.5 795.2 5423.9 5424.9 5430.7 5542.0 5702.9 918.6 966.4 969.9 975.6 984.0 3677.5 3692.6 3952.8 3989.2 4017.5 10004.7 10038.0 10198.7 10341.8 10354.7 10034.8 10099.6 10137.6 10147.3 10149.2 7634.3 7817.0 7829.6 7869.7 7873.1 5430.5 5575.3 5601.7 5621.0 5772.2 9208.5 9444.5 9483.6 9565.5 9604.8 9481.2 9499.7 9617.7 9755.6 9760.3 7317.6 7409.5 7431.3 7455.0 7471.3 7993.6 7996.4 8004.6 8007.2 8009.6 6896.6 7055.9 7217.1 7223.8 7410.7 6917.5 7098.7 7106.8 7341.0 7353.2 6330.4 6332.7 6355.4 6371.7 6373.5 4641.8 4654.7 4710.0 4763.7 4768.1 4720.2 4808.6 4845.7 4947.7 5079.0 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | [#4] prototype.html Cycles:180 Average:4659.14 Median:5175.87 stddev:1326.30 (25.6%) stddev-sans-first:1290.39 05:04:22 INFO - PROCESS | 5483 | Values: 371.9 397.4 399.3 402.3 406.8 5087.5 5221.8 5298.0 5327.1 5340.3 5111.2 5182.8 5235.2 5243.7 5257.6 4138.8 4153.6 4175.6 4177.5 4206.9 3820.0 4177.3 4187.8 4198.2 4205.7 4098.7 4133.2 4141.9 4165.5 4172.0 4102.0 4109.7 4112.3 4118.4 4156.7 3731.7 3734.1 3757.9 3766.0 3788.9 5022.6 5095.3 5138.9 5140.4 5161.7 4772.9 4792.6 4842.2 4853.5 4867.7 5402.2 5555.6 5571.3 5595.5 5601.4 4145.7 4147.8 4149.9 4165.4 4190.2 5675.3 5700.5 5741.0 5744.6 5779.5 4271.9 4285.6 4288.6 4290.1 4313.4 4152.8 4317.4 4325.1 4325.8 4349.1 4765.4 4796.4 4811.5 4828.3 4831.3 5533.6 5538.6 5557.2 5569.1 5618.0 1384.7 1438.3 1449.2 1455.4 1465.9 1003.4 1046.5 1051.6 1065.4 1072.6 5094.8 5095.6 5144.5 5150.5 5180.9 5433.5 5435.2 5479.7 5485.3 5487.8 4930.3 5055.8 5059.7 5153.3 5170.9 2902.0 2930.6 2935.3 2936.8 2944.6 5613.4 5702.0 5724.4 5736.5 5749.5 5336.7 5432.9 5505.2 5586.9 5597.0 5670.7 5685.3 5733.6 5773.7 5816.1 5309.4 5377.7 5495.5 5525.7 5532.4 5605.1 5633.1 5635.8 5640.4 5683.8 5922.8 5942.8 5948.3 5967.3 6010.8 3900.7 4026.6 4043.0 4051.4 4082.6 5594.9 5612.1 5636.2 5655.4 5689.5 5502.6 5542.8 5613.7 5621.1 5627.6 5419.3 5469.3 5491.5 5528.4 5533.9 5473.2 5480.2 5509.8 5514.9 5523.4 5281.3 5501.3 5541.4 5599.6 5601.6 5405.3 5431.9 5446.5 5453.6 5467.1 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - PROCESS | 5483 | [#5] yui.html Cycles:180 Average:16749.30 Median:4347.72 stddev:20610.85 (474.1%) stddev-sans-first:20633.32 05:04:22 INFO - PROCESS | 5483 | Values: 674.1 704.2 736.9 809.4 811.5 14269.2 16054.7 16691.7 17236.8 17317.2 16509.8 16760.6 16795.3 16909.7 16941.7 782.6 792.3 813.1 814.6 816.8 791.7 806.7 809.2 810.3 810.4 852.8 854.4 854.6 855.1 855.3 848.7 849.8 850.2 851.4 852.0 619.1 623.5 624.3 624.7 627.0 15277.8 15416.0 15466.7 15488.1 15795.9 13839.8 14445.7 14485.0 14552.9 14645.1 12265.5 12328.9 12362.8 12467.8 12504.9 3640.5 3704.9 3772.5 3776.2 3779.4 77163.0 78074.0 78579.2 79266.6 79529.2 10659.4 10937.2 10943.4 10977.0 11309.3 19489.9 21511.5 21835.8 21917.8 22167.6 7694.0 7906.5 7945.6 8029.0 8058.6 4317.7 4377.8 4384.8 4392.6 4457.9 3636.5 3755.5 3761.5 3767.0 3800.3 716.9 723.9 730.3 741.2 750.4 640.4 652.8 672.5 677.5 696.1 9116.2 9301.9 9383.7 9534.0 9867.3 655.5 682.4 687.5 693.4 694.5 4307.7 4600.8 4653.4 5264.7 5420.9 71689.6 72735.0 72763.6 72864.0 73959.0 55861.0 61028.4 61272.4 61457.4 61761.4 54001.8 55458.0 55856.5 55903.0 56046.2 10084.0 10134.5 10367.0 10641.3 10675.2 38903.6 39728.0 39784.4 40918.0 41983.8 46771.8 47312.8 47532.5 47830.5 50395.0 12283.6 12482.4 12574.9 12585.5 13046.9 14114.6 14132.4 14140.7 14207.0 14570.8 13317.4 13384.9 13558.9 13573.7 14273.6 13293.8 13422.3 13513.8 14151.9 14153.9 12402.1 12740.5 13165.0 13204.5 13678.7 10611.0 10735.7 10992.8 11073.7 11092.3 9865.8 10703.1 10817.2 10883.9 10963.6 05:04:22 INFO - PROCESS | 5483 | -------- Summary: end -------- 05:04:22 INFO - PROCESS | 5483 | 05:04:22 INFO - TEST-INFO | 5483: exit 0 05:04:22 INFO - TEST-OK | dromaeo_css | took 1115985ms 05:04:22 INFO - TEST-START | kraken 05:04:22 INFO - operating with platform_type : linux_ 05:04:22 INFO - Initialising browser for kraken test... 05:04:22 INFO - TEST-INFO | started process 5801 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp1ZmRO4/profile http://localhost:55338/getInfo.html) 05:04:25 INFO - PROCESS | 5801 | Iterating over profile /tmp/tmp1ZmRO4/profile 05:04:26 INFO - PROCESS | 5801 | __metrics Screen width/height:1600/1200 05:04:26 INFO - PROCESS | 5801 | colorDepth:24 05:04:26 INFO - PROCESS | 5801 | Browser inner width/height: 1024/697 05:04:26 INFO - PROCESS | 5801 | __metrics 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/storage.sqlite-journal = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/crashes = Fri Feb 17 2017 05:04:22 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/pluginreg.dat = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/extensions.json = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/places.sqlite-wal = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/blocklist.xml = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/frequencyCap.json = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/places.sqlite = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | Stat failure 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/minidumps = Fri Feb 17 2017 05:04:22 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/startupCache = Fri Feb 17 2017 05:04:22 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/mimeTypes.rdf = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/cert8.db = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/storage.sqlite = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/extensions = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/secmod.db = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/prefs.js = Fri Feb 17 2017 04:45:04 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/directoryLinks.json = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/thumbnails = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/localstore.rdf = Fri Feb 17 2017 04:45:04 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/cookies.sqlite = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/gmp = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/content-prefs.sqlite = Fri Feb 17 2017 05:04:24 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/places.sqlite-shm = Fri Feb 17 2017 05:04:24 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | Stat failure 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/.parentlock = Fri Feb 17 2017 05:04:22 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/extensions.ini = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/permissions.sqlite = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/cache2 = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/compatibility.ini = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/safebrowsing = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/bookmarkbackups = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/user.js = Fri Feb 17 2017 05:04:22 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/addons.json = Fri Feb 17 2017 05:04:25 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/key3.db = Fri Feb 17 2017 05:04:23 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/sessionCheckpoints.json = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:26 INFO - PROCESS | 5801 | No birth date. Using mtime. 05:04:26 INFO - PROCESS | 5801 | Using date: /tmp/tmp1ZmRO4/profile/webappsstore.sqlite = Fri Feb 17 2017 05:04:26 GMT-0800 (PST) 05:04:27 INFO - PROCESS | 5801 | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 692: Error: Phase "quit-application-granted" is finished, it is too late to register completion condition "SessionStore: flushing all windows" 05:04:27 INFO - PROCESS | 5801 | JavaScript error: resource://app/modules/BrowserUsageTelemetry.jsm, line 303: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIObserverService.removeObserver] 05:04:28 INFO - TEST-INFO | 5801: exit 0 05:04:28 INFO - Browser initialized. 05:04:28 INFO - Running cycle 1/1 for kraken test... 05:04:28 INFO - TEST-INFO | started process 5892 (/builds/slave/test/build/application/firefox/firefox -profile /tmp/tmp1ZmRO4/profile -tp file:/builds/slave/test/build/tests/talos/talos/tests/kraken/kraken.manifest.develop -tpchrome -tpnoisy -tpcycles 1 -tppagecycles 1) 05:04:28 CRITICAL - PROCESS | 5892 | Inconsistency detected by ld.so: dl-open.c: 667: _dl_open: Assertion `_dl_debug_initialize (0, args.nsid)->r_state == RT_CONSISTENT' failed! 05:04:28 INFO - Terminating psutil.Process(pid=5892, name='firefox') 05:04:28 INFO - TEST-INFO | 5892: exit 127 05:04:28 INFO - TEST-UNEXPECTED-ERROR | kraken | Could not find report in browser output: [('tsformat', ('__start_report', '__end_report')), ('tpformat', ('__start_tp_report', '__end_tp_report'))] 05:04:28 ERROR - Traceback (most recent call last): 05:04:28 INFO - File "/builds/slave/test/build/tests/talos/talos/run_tests.py", line 202, in run_tests 05:04:28 INFO - talos_results.add(mytest.runTest(browser_config, test)) 05:04:28 INFO - File "/builds/slave/test/build/tests/talos/talos/ttest.py", line 70, in runTest 05:04:28 INFO - return self._runTest(browser_config, test_config, setup) 05:04:28 INFO - File "/builds/slave/test/build/tests/talos/talos/ttest.py", line 232, in _runTest 05:04:28 INFO - else None) 05:04:28 INFO - File "/builds/slave/test/build/tests/talos/talos/results.py", line 94, in add 05:04:28 INFO - global_counters=self.global_counters 05:04:28 INFO - File "/builds/slave/test/build/tests/talos/talos/results.py", line 311, in __init__ 05:04:28 INFO - self.parse() 05:04:28 INFO - File "/builds/slave/test/build/tests/talos/talos/results.py", line 338, in parse 05:04:28 INFO - % self.report_tokens) 05:04:28 INFO - File "/builds/slave/test/build/tests/talos/talos/results.py", line 322, in error 05:04:28 INFO - raise utils.TalosError(message) 05:04:28 INFO - TalosError: Could not find report in browser output: [('tsformat', ('__start_report', '__end_report')), ('tpformat', ('__start_tp_report', '__end_tp_report'))] 05:04:28 INFO - TEST-INFO took 5745ms 05:04:28 INFO - SUITE-END | took 1121s 05:04:29 ERROR - Return code: 2 05:04:29 WARNING - setting return code to 2 05:04:29 CRITICAL - # TBPL RETRY # 05:04:29 WARNING - setting return code to 4 05:04:29 INFO - Running post-action listener: _resource_record_post_action 05:04:29 INFO - [mozharness: 2017-02-17 13:04:29.009186Z] Finished run-tests step (success) 05:04:29 INFO - Running post-run listener: _resource_record_post_run 05:04:29 INFO - Total resource usage - Wall time: 1139s; CPU: 13.0%; Read bytes: 0; Write bytes: 315162624; Read time: 0; Write time: 245636 05:04:29 INFO - TinderboxPrint: CPU usage
13.2% 05:04:29 INFO - TinderboxPrint: I/O read bytes / time
0 / 0 05:04:29 INFO - TinderboxPrint: I/O write bytes / time
315,162,624 / 245,636 05:04:29 INFO - TinderboxPrint: CPU idle
7,888.2 (86.8%) 05:04:29 INFO - TinderboxPrint: CPU user
1,164.8 (12.8%) 05:04:29 INFO - TinderboxPrint: Swap in / out
0 / 0 05:04:29 INFO - install - Wall time: 17s; CPU: 13.0%; Read bytes: 0; Write bytes: 110604288; Read time: 0; Write time: 97904 05:04:29 INFO - run-tests - Wall time: 1122s; CPU: 13.0%; Read bytes: 0; Write bytes: 204558336; Read time: 0; Write time: 147732 05:04:29 INFO - Running post-run listener: _upload_blobber_files 05:04:29 INFO - Blob upload gear active. 05:04:29 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 05:04:29 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 05:04:29 INFO - Running command: ['/builds/slave/test/build/venv/bin/python', '/builds/slave/test/build/venv/bin/blobberc.py', '-u', 'https://blobupload.elasticbeanstalk.com', '-a', '/builds/slave/test/oauth.txt', '-b', 'Firefox', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 05:04:29 INFO - Copy/paste: /builds/slave/test/build/venv/bin/python /builds/slave/test/build/venv/bin/blobberc.py -u https://blobupload.elasticbeanstalk.com -a /builds/slave/test/oauth.txt -b Firefox -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 05:04:30 INFO - (blobuploader) - INFO - Open directory for files ... 05:04:30 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 05:04:30 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 05:04:30 INFO - (blobuploader) - INFO - Uploading, attempt #1. 05:04:34 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 05:04:34 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 05:04:34 INFO - (blobuploader) - INFO - Done attempting. 05:04:34 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/dromaeojs_raw.log ... 05:04:34 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 05:04:34 INFO - (blobuploader) - INFO - Uploading, attempt #1. 05:04:35 INFO - (blobuploader) - INFO - TinderboxPrint: dromaeojs_raw.log: uploaded 05:04:35 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 05:04:35 INFO - (blobuploader) - INFO - Done attempting. 05:04:35 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/dromaeojs_errorsummary.log ... 05:04:35 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 05:04:35 INFO - (blobuploader) - INFO - Uploading, attempt #1. 05:04:36 INFO - (blobuploader) - INFO - TinderboxPrint: dromaeojs_errorsummary.log: uploaded 05:04:36 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 05:04:36 INFO - (blobuploader) - INFO - Done attempting. 05:04:36 INFO - (blobuploader) - INFO - Iteration through files over. 05:04:36 INFO - Return code: 0 05:04:36 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 05:04:36 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 05:04:36 INFO - Setting buildbot property blobber_files to {"dromaeojs_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/11632de298f56d543914104f5eac06f385175d3b5a52ffab46e7cdb1586f962de07fd1a8b5f6089ea55061ce2395c34b4fb52925577173a938e8ee063a04cbe3", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79bf0e83c4445443d21cb977e5b59383105f9ef833c859a9a8a2c84e2af0ecc854b9329e1deac12ebe6d91be2235c8a03b8817d763218c9acfa66a86b27993d9", "dromaeojs_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/00b345dd2426e7fa62c37474aa768eb9ef408affce2a30417adf5e5928e2f9772a73093c37b3971ff90d27e84add49f9067f4a4c7115306092a6236404cd4985"} 05:04:36 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 05:04:36 INFO - Writing to file /builds/slave/test/properties/blobber_files 05:04:36 INFO - Contents: 05:04:36 INFO - blobber_files:{"dromaeojs_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/11632de298f56d543914104f5eac06f385175d3b5a52ffab46e7cdb1586f962de07fd1a8b5f6089ea55061ce2395c34b4fb52925577173a938e8ee063a04cbe3", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79bf0e83c4445443d21cb977e5b59383105f9ef833c859a9a8a2c84e2af0ecc854b9329e1deac12ebe6d91be2235c8a03b8817d763218c9acfa66a86b27993d9", "dromaeojs_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/00b345dd2426e7fa62c37474aa768eb9ef408affce2a30417adf5e5928e2f9772a73093c37b3971ff90d27e84add49f9067f4a4c7115306092a6236404cd4985"} 05:04:36 INFO - Running post-run listener: copy_logs_to_upload_dir 05:04:36 INFO - Copying logs to upload dir... 05:04:36 INFO - mkdir: /builds/slave/test/build/upload/logs 05:04:36 INFO - Copying logs to upload dir... 05:04:36 WARNING - returning nonzero exit status 4 program finished with exit code 4 elapsedTime=1198.343128 ========= master_lag: 0.03 ========= ========= Finished '/tools/buildbot/bin/python scripts/scripts/talos_script.py ...' failed (results: 5, elapsed: 19 mins, 58 secs) (at 2017-02-17 05:04:36.456998) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-02-17 05:04:36.461477) ========= 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=20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False blobber_files:{"dromaeojs_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/11632de298f56d543914104f5eac06f385175d3b5a52ffab46e7cdb1586f962de07fd1a8b5f6089ea55061ce2395c34b4fb52925577173a938e8ee063a04cbe3", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79bf0e83c4445443d21cb977e5b59383105f9ef833c859a9a8a2c84e2af0ecc854b9329e1deac12ebe6d91be2235c8a03b8817d763218c9acfa66a86b27993d9", "dromaeojs_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/00b345dd2426e7fa62c37474aa768eb9ef408affce2a30417adf5e5928e2f9772a73093c37b3971ff90d27e84add49f9067f4a4c7115306092a6236404cd4985"} build_url:https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2 program finished with exit code 0 elapsedTime=0.011400 build_url: 'https://queue.taskcluster.net/v1/task/bkheuIwGQzWQeKLtfoJKuA/artifacts/public/build/target.tar.bz2' blobber_files: '{"dromaeojs_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/11632de298f56d543914104f5eac06f385175d3b5a52ffab46e7cdb1586f962de07fd1a8b5f6089ea55061ce2395c34b4fb52925577173a938e8ee063a04cbe3", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/79bf0e83c4445443d21cb977e5b59383105f9ef833c859a9a8a2c84e2af0ecc854b9329e1deac12ebe6d91be2235c8a03b8817d763218c9acfa66a86b27993d9", "dromaeojs_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/Firefox/sha512/00b345dd2426e7fa62c37474aa768eb9ef408affce2a30417adf5e5928e2f9772a73093c37b3971ff90d27e84add49f9067f4a4c7115306092a6236404cd4985"}' ========= master_lag: 0.01 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-02-17 05:04:36.486226) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 05:04:36.486541) ========= 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=20e666a3d4cfbb71505a330e000001b4-1487335476.630387-983466232 XPCOM_DEBUG_BREAK=warn _=/tools/buildbot/bin/python using PTY: False program finished with exit code 0 elapsedTime=0.004528 ========= master_lag: 0.08 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-02-17 05:04:36.572174) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-02-17 05:04:36.572707) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-02-17 05:04:36.573249) ========= ========= Total master_lag: 0.22 =========