builder: graphics_yosemite_r7_test-mochitest-e10s-4 slave: t-yosemite-r7-0281 starttime: 1497406538.93 results: failure (2) revision: 4f1538523ab8b04ab21af64c01cb3cd12bd689cb ========= Started set props: master (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:38.932555) ========= master: http://buildbot-master135.bb.releng.scl3.mozilla.com:8201/ ========= Finished set props: master (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:38.932969) ========= ========= Started downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:38.933238) ========= ========= Finished downloading to buildprops.json (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:38.968243) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:38.968822) ========= 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: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.Us01N6b4Wi/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners TMPDIR=/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False --2017-06-13 19:15:38-- https://hg.mozilla.org/build/tools/raw-file/default/buildfarm/utils/archiver_client.py Resolving hg.mozilla.org... 63.245.215.25, 63.245.215.102 Connecting to 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% 197M=0s 2017-06-13 19:15:39 (197 MB/s) - 'archiver_client.py' saved [12179/12179] program finished with exit code 0 elapsedTime=0.177867 ========= master_lag: 0.02 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:39.170098) ========= ========= Started 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:39.170419) ========= rm -rf scripts properties in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-rf', 'scripts', 'properties'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.Us01N6b4Wi/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners TMPDIR=/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False program finished with exit code 0 elapsedTime=0.021642 ========= master_lag: 0.03 ========= ========= Finished 'rm -rf ...' (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:39.218105) ========= ========= Started 'bash -c ...' (results: 0, elapsed: 2 secs) (at 2017-06-13 19:15:39.218429) ========= bash -c 'python archiver_client.py mozharness --repo projects/graphics --rev 4f1538523ab8b04ab21af64c01cb3cd12bd689cb --destination scripts --debug' in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['bash', '-c', 'python archiver_client.py mozharness --repo projects/graphics --rev 4f1538523ab8b04ab21af64c01cb3cd12bd689cb --destination scripts --debug'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.Us01N6b4Wi/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners TMPDIR=/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False 2017-06-13 19:15:39,300 truncating revision to first 12 chars 2017-06-13 19:15:39,300 Setting DEBUG logging. 2017-06-13 19:15:39,300 attempt 1/10 2017-06-13 19:15:39,300 Getting archive location from https://api.pub.build.mozilla.org/archiver/hgmo/projects/graphics/4f1538523ab8?&preferred_region=us-west-2&suffix=tar.gz&subdir=testing/mozharness 2017-06-13 19:15:41,119 unpacking tar archive at: graphics-4f1538523ab8/testing/mozharness/ program finished with exit code 0 elapsedTime=2.077458 ========= master_lag: 0.21 ========= ========= Finished 'bash -c ...' (results: 0, elapsed: 2 secs) (at 2017-06-13 19:15:41.505834) ========= ========= Started set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:41.506121) ========= script_repo_revision: 4f1538523ab8b04ab21af64c01cb3cd12bd689cb ========= Finished set props: script_repo_revision (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:41.506453) ========= ========= Started downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:41.506728) ========= ========= Finished downloading to oauth.txt (results: 0, elapsed: 0 secs) (at 2017-06-13 19:15:41.554419) ========= ========= Started '/tools/buildbot/bin/python -u ...' failed (results: 2, elapsed: 1 hrs, 39 mins, 52 secs) (at 2017-06-13 19:15:41.554711) ========= /tools/buildbot/bin/python -u scripts/scripts/desktop_unittest.py --cfg unittests/mac_unittest.py --mochitest-suite plain-chunked --e10s --total-chunks 5 --this-chunk 4 --blob-upload-branch graphics --download-symbols ondemand in dir /builds/slave/test/. (timeout 1800 secs) (maxTime 7200 secs) watching logfiles {} argv: ['/tools/buildbot/bin/python', '-u', 'scripts/scripts/desktop_unittest.py', '--cfg', 'unittests/mac_unittest.py', '--mochitest-suite', 'plain-chunked', '--e10s', '--total-chunks', '5', '--this-chunk', '4', '--blob-upload-branch', 'graphics', '--download-symbols', 'ondemand'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.Us01N6b4Wi/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld MOZ_HIDE_RESULTS_TABLE=1 MOZ_NODE_PATH=/usr/local/bin/node MOZ_NO_REMOTE=1 NO_EM_RESTART=1 NO_FAIL_ON_TEST_ERRORS=1 PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PROPERTIES_FILE=/builds/slave/test/buildprops.json PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners TMPDIR=/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPCOM_DEBUG_BREAK=warn XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False 19:15:41 INFO - MultiFileLogger online at 20170613 19:15:41 in /builds/slave/test 19:15:41 INFO - Run as scripts/scripts/desktop_unittest.py --cfg unittests/mac_unittest.py --mochitest-suite plain-chunked --e10s --total-chunks 5 --this-chunk 4 --blob-upload-branch graphics --download-symbols ondemand 19:15:41 INFO - Dumping config to /builds/slave/test/logs/localconfig.json. 19:15:41 INFO - {'all_cppunittest_suites': {'cppunittest': ('tests/cppunittest',)}, 19:15:41 INFO - 'all_gtest_suites': {'gtest': ()}, 19:15:41 INFO - 'all_jittest_suites': {'jittest': ()}, 19:15:41 INFO - 'all_mochitest_suites': {'a11y': ('--flavor=a11y',), 19:15:41 INFO - 'browser-chrome': ('--flavor=browser',), 19:15:41 INFO - 'browser-chrome-addons': ('--flavor=browser', 19:15:41 INFO - '--chunk-by-runtime', 19:15:41 INFO - '--tag=addons'), 19:15:41 INFO - 'browser-chrome-chunked': ('--flavor=browser', 19:15:41 INFO - '--chunk-by-runtime'), 19:15:41 INFO - 'browser-chrome-clipboard': ('--flavor=browser', 19:15:41 INFO - '--subsuite=clipboard'), 19:15:41 INFO - 'browser-chrome-gpu': ('--flavor=browser', 19:15:41 INFO - '--subsuite=gpu'), 19:15:41 INFO - 'browser-chrome-screenshots': ('--flavor=browser', 19:15:41 INFO - '--subsuite=screenshots'), 19:15:41 INFO - 'chrome': ('--flavor=chrome',), 19:15:41 INFO - 'chrome-chunked': ('--flavor=chrome', 19:15:41 INFO - '--chunk-by-dir=4'), 19:15:41 INFO - 'chrome-clipboard': ('--flavor=chrome', 19:15:41 INFO - '--subsuite=clipboard'), 19:15:41 INFO - 'chrome-gpu': ('--flavor=chrome', '--subsuite=gpu'), 19:15:41 INFO - 'jetpack-addon': ('--flavor=jetpack-addon',), 19:15:41 INFO - 'jetpack-package': ('--flavor=jetpack-package',), 19:15:41 INFO - 'jetpack-package-clipboard': ('--flavor=jetpack-package', 19:15:41 INFO - '--subsuite=clipboard'), 19:15:41 INFO - 'mochitest-devtools-chrome': ('--flavor=browser', 19:15:41 INFO - '--subsuite=devtools'), 19:15:41 INFO - 'mochitest-devtools-chrome-chunked': ('--flavor=browser', 19:15:41 INFO - '--subsuite=devtools', 19:15:41 INFO - '--chunk-by-runtime'), 19:15:41 INFO - 'mochitest-gl': ('--subsuite=webgl',), 19:15:41 INFO - 'mochitest-media': ('--subsuite=media',), 19:15:41 INFO - 'plain': (), 19:15:41 INFO - 'plain-chunked': ('--chunk-by-dir=4',), 19:15:41 INFO - 'plain-clipboard': ('--subsuite=clipboard',), 19:15:41 INFO - 'plain-gpu': ('--subsuite=gpu',)}, 19:15:41 INFO - 'all_mozbase_suites': {'mozbase': ()}, 19:15:41 INFO - 'all_reftest_suites': {'crashtest': {'options': ('--suite=crashtest',), 19:15:41 INFO - 'tests': ('tests/reftest/tests/testing/crashtest/crashtests.list',)}, 19:15:41 INFO - 'jsreftest': {'options': ('--extra-profile-file=tests/jsreftest/tests/user.js',), 19:15:41 INFO - 'tests': ('tests/jsreftest/tests/jstests.list',)}, 19:15:41 INFO - 'reftest': {'options': ('--suite=reftest',), 19:15:41 INFO - 'tests': ('tests/reftest/tests/layout/reftests/reftest.list',)}}, 19:15:41 INFO - 'all_xpcshell_suites': {'xpcshell': {'options': ('--xpcshell=%(abs_app_dir)s/xpcshell', 19:15:41 INFO - '--manifest=tests/xpcshell/tests/xpcshell.ini'), 19:15:41 INFO - 'tests': ()}, 19:15:41 INFO - 'xpcshell-addons': {'options': ('--xpcshell=%(abs_app_dir)s/xpcshell', 19:15:41 INFO - '--tag=addons', 19:15:41 INFO - '--manifest=tests/xpcshell/tests/xpcshell.ini'), 19:15:41 INFO - 'tests': ()}}, 19:15:41 INFO - 'allow_software_gl_layers': False, 19:15:41 INFO - 'append_to_log': False, 19:15:41 INFO - 'base_work_dir': '/builds/slave/test', 19:15:41 INFO - 'blob_upload_branch': 'graphics', 19:15:41 INFO - 'blob_uploader_auth_file': '/builds/slave/test/oauth.txt', 19:15:41 INFO - 'buildbot_json_path': 'buildprops.json', 19:15:41 INFO - 'buildbot_max_log_size': 52428800, 19:15:41 INFO - 'code_coverage': False, 19:15:41 INFO - 'config_files': ('unittests/mac_unittest.py',), 19:15:41 INFO - 'default_blob_upload_servers': ('https://blobupload.elasticbeanstalk.com',), 19:15:41 INFO - 'disable_ccov_upload': False, 19:15:41 INFO - 'download_minidump_stackwalk': True, 19:15:41 INFO - 'download_nodejs': True, 19:15:41 INFO - 'download_symbols': 'ondemand', 19:15:41 INFO - 'e10s': True, 19:15:41 INFO - 'enable_webrender': False, 19:15:41 INFO - 'exe_suffix': '', 19:15:41 INFO - 'exes': {'python': '/tools/buildbot/bin/python', 19:15:41 INFO - 'tooltool.py': '/tools/tooltool.py', 19:15:41 INFO - 'virtualenv': ('/tools/buildbot/bin/python', 19:15:41 INFO - '/tools/misc-python/virtualenv.py')}, 19:15:41 INFO - 'find_links': ('http://pypi.pvt.build.mozilla.org/pub', 19:15:41 INFO - 'http://pypi.pub.build.mozilla.org/pub'), 19:15:41 INFO - 'installer_path': '/builds/slave/test/installer.dmg', 19:15:41 INFO - 'log_level': 'info', 19:15:41 INFO - 'log_to_console': True, 19:15:41 INFO - 'minidump_save_path': '%(abs_work_dir)s/../minidumps', 19:15:41 INFO - 'minidump_stackwalk_path': 'macosx64-minidump_stackwalk', 19:15:41 INFO - 'minidump_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/releng.manifest', 19:15:41 INFO - 'minimum_tests_zip_dirs': ('bin/*', 19:15:41 INFO - 'certs/*', 19:15:41 INFO - 'config/*', 19:15:41 INFO - 'mach', 19:15:41 INFO - 'marionette/*', 19:15:41 INFO - 'modules/*', 19:15:41 INFO - 'mozbase/*', 19:15:41 INFO - 'tools/*'), 19:15:41 INFO - 'no_random': False, 19:15:41 INFO - 'nodejs_path': 'node-osx/bin/node', 19:15:41 INFO - 'nodejs_tooltool_manifest_path': 'config/tooltool-manifests/macosx64/nodejs.manifest', 19:15:41 INFO - 'opt_config_files': (), 19:15:41 INFO - 'parallel_stylo_traversal': False, 19:15:41 INFO - 'pip_index': False, 19:15:41 INFO - 'preflight_run_cmd_suites': ({'architectures': ('32bit', '64bit'), 19:15:41 INFO - 'cmd': ('xset', 's', 'off', 's', 'reset'), 19:15:41 INFO - 'enabled': False, 19:15:41 INFO - 'halt_on_failure': False, 19:15:41 INFO - 'name': 'disable_screen_saver'}, 19:15:41 INFO - {'architectures': ('32bit',), 19:15:41 INFO - 'cmd': ('python', 19:15:41 INFO - '../scripts/external_tools/mouse_and_screen_resolution.py', 19:15:41 INFO - '--configuration-file', 19:15:41 INFO - '../scripts/external_tools/machine-configuration.json'), 19:15:41 INFO - 'enabled': False, 19:15:41 INFO - 'halt_on_failure': True, 19:15:41 INFO - 'name': 'run mouse & screen adjustment script'}), 19:15:41 INFO - 'require_test_zip': True, 19:15:41 INFO - 'run_all_suites': False, 19:15:41 INFO - 'run_cmd_checks_enabled': True, 19:15:41 INFO - 'run_file_names': {'cppunittest': 'runcppunittests.py', 19:15:41 INFO - 'gtest': 'rungtests.py', 19:15:41 INFO - 'jittest': 'jit_test.py', 19:15:41 INFO - 'mochitest': 'runtests.py', 19:15:41 INFO - 'mozbase': 'test.py', 19:15:41 INFO - 'mozmill': 'runtestlist.py', 19:15:41 INFO - 'reftest': 'runreftest.py', 19:15:41 INFO - 'xpcshell': 'runxpcshelltests.py'}, 19:15:41 INFO - 'specific_tests_zip_dirs': {'cppunittest': ('cppunittest/*',), 19:15:41 INFO - 'gtest': ('gtest/*',), 19:15:41 INFO - 'jittest': ('jit-test/*',), 19:15:41 INFO - 'mochitest': ('mochitest/*',), 19:15:41 INFO - 'mozbase': ('mozbase/*',), 19:15:41 INFO - 'mozmill': ('mozmill/*',), 19:15:41 INFO - 'reftest': ('reftest/*', 'jsreftest/*'), 19:15:41 INFO - 'xpcshell': ('xpcshell/*',)}, 19:15:41 INFO - 'specified_mochitest_suites': ('plain-chunked',), 19:15:41 INFO - 'strict_content_sandbox': False, 19:15:41 INFO - 'suite_definitions': {'cppunittest': {'options': ('--symbols-path=%(symbols_path)s', 19:15:41 INFO - '--xre-path=%(abs_res_dir)s'), 19:15:41 INFO - 'run_filename': 'runcppunittests.py', 19:15:41 INFO - 'testsdir': 'cppunittest'}, 19:15:41 INFO - 'gtest': {'options': ('--xre-path=%(abs_res_dir)s', 19:15:41 INFO - '--cwd=%(gtest_dir)s', 19:15:41 INFO - '--symbols-path=%(symbols_path)s', 19:15:41 INFO - '--utility-path=tests/bin', 19:15:41 INFO - '%(binary_path)s'), 19:15:41 INFO - 'run_filename': 'rungtests.py'}, 19:15:41 INFO - 'jittest': {'options': ('tests/bin/js', 19:15:41 INFO - '--no-slow', 19:15:41 INFO - '--no-progress', 19:15:41 INFO - '--format=automation', 19:15:41 INFO - '--jitflags=all', 19:15:41 INFO - '--timeout=970'), 19:15:41 INFO - 'run_filename': 'jit_test.py', 19:15:41 INFO - 'run_timeout': 1000, 19:15:41 INFO - 'testsdir': 'jit-test/jit-test'}, 19:15:41 INFO - 'mochitest': {'options': ('--appname=%(binary_path)s', 19:15:41 INFO - '--utility-path=tests/bin', 19:15:41 INFO - '--extra-profile-file=tests/bin/plugins', 19:15:41 INFO - '--symbols-path=%(symbols_path)s', 19:15:41 INFO - '--certificate-path=tests/certs', 19:15:41 INFO - '--quiet', 19:15:41 INFO - '--log-raw=%(raw_log_file)s', 19:15:41 INFO - '--log-errorsummary=%(error_summary_file)s', 19:15:41 INFO - '--screenshot-on-fail', 19:15:41 INFO - '--cleanup-crashes'), 19:15:41 INFO - 'run_filename': 'runtests.py', 19:15:41 INFO - 'testsdir': 'mochitest'}, 19:15:41 INFO - 'mozbase': {'options': ('-b', '%(binary_path)s'), 19:15:41 INFO - 'run_filename': 'test.py', 19:15:41 INFO - 'testsdir': 'mozbase'}, 19:15:41 INFO - 'mozmill': {'options': ('--binary=%(binary_path)s', 19:15:41 INFO - '--testing-modules-dir=test/modules', 19:15:41 INFO - '--plugins-path=%(test_plugin_path)s', 19:15:41 INFO - '--symbols-path=%(symbols_path)s'), 19:15:41 INFO - 'run_filename': 'runtestlist.py', 19:15:41 INFO - 'testsdir': 'mozmill'}, 19:15:41 INFO - 'reftest': {'options': ('--appname=%(binary_path)s', 19:15:41 INFO - '--utility-path=tests/bin', 19:15:41 INFO - '--extra-profile-file=tests/bin/plugins', 19:15:41 INFO - '--symbols-path=%(symbols_path)s', 19:15:41 INFO - '--log-raw=%(raw_log_file)s', 19:15:41 INFO - '--log-errorsummary=%(error_summary_file)s', 19:15:41 INFO - '--cleanup-crashes'), 19:15:41 INFO - 'run_filename': 'runreftest.py', 19:15:41 INFO - 'testsdir': 'reftest'}, 19:15:41 INFO - 'xpcshell': {'options': ('--symbols-path=%(symbols_path)s', 19:15:41 INFO - '--test-plugin-path=%(test_plugin_path)s', 19:15:41 INFO - '--log-raw=%(raw_log_file)s', 19:15:41 INFO - '--log-errorsummary=%(error_summary_file)s', 19:15:41 INFO - '--utility-path=tests/bin'), 19:15:41 INFO - 'run_filename': 'runxpcshelltests.py', 19:15:41 INFO - 'testsdir': 'xpcshell'}}, 19:15:41 INFO - 'this_chunk': '4', 19:15:41 INFO - 'tooltool_cache': '/builds/tooltool_cache', 19:15:41 INFO - 'total_chunks': '5', 19:15:41 INFO - 'unstructured_flavors': {'cppunittest': (), 19:15:41 INFO - 'gtest': (), 19:15:41 INFO - 'jittest': (), 19:15:41 INFO - 'mochitest': ('jetpack',), 19:15:41 INFO - 'mozbase': (), 19:15:41 INFO - 'mozmill': (), 19:15:41 INFO - 'xpcshell': ()}, 19:15:41 INFO - 'vcs_output_timeout': 1000, 19:15:41 INFO - 'virtualenv_path': 'venv', 19:15:41 INFO - 'volatile_config': {'actions': None, 'add_actions': None, 'no_actions': None}, 19:15:41 INFO - 'work_dir': 'build', 19:15:41 INFO - 'xpcshell_name': 'xpcshell'} 19:15:41 INFO - [mozharness: 2017-06-14 02:15:41.789612Z] Running clobber step. 19:15:41 INFO - Running pre-action listener: _resource_record_pre_action 19:15:41 INFO - Running main action method: clobber 19:15:41 INFO - rmtree: /builds/slave/test/build 19:15:41 INFO - retry: Calling rmtree with args: ('/builds/slave/test/build',), kwargs: {}, attempt #1 19:15:43 INFO - Running post-action listener: _resource_record_post_action 19:15:43 INFO - [mozharness: 2017-06-14 02:15:43.976711Z] Finished clobber step (success) 19:15:43 INFO - [mozharness: 2017-06-14 02:15:43.976864Z] Running read-buildbot-config step. 19:15:43 INFO - Running pre-action listener: _resource_record_pre_action 19:15:43 INFO - Running main action method: read_buildbot_config 19:15:43 INFO - Using buildbot properties: 19:15:43 INFO - { 19:15:43 INFO - "project": "", 19:15:43 INFO - "product": "firefox", 19:15:43 INFO - "who": "mwoodrow@mozilla.com", 19:15:43 INFO - "installer_path": "public/build/firefox-55.0a1.en-US.mac.dmg", 19:15:43 INFO - "taskId": "ICPNop8YSWW7nxPC2VrFeg", 19:15:43 INFO - "repository": "https://hg.mozilla.org/projects/graphics/", 19:15:43 INFO - "buildername": "Rev7 MacOSX Yosemite 10.10.5 graphics opt test mochitest-e10s-4", 19:15:43 INFO - "stage_platform": "macosx64", 19:15:43 INFO - "basedir": "/builds/slave/test", 19:15:43 INFO - "buildnumber": 0, 19:15:43 INFO - "platform": "macosx64", 19:15:43 INFO - "parent_task_id": "S9Ns3CFNSWyKVBvfR9ry8g", 19:15:43 INFO - "master": "http://buildbot-master135.bb.releng.scl3.mozilla.com:8201/", 19:15:43 INFO - "slavebuilddir": "test", 19:15:43 INFO - "branch": "graphics", 19:15:43 INFO - "script_repo_revision": "default", 19:15:43 INFO - "revision": "4f1538523ab8b04ab21af64c01cb3cd12bd689cb", 19:15:43 INFO - "moz_repo_path": "", 19:15:43 INFO - "slavename": "t-yosemite-r7-0281", 19:15:43 INFO - "repo_path": "projects/graphics" 19:15:43 INFO - } 19:15:43 INFO - Finding installer, test and symbols from parent task. 19:15:43 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/ICPNop8YSWW7nxPC2VrFeg'}, attempt #1 19:15:44 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/ICPNop8YSWW7nxPC2VrFeg'}, attempt #1 19:15:45 INFO - Task dependencies: cMC0o9fQSkiRNsjf-RCE8g S9Ns3CFNSWyKVBvfR9ry8g 19:15:45 INFO - retry: Calling _urlopen with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g'}, attempt #1 19:15:45 INFO - Set installer_url: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg 19:15:45 INFO - Set test_url: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/test_packages.json 19:15:45 INFO - Set symbols_url: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 19:15:45 INFO - Running post-action listener: _resource_record_post_action 19:15:45 INFO - [mozharness: 2017-06-14 02:15:45.768972Z] Finished read-buildbot-config step (success) 19:15:45 INFO - [mozharness: 2017-06-14 02:15:45.769107Z] Running download-and-extract step. 19:15:45 INFO - Running pre-action listener: _pre_download_and_extract 19:15:45 WARNING - Try message not found. 19:15:45 INFO - Running pre-action listener: _resource_record_pre_action 19:15:45 INFO - Running main action method: download_and_extract 19:15:45 INFO - mkdir: /builds/slave/test/build/tests 19:15:45 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 19:15:45 INFO - trying https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.test_packages.json 19:15:45 INFO - Downloading https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.test_packages.json to /builds/slave/test/build/firefox-55.0a1.en-US.mac.test_packages.json 19:15:45 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.test_packages.json', 'file_name': '/builds/slave/test/build/firefox-55.0a1.en-US.mac.test_packages.json'}, attempt #1 19:15:46 INFO - Downloaded 1328 bytes. 19:15:46 INFO - Reading from file /builds/slave/test/build/firefox-55.0a1.en-US.mac.test_packages.json 19:15:46 INFO - Using the following test package requirements: 19:15:46 INFO - {u'awsy': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.awsy.tests.zip'], 19:15:46 INFO - u'common': [u'firefox-55.0a1.en-US.mac.common.tests.zip'], 19:15:46 INFO - u'cppunittest': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.cppunittest.tests.zip'], 19:15:46 INFO - u'gtest': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.gtest.tests.zip'], 19:15:46 INFO - u'jittest': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'jsshell-mac.zip'], 19:15:46 INFO - u'mochitest': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.mochitest.tests.zip'], 19:15:46 INFO - u'mozbase': [u'firefox-55.0a1.en-US.mac.common.tests.zip'], 19:15:46 INFO - u'reftest': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.reftest.tests.zip'], 19:15:46 INFO - u'talos': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.talos.tests.zip'], 19:15:46 INFO - u'web-platform': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.web-platform.tests.tar.gz'], 19:15:46 INFO - u'xpcshell': [u'firefox-55.0a1.en-US.mac.common.tests.zip', 19:15:46 INFO - u'firefox-55.0a1.en-US.mac.xpcshell.tests.zip']} 19:15:46 INFO - Downloading packages: [u'firefox-55.0a1.en-US.mac.common.tests.zip', u'firefox-55.0a1.en-US.mac.mochitest.tests.zip'] for test suite category: mochitest 19:15:46 INFO - Adding 'mozinfo.json' for extraction from common.tests zip file 19:15:46 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs bin/*, certs/*, config/*, mach, marionette/*, modules/*, mozbase/*, tools/*, mochitest/*, mozinfo.json from https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.common.tests.zip 19:15:46 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.common.tests.zip'}, attempt #1 19:15:46 INFO - Fetch https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.common.tests.zip into memory 19:15:48 INFO - Content-Length response header: 57642491 19:15:48 INFO - Bytes received: 57642491 19:15:49 INFO - Downloading and extracting to /builds/slave/test/build/tests these dirs bin/*, certs/*, config/*, mach, marionette/*, modules/*, mozbase/*, tools/*, mochitest/*, mozinfo.json from https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.mochitest.tests.zip 19:15:49 INFO - retry: Calling fetch_url_into_memory with args: (), kwargs: {'url': u'https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.mochitest.tests.zip'}, attempt #1 19:15:49 INFO - Fetch https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.mochitest.tests.zip into memory 19:15:51 INFO - Content-Length response header: 67570180 19:15:51 INFO - Bytes received: 67570180 19:16:03 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 19:16:03 INFO - trying https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg 19:16:03 INFO - Downloading https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg to /builds/slave/test/installer.dmg 19:16:03 INFO - retry: Calling _download_file with args: (), kwargs: {'url': 'https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg', 'file_name': '/builds/slave/test/installer.dmg'}, attempt #1 19:16:05 INFO - Downloaded 68133847 bytes. 19:16:05 INFO - Setting buildbot property build_url to https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg 19:16:05 INFO - mkdir: /builds/slave/test/properties 19:16:05 INFO - Writing buildbot properties ['build_url'] to /builds/slave/test/properties/build_url 19:16:05 INFO - Writing to file /builds/slave/test/properties/build_url 19:16:05 INFO - Contents: 19:16:05 INFO - build_url:https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg 19:16:05 INFO - Running post-action listener: _resource_record_post_action 19:16:05 INFO - Running post-action listener: set_extra_try_arguments 19:16:05 INFO - [mozharness: 2017-06-14 02:16:05.193414Z] Finished download-and-extract step (success) 19:16:05 INFO - [mozharness: 2017-06-14 02:16:05.193574Z] Running create-virtualenv step. 19:16:05 INFO - Running pre-action listener: _install_mozbase 19:16:05 INFO - Running pre-action listener: _pre_create_virtualenv 19:16:05 INFO - Running pre-action listener: _resource_record_pre_action 19:16:05 INFO - Running main action method: create_virtualenv 19:16:05 INFO - Creating virtualenv /builds/slave/test/build/venv 19:16: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 19:16:05 INFO - Copy/paste: /tools/buildbot/bin/python /tools/misc-python/virtualenv.py --no-site-packages --distribute /builds/slave/test/build/venv 19:16:05 INFO - Using partial env: {'VIRTUALENV_NO_DOWNLOAD': '1'} 19:16:05 INFO - The --no-site-packages flag is deprecated; it is now the default behavior. 19:16:05 INFO - Using real prefix '/tools/python27' 19:16:05 INFO - New python executable in /builds/slave/test/build/venv/bin/python 19:16:06 INFO - Installing distribute.............................................................................................................................................................................................done. 19:16:08 INFO - Installing pip.................done. 19:16:08 INFO - Return code: 0 19:16:08 INFO - Getting output from command: ['/builds/slave/test/build/venv/bin/pip', '--version'] 19:16:08 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip --version 19:16:09 INFO - Reading from file tmpfile_stdout 19:16:09 INFO - Output received: 19:16:09 INFO - pip 1.5.5 from /builds/slave/test/build/venv/lib/python2.7/site-packages/pip-1.5.5-py2.7.egg (python 2.7) 19:16:09 INFO - Installing psutil>=3.1.1 into virtualenv /builds/slave/test/build/venv 19:16:09 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 19:16:09 INFO - http://pypi.pvt.build.mozilla.org/pub matches http://pypi.pvt.build.mozilla.org 19:16:09 INFO - proxxy config: {'regions': ['.use1.', '.usw2.'], 'instances': ['proxxy1.srv.releng.use1.mozilla.com', 'proxxy1.srv.releng.usw2.mozilla.com'], 'urls': [('http://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp.mozilla.org', 'ftp.mozilla.org'), ('https://ftp-ssl.mozilla.org', 'ftp.mozilla.org'), ('http://pypi.pvt.build.mozilla.org', 'pypi.pvt.build.mozilla.org'), ('http://pypi.pub.build.mozilla.org', 'pypi.pub.build.mozilla.org')]} 19:16:09 INFO - http://pypi.pub.build.mozilla.org/pub matches http://pypi.pub.build.mozilla.org 19:16: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/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 0x10e815030>, 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e8b7960>, 'level': 'warning'}, {'regex': <_sre.SRE_Pattern object at 0x7fb13947a440>, 'level': 'debug'}, {'substr': 'command not found', 'level': 'error'}, {'regex': <_sre.SRE_Pattern object at 0x10e7a71d0>, '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 0x10e783108>, 'level': 'critical'}, {'regex': <_sre.SRE_Pattern object at 0x10e79d030>, 'level': 'critical'}], 'cwd': '/builds/slave/test/build', 'env': {'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 'LOGNAME': 'cltbld', 'USER': 'cltbld', 'XPC_SERVICE_NAME': '0', 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 'HOME': '/Users/cltbld', 'NO_EM_RESTART': '1', 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 'XPCOM_DEBUG_BREAK': 'warn', 'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.Us01N6b4Wi/Render', 'MOZ_NODE_PATH': '/usr/local/bin/node', 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 'VERSIONER_PYTHON_VERSION': '2.7', 'XPC_FLAGS': '0x0', 'NO_FAIL_ON_TEST_ERRORS': '1', 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 'MOZ_NO_REMOTE': '1', 'MOZ_HIDE_RESULTS_TABLE': '1', 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners', 'SHELL': '/bin/bash', 'TMPDIR': '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/', '__CF_USER_TEXT_ENCODING': '0x1C:0:0', 'PWD': '/builds/slave/test', 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json'}}, attempt #1 19:16:09 INFO - Running command: ['/builds/slave/test/build/venv/bin/pip', 'install', '--timeout', '120', '--no-index', '--find-links', 'http://pypi.pvt.build.mozilla.org/pub', '--find-links', 'http://pypi.pub.build.mozilla.org/pub', 'psutil>=3.1.1'] in /builds/slave/test/build 19:16:09 INFO - Copy/paste: /builds/slave/test/build/venv/bin/pip install --timeout 120 --no-index --find-links http://pypi.pvt.build.mozilla.org/pub --find-links http://pypi.pub.build.mozilla.org/pub psutil>=3.1.1 19:16:09 INFO - Using env: {'Apple_PubSub_Socket_Render': '/private/tmp/com.apple.launchd.Us01N6b4Wi/Render', 19:16:09 INFO - 'GIT_SHARE_BASE_DIR': '/builds/git-shared', 19:16:09 INFO - 'HG_SHARE_BASE_DIR': '/builds/hg-shared', 19:16:09 INFO - 'HOME': '/Users/cltbld', 19:16:09 INFO - 'IDLEIZER_DISABLE_SHUTDOWN': 'true', 19:16:09 INFO - 'LOGNAME': 'cltbld', 19:16:09 INFO - 'MOZ_HIDE_RESULTS_TABLE': '1', 19:16:09 INFO - 'MOZ_NODE_PATH': '/usr/local/bin/node', 19:16:09 INFO - 'MOZ_NO_REMOTE': '1', 19:16:09 INFO - 'NO_EM_RESTART': '1', 19:16:09 INFO - 'NO_FAIL_ON_TEST_ERRORS': '1', 19:16:09 INFO - 'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11', 19:16:09 INFO - 'PROPERTIES_FILE': '/builds/slave/test/buildprops.json', 19:16:09 INFO - 'PWD': '/builds/slave/test', 19:16:09 INFO - 'RUNNER_CONFIG_CMD': '/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg', 19:16:09 INFO - 'SHELL': '/bin/bash', 19:16:09 INFO - 'SSH_AUTH_SOCK': '/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners', 19:16:09 INFO - 'TMPDIR': '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/', 19:16:09 INFO - 'TWISTD_LOG_PATH': '/builds/slave/twistd.log', 19:16:09 INFO - 'USER': 'cltbld', 19:16:09 INFO - 'VERSIONER_PYTHON_PREFER_32_BIT': 'no', 19:16:09 INFO - 'VERSIONER_PYTHON_VERSION': '2.7', 19:16:09 INFO - 'XPCOM_DEBUG_BREAK': 'warn', 19:16:09 INFO - 'XPC_FLAGS': '0x0', 19:16:09 INFO - 'XPC_SERVICE_NAME': '0', 19:16:09 INFO - '__CF_USER_TEXT_ENCODING': '0x1C:0:0'} 19:16:09 INFO - Ignoring indexes: https://pypi.python.org/simple/ 19:16:09 INFO - Downloading/unpacking psutil>=3.1.1 19:16: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 19:16: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 19:16: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 19:16: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 19:16:11 INFO - Running setup.py (path:/builds/slave/test/build/venv/build/psutil/setup.py) egg_info for package psutil 19:16:11 INFO - warning: no previously-included files matching '*' found under directory 'docs/_build' 19:16:11 INFO - warning: manifest_maker: MANIFEST.in, line 18: 'recursive-include' expects
xyz
A
xyz
A
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from immediately after the last character:
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from immediately after the last character:
should have 5 children after pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from immediately after the last character: 'c' should be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from immediately after the last character: 1st empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from immediately after the last character: 2nd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from immediately after the last character: 3rd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Failed to initialize the editor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 1st text node should be emptyTextNode1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 2nd text node should be emptyTextNode2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 3rd text node should be emptyTextNode3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 1th empty text node:
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 1th empty text node:
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 1th empty text node:
should have 5 children after pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 1th empty text node: 'c' should be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 1th empty text node: 1st empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 1th empty text node: 2nd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 1th empty text node: 3rd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Failed to initialize the editor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 1st text node should be emptyTextNode1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 2nd text node should be emptyTextNode2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 3rd text node should be emptyTextNode3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 2th empty text node:
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 2th empty text node:
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 2th empty text node:
should have 5 children after pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 2th empty text node: 'c' should be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 2th empty text node: 1st empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 2th empty text node: 2nd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 2th empty text node: 3rd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Failed to initialize the editor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 1st text node should be emptyTextNode1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 2nd text node should be emptyTextNode2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 3rd text node should be emptyTextNode3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 3th empty text node:
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 3th empty text node:
element shouldn't be removed by Backspace key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 3th empty text node:
should have 5 children after pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 3th empty text node: 'c' should be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 3th empty text node: 1st empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 3th empty text node: 2nd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Backspace from 3th empty text node: 3rd empty text node should not be removed by pressing Backspace key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Failed to initialize the editor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 1st text node should be emptyTextNode3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 2nd text node should be emptyTextNode2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 3rd text node should be emptyTextNode1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from immediately before the first character:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from immediately before the first character:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from immediately before the first character:
should have only 2 children after pressing Delete key (empty text nodes should be removed 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from immediately before the first character: 1st empty text node should not be removed by pressing Delete key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from immediately before the first character: 2nd empty text node should not be removed by pressing Delete key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from immediately before the first character: 3rd empty text node should not be removed by pressing Delete key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from immediately before the first character: 'a' should be removed by pressing Delete key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Failed to initialize the editor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 1st text node should be emptyTextNode3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 2nd text node should be emptyTextNode2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 3rd text node should be emptyTextNode1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 1th empty text node:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 1th empty text node:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 1th empty text node:
should have only 1 children after pressing Delete key (1 empty text nodes should be removed 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 1th empty text node: empty text nodes and 'a' should be removed by pressing Delete key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Failed to initialize the editor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 1st text node should be emptyTextNode3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 2nd text node should be emptyTextNode2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 3rd text node should be emptyTextNode1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 2th empty text node:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 2th empty text node:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 2th empty text node:
should have only 2 children after pressing Delete key (2 empty text nodes should be removed 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 2th empty text node: empty text nodes and 'a' should be removed by pressing Delete key 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Failed to initialize the editor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 1st text node should be emptyTextNode3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 2nd text node should be emptyTextNode2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | 3rd text node should be emptyTextNode1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 3th empty text node:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 3th empty text node:
element shouldn't be removed by Delete key press 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 3th empty text node:
should have only 3 children after pressing Delete key (3 empty text nodes should be removed 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1315065.html | Delete from 3th empty text node: empty text nodes and 'a' should be removed by pressing Delete key 20:06:58 INFO - GECKO(2351) | MEMORY STAT | vsize 4135MB | residentFast 154MB | heapAllocated 39MB 20:06:58 INFO - TEST-OK | editor/libeditor/tests/test_bug1315065.html | took 164ms 20:06:58 INFO - TEST-START | editor/libeditor/tests/test_bug1316302.html 20:06:58 INFO - must wait for load 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | range should be collapsed at the end of
20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | range should be collapsed in the20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | range should be collapsed at the end 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | Pressing Backspace key at the end ofshould remove the last character in the20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | range should be collapsed at the start of
20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | range should be collapsed in the20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | range should be collapsed at the start 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1316302.html | Pressing Delete key at the start ofshould remove the first character in the20:06:58 INFO - GECKO(2351) | MEMORY STAT | vsize 4137MB | residentFast 156MB | heapAllocated 39MB 20:06:58 INFO - TEST-OK | editor/libeditor/tests/test_bug1316302.html | took 80ms 20:06:58 INFO - TEST-START | editor/libeditor/tests/test_bug1318312.html 20:06:58 INFO - must wait for load 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should have focus 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should still have focus because focus shouldn't be moved by moving caret 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the innerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus offset of selection should be 0 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should still have focus because focus shouldn't be moved by typing a character 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the innerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus offset of selection should be 1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should still have focus because focus shouldn't be moved by typing Enter 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the second paragraph in the innerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus offset of selection should be 0 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should still have focus because focus shouldn't be moved by typing Backspace (removing the line breaker) 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the innerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus offset of selection should be 1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should still have focus because focus shouldn't be moved by typing Shift+ArrowLeft (selecting 'a') 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the innerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus offset of selection should be 0 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | anchor node of selection should be the text node in the innerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | anchor offset of selection should be 1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should still have focus because focus shouldn't be moved by typing Delete (removing the 'a') 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the innerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus offset of selection should be 0 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | outerEditor should still have focus because focus shouldn't be moved by moving caret from innerEditor to outerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the outerEditor 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus offset of selection should be 0 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | innerEditor should get focus because focus should be moved to innerEditor even from outerEditor by click 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1318312.html | focus node of selection should be the text node in the innerEditor 20:06:58 INFO - GECKO(2351) | MEMORY STAT | vsize 4138MB | residentFast 157MB | heapAllocated 40MB 20:06:58 INFO - TEST-OK | editor/libeditor/tests/test_bug1318312.html | took 98ms 20:06:58 INFO - TEST-START | editor/libeditor/tests/test_bug1328023.html 20:06:58 INFO - must wait for load 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | AB is input.value now 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | A is input.value now 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | AB is input.value now 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | ABC is input.value now 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | ABC is input.value now 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | '' is input.value now 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | ABC is input.value now 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1328023.html | ABCD is input.value now 20:06:58 INFO - GECKO(2351) | MEMORY STAT | vsize 4139MB | residentFast 159MB | heapAllocated 40MB 20:06:58 INFO - TEST-OK | editor/libeditor/tests/test_bug1328023.html | took 92ms 20:06:58 INFO - TEST-START | editor/libeditor/tests/test_bug1330796.html 20:06:58 INFO - must wait for load 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 0 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 1 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 2 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 3 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 4 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 5 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 6 20:06:58 INFO - TEST-PASS | editor/libeditor/tests/test_bug1330796.html | unexpected HTML for test 7 20:06:58 INFO - GECKO(2351) | MEMORY STAT | vsize 4140MB | residentFast 160MB | heapAllocated 41MB 20:06:58 INFO - TEST-OK | editor/libeditor/tests/test_bug1330796.html | took 103ms 20:06:58 INFO - TEST-START | editor/libeditor/tests/test_bug1332876.html 20:06:59 INFO - must wait for load 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1332876.html | did not crash 20:06:59 INFO - GECKO(2351) | MEMORY STAT | vsize 4145MB | residentFast 165MB | heapAllocated 41MB 20:06:59 INFO - TEST-OK | editor/libeditor/tests/test_bug1332876.html | took 126ms 20:06:59 INFO - TEST-START | editor/libeditor/tests/test_bug1352799.html 20:06:59 INFO - must wait for load 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1352799.html | value should be 12 with maxlength = 2 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1352799.html | value should be 4567 with maxlength = 4 20:06:59 INFO - TEST-FAIL | editor/libeditor/tests/test_bug1352799.html | value should be 45 with maxlength = 2 - got "4567", expected "45" 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1352799.html | value should be 12345678 without maxlength 20:06:59 INFO - GECKO(2351) | MEMORY STAT | vsize 4147MB | residentFast 166MB | heapAllocated 42MB 20:06:59 INFO - TEST-OK | editor/libeditor/tests/test_bug1352799.html | took 155ms 20:06:59 INFO - TEST-START | editor/libeditor/tests/test_bug1355792.html 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1355792.html | No creating an extra
20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1355792.html | Selection node should not change 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1355792.html | Selection offset should not move 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1355792.html | Selection should be collapsed 20:06:59 INFO - GECKO(2351) | MEMORY STAT | vsize 4147MB | residentFast 166MB | heapAllocated 42MB 20:06:59 INFO - TEST-OK | editor/libeditor/tests/test_bug1355792.html | took 80ms 20:06:59 INFO - TEST-START | editor/libeditor/tests/test_bug1358025.html 20:06:59 INFO - must wait for load 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled by same empty string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is ABC 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled by a string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is ABC 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled by same string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is DEF 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled by different string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled by empty string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is still enabled by same empty string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is ABC 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is disabled by a string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is ABC 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is still enabled by same string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is DEF 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is disabled by different string 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is enabled 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1358025.html | Undo is disabled by empty string 20:06:59 INFO - GECKO(2351) | MEMORY STAT | vsize 4148MB | residentFast 168MB | heapAllocated 43MB 20:06:59 INFO - TEST-OK | editor/libeditor/tests/test_bug1358025.html | took 122ms 20:06:59 INFO - TEST-START | editor/libeditor/tests/test_bug1368544.html 20:06:59 INFO - must wait for load 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | editor of textarea has child nodes 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | D is last character 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | editor of textarea has child nodes 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | editor of textarea has child node even if value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | editor of textarea has child node even if value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | editor of textarea has child node even if value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | editor of textarea has child node even if value is empty 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | value is AAA 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug1368544.html | editor of textarea has child node even if value is empty 20:06:59 INFO - GECKO(2351) | MEMORY STAT | vsize 4149MB | residentFast 169MB | heapAllocated 43MB 20:06:59 INFO - TEST-OK | editor/libeditor/tests/test_bug1368544.html | took 166ms 20:06:59 INFO - TEST-START | editor/libeditor/tests/test_bug200416.html 20:06:59 INFO - TEST-PASS | editor/libeditor/tests/test_bug200416.html | foo needs to still come before bar 20:06:59 INFO - GECKO(2351) | MEMORY STAT | vsize 4150MB | residentFast 170MB | heapAllocated 44MB 20:06:59 INFO - TEST-OK | editor/libeditor/tests/test_bug200416.html | took 79ms 20:06:59 INFO - TEST-START | editor/libeditor/tests/test_bug289384.html 20:07:00 INFO - must wait for focus 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug289384.html | The selection must be collapsed 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug289384.html | The anchor node should be the body element's text node 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug289384.html | The anchor offset should be 0 20:07:00 INFO - GECKO(2351) | MEMORY STAT | vsize 4165MB | residentFast 185MB | heapAllocated 46MB 20:07:00 INFO - TEST-OK | editor/libeditor/tests/test_bug289384.html | took 724ms 20:07:00 INFO - TEST-START | editor/libeditor/tests/test_bug290026.html 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug290026.html | a once indented bulleted list 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug290026.html | a twice indented bulleted list 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug290026.html | outdenting a twice indented bulleted list 20:07:00 INFO - GECKO(2351) | MEMORY STAT | vsize 4247MB | residentFast 191MB | heapAllocated 49MB 20:07:00 INFO - TEST-OK | editor/libeditor/tests/test_bug290026.html | took 122ms 20:07:00 INFO - TEST-START | editor/libeditor/tests/test_bug291780.html 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug291780.html | indenting part of an already indented bulleted list 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug291780.html | outdenting the partially indented part of an already indented bulleted list 20:07:00 INFO - GECKO(2351) | MEMORY STAT | vsize 4296MB | residentFast 192MB | heapAllocated 46MB 20:07:00 INFO - TEST-OK | editor/libeditor/tests/test_bug291780.html | took 95ms 20:07:00 INFO - TEST-START | editor/libeditor/tests/test_bug309731.html 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | Input node starts empty 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | execCommand should return true 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | empty inserthtml with empty selection shouldn't change contents 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | execCommand should return true 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | 'foo'inserthtml with empty selection should add foo to contents 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | execCommand should return true 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | 'bar' inserthtml with complete selection should replace contents with bar 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | execCommand should return true 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug309731.html | empty inserthtml with complete selection should delete everything 20:07:00 INFO - GECKO(2351) | MEMORY STAT | vsize 4312MB | residentFast 193MB | heapAllocated 46MB 20:07:00 INFO - TEST-OK | editor/libeditor/tests/test_bug309731.html | took 69ms 20:07:00 INFO - TEST-START | editor/libeditor/tests/test_bug316447.html 20:07:00 INFO - TEST-PASS | editor/libeditor/tests/test_bug316447.html | Wrong innerHTML 20:07:00 INFO - GECKO(2351) | MEMORY STAT | vsize 4312MB | residentFast 193MB | heapAllocated 47MB 20:07:00 INFO - TEST-OK | editor/libeditor/tests/test_bug316447.html | took 74ms 20:07:01 INFO - TEST-START | editor/libeditor/tests/test_bug318065.html 20:07:01 INFO - must wait for load 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug318065.html | Initial text inserted 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug318065.html | Initial text deleted 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug318065.html | Undo of deletion 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug318065.html | Redo of deletion 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug318065.html | Initial text typed 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug318065.html | Undo of typing 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug318065.html | Redo of typing 20:07:01 INFO - GECKO(2351) | MEMORY STAT | vsize 4312MB | residentFast 193MB | heapAllocated 47MB 20:07:01 INFO - TEST-OK | editor/libeditor/tests/test_bug318065.html | took 100ms 20:07:01 INFO - TEST-START | editor/libeditor/tests/test_bug332636.html 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug332636.html | The backspace key should delete the UTF-16 surrogate pair correctly 20:07:01 INFO - GECKO(2351) | MEMORY STAT | vsize 4310MB | residentFast 194MB | heapAllocated 49MB 20:07:01 INFO - TEST-OK | editor/libeditor/tests/test_bug332636.html | took 137ms 20:07:01 INFO - TEST-START | editor/libeditor/tests/test_bug366682.html 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug366682.html | Correct number of misspellings and words. 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug366682.html | Misspelling is what we think it is. 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug366682.html | Misspelling is what we think it is. 20:07:01 INFO - TEST-PASS | editor/libeditor/tests/test_bug366682.html | All misspellings accounted for. 20:07:01 INFO - GECKO(2351) | MEMORY STAT | vsize 4310MB | residentFast 195MB | heapAllocated 49MB 20:07:01 INFO - TEST-OK | editor/libeditor/tests/test_bug366682.html | took 83ms 20:07:01 INFO - TEST-START | editor/libeditor/tests/test_bug372345.html 20:07:01 INFO - GECKO(2351) | libc++abi.dylib: Pure virtual function called! 20:07:01 INFO - GECKO(2351) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x800017,name=PHttpChannel::Msg_DeleteSelf) Channel error: cannot send/recv 20:07:01 INFO - GECKO(2351) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x280080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 20:07:01 INFO - GECKO(2351) | 2017-06-13 20:07:01: minidump_processor.cc:295: ERROR: Minidump indicated requesting thread 0x9827, not found in /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpwe9AR9.mozrunner/minidumps/00ADFB4F-6EA2-4F2B-91E3-CF810035DA72.dmp 20:12:31 INFO - Buffered messages finished 20:12:31 ERROR - TEST-UNEXPECTED-TIMEOUT | editor/libeditor/tests/test_bug372345.html | application timed out after 330 seconds with no output 20:12:31 ERROR - Force-terminating active process(es). 20:12:31 INFO - Determining child pids from psutil 20:12:31 INFO - Found child pids: [2353] 20:12:31 INFO - Killing process: 2353 20:12:31 INFO - Not taking screenshot here: see the one that was previously logged 20:12:31 INFO - psutil found pid 2353 dead 20:12:31 INFO - Killing process: 2351 20:12:31 INFO - Not taking screenshot here: see the one that was previously logged 20:12:31 INFO - TEST-INFO | Main app process: exit 5 20:12:31 INFO - Buffered messages finished 20:12:31 ERROR - TEST-UNEXPECTED-FAIL | editor/libeditor/tests/test_bug372345.html | application terminated with exit code 5 20:12:31 INFO - runtests.py | Application ran for: 0:05:41.921744 20:12:31 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpzHXrTnpidlog 20:12:31 INFO - ==> process 2351 launched child process 2352 20:12:31 INFO - ==> process 2351 launched child process 2353 20:12:31 INFO - zombiecheck | Checking for orphan process with PID: 2352 20:12:31 INFO - zombiecheck | Checking for orphan process with PID: 2353 20:12:31 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 20:12:32 INFO - Traceback (most recent call last): 20:12:32 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2521, in doTests 20:12:32 INFO - marionette_args=marionette_args, 20:12:32 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2173, in runApp 20:12:32 INFO - test=self.lastTestSeen) 20:12:32 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 126, in log_crashes 20:12:32 INFO - stackwalk_binary=stackwalk_binary): 20:12:32 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 212, in __iter__ 20:12:32 INFO - rv = self._process_dump_file(path, extra) 20:12:32 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 234, in _process_dump_file 20:12:32 INFO - self._get_symbols() 20:12:32 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 180, in _get_symbols 20:12:32 INFO - data = urllib2.urlopen(self.symbols_path) 20:12:32 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 126, in urlopen 20:12:32 INFO - return _opener.open(url, data, timeout) 20:12:32 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 406, in open 20:12:32 INFO - response = meth(req, response) 20:12:32 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 519, in http_response 20:12:32 INFO - 'http', request, response, code, msg, hdrs) 20:12:32 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 444, in error 20:12:32 INFO - return self._call_chain(*args) 20:12:32 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 378, in _call_chain 20:12:32 INFO - result = func(*args) 20:12:32 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 527, in http_error_default 20:12:32 INFO - raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) 20:12:32 INFO - HTTPError: HTTP Error 404: Not Found 20:12:32 ERROR - Automation Error: Received unexpected exception while running application 20:12:32 ERROR - 20:12:32 INFO - Stopping web server 20:12:32 INFO - Stopping web socket server 20:12:32 INFO - Stopping ssltunnel 20:12:32 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:12:32 INFO - runtests.py | Running tests: end. 20:12:32 INFO - Buffered messages finished 20:12:32 INFO - dir: extensions/cookie/test 20:12:32 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:12:33 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:12:33 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpTVoBcr.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:12:33 INFO - runtests.py | Server pid: 2364 20:12:33 INFO - runtests.py | Websocket server pid: 2365 20:12:33 INFO - runtests.py | SSL tunnel pid: 2366 20:12:33 INFO - runtests.py | Running with e10s: True 20:12:33 INFO - runtests.py | Running tests: start. 20:12:33 INFO - 20:12:33 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpTVoBcr.mozrunner 20:12:33 INFO - runtests.py | Application pid: 2367 20:12:33 INFO - TEST-INFO | started process GECKO(2367) 20:12:36 INFO - GECKO(2367) | 1497409956269 Marionette INFO Listening on port 2828 20:12:36 INFO - GECKO(2367) | 2017-06-13 20:12:36.331 plugin-container[2368:29625] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4547, name = 'com.apple.tsm.portname' 20:12:36 INFO - GECKO(2367) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:36 INFO - GECKO(2367) | 2017-06-13 20:12:36.334 plugin-container[2368:29625] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0xa00b, name = 'com.apple.CFPasteboardClient' 20:12:36 INFO - GECKO(2367) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:36 INFO - GECKO(2367) | 2017-06-13 20:12:36.334 plugin-container[2368:29625] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:12:36 INFO - GECKO(2367) | 1497409956434 Marionette DEBUG loaded listener.js 20:12:37 INFO - GECKO(2367) | 2017-06-13 20:12:37.034 plugin-container[2369:29684] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9937, name = 'com.apple.tsm.portname' 20:12:37 INFO - GECKO(2367) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:37 INFO - GECKO(2367) | 2017-06-13 20:12:37.034 plugin-container[2369:29684] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4807, name = 'com.apple.CFPasteboardClient' 20:12:37 INFO - GECKO(2367) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:37 INFO - GECKO(2367) | 2017-06-13 20:12:37.034 plugin-container[2369:29684] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:12:37 INFO - SimpleTest START 20:12:37 INFO - TEST-START | extensions/cookie/test/test_different_domain_in_hierarchy.html 20:12:38 INFO - TEST-PASS | extensions/cookie/test/test_different_domain_in_hierarchy.html | message data received from popup 20:12:38 INFO - TEST-PASS | extensions/cookie/test/test_different_domain_in_hierarchy.html | message data received from popup 20:12:38 INFO - TEST-PASS | extensions/cookie/test/test_different_domain_in_hierarchy.html | message data received from popup 20:12:38 INFO - TEST-PASS | extensions/cookie/test/test_different_domain_in_hierarchy.html | total number of cookies 20:12:38 INFO - GECKO(2367) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:12:38 INFO - GECKO(2367) | MEMORY STAT | vsize 3912MB | residentFast 117MB | heapAllocated 22MB 20:12:38 INFO - TEST-OK | extensions/cookie/test/test_different_domain_in_hierarchy.html | took 1607ms 20:12:38 INFO - TEST-START | extensions/cookie/test/test_differentdomain.html 20:12:39 INFO - TEST-PASS | extensions/cookie/test/test_differentdomain.html | message data received from popup 20:12:39 INFO - TEST-PASS | extensions/cookie/test/test_differentdomain.html | message data received from popup 20:12:39 INFO - TEST-PASS | extensions/cookie/test/test_differentdomain.html | total number of cookies 20:12:39 INFO - GECKO(2367) | MEMORY STAT | vsize 3917MB | residentFast 122MB | heapAllocated 24MB 20:12:39 INFO - TEST-OK | extensions/cookie/test/test_differentdomain.html | took 487ms 20:12:39 INFO - TEST-START | extensions/cookie/test/test_image.html 20:12:39 INFO - TEST-PASS | extensions/cookie/test/test_image.html | message data received from popup 20:12:39 INFO - TEST-PASS | extensions/cookie/test/test_image.html | message data received from popup 20:12:39 INFO - TEST-PASS | extensions/cookie/test/test_image.html | message data received from popup 20:12:39 INFO - TEST-PASS | extensions/cookie/test/test_image.html | total number of cookies 20:12:39 INFO - GECKO(2367) | MEMORY STAT | vsize 3920MB | residentFast 126MB | heapAllocated 26MB 20:12:39 INFO - TEST-OK | extensions/cookie/test/test_image.html | took 519ms 20:12:39 INFO - TEST-START | extensions/cookie/test/test_loadflags.html 20:12:40 INFO - setupTest uri: http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html domain: example.org cookies: 5 loads: 2 headers: 2 20:12:40 INFO - we are going to remove these cookies 20:12:40 INFO - 0 cookies 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_loadflags.html | number of cookies for domain example.org (1 === 1) 20:12:40 INFO - adding observer 20:12:40 INFO - theSubject [xpconnect wrapped nsISupports] 20:12:40 INFO - theTopic http-on-modify-request 20:12:40 INFO - theData null 20:12:40 INFO - channel [xpconnect wrapped nsIHttpChannel] 20:12:40 INFO - channel.URI [xpconnect wrapped nsIURI] 20:12:40 INFO - channel.URI.spec http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html 20:12:40 INFO - Host: example.org 20:12:40 INFO - User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:55.0) Gecko/20100101 Firefox/55.0 20:12:40 INFO - Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 20:12:40 INFO - Accept-Language: en-US,en;q=0.5 20:12:40 INFO - Accept-Encoding: gzip, deflate 20:12:40 INFO - Referer: http://mochi.test:8888/tests/extensions/cookie/test/test_loadflags.html 20:12:40 INFO - Cookie: oh=hai 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_loadflags.html | cookie 'oh=hai' is in header for http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html 20:12:40 INFO - theSubject [xpconnect wrapped nsISupports] 20:12:40 INFO - theTopic http-on-modify-request 20:12:40 INFO - theData null 20:12:40 INFO - channel [xpconnect wrapped nsIHttpChannel] 20:12:40 INFO - channel.URI [xpconnect wrapped nsIURI] 20:12:40 INFO - channel.URI.spec http://example.org/tests/extensions/cookie/test/beltzner.jpg 20:12:40 INFO - Host: example.org 20:12:40 INFO - User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:55.0) Gecko/20100101 Firefox/55.0 20:12:40 INFO - Accept: */* 20:12:40 INFO - Accept-Language: en-US,en;q=0.5 20:12:40 INFO - Accept-Encoding: gzip, deflate 20:12:40 INFO - Referer: http://example.org/tests/extensions/cookie/test/file_loadflags_inner.html 20:12:40 INFO - Cookie: meta=tag; oh=hai 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_loadflags.html | cookie 'oh=hai' is in header for http://example.org/tests/extensions/cookie/test/beltzner.jpg 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_loadflags.html | message data received from popup 20:12:40 INFO - message data received from popup for image 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_loadflags.html | message data received from popup 20:12:40 INFO - message data received from popup for page 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_loadflags.html | number of observed request headers 20:12:40 INFO - cookie: [xpconnect wrapped nsICookie] 20:12:40 INFO - cookie host example.org path name oh value hai isSecure false expires 0 20:12:40 INFO - cookie: [xpconnect wrapped nsICookie] 20:12:40 INFO - cookie host example.org path /tests/extensions/cookie/test/ name meta value tag isSecure false expires 0 20:12:40 INFO - cookie: [xpconnect wrapped nsICookie] 20:12:40 INFO - cookie host example.org path /tests/extensions/cookie/test/ name mike value beltzer isSecure false expires 0 20:12:40 INFO - cookie: [xpconnect wrapped nsICookie] 20:12:40 INFO - cookie host example.org path /tests/extensions/cookie/test/ name can value has isSecure false expires 0 20:12:40 INFO - cookie: [xpconnect wrapped nsICookie] 20:12:40 INFO - cookie host mochi.test path /tests/extensions/cookie/test/ name o value noes isSecure false expires 0 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_loadflags.html | total number of cookies 20:12:40 INFO - theSubject [xpconnect wrapped nsISupports] 20:12:40 INFO - theTopic http-on-modify-request 20:12:40 INFO - theData null 20:12:40 INFO - channel [xpconnect wrapped nsIHttpChannel] 20:12:40 INFO - channel.URI [xpconnect wrapped nsIURI] 20:12:40 INFO - channel.URI.spec http://example.org/favicon.ico 20:12:40 INFO - Host: example.org 20:12:40 INFO - User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:55.0) Gecko/20100101 Firefox/55.0 20:12:40 INFO - Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 20:12:40 INFO - Accept-Language: en-US,en;q=0.5 20:12:40 INFO - Accept-Encoding: gzip, deflate 20:12:40 INFO - ignoring this one 20:12:40 INFO - removing observer 20:12:40 INFO - GECKO(2367) | MEMORY STAT | vsize 3925MB | residentFast 131MB | heapAllocated 29MB 20:12:40 INFO - TEST-OK | extensions/cookie/test/test_loadflags.html | took 813ms 20:12:40 INFO - TEST-START | extensions/cookie/test/test_same_base_domain.html 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain.html | message data received from popup 20:12:40 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain.html | message data received from popup 20:12:41 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain.html | total number of cookies 20:12:41 INFO - GECKO(2367) | MEMORY STAT | vsize 3932MB | residentFast 138MB | heapAllocated 31MB 20:12:41 INFO - TEST-OK | extensions/cookie/test/test_same_base_domain.html | took 441ms 20:12:41 INFO - TEST-START | extensions/cookie/test/test_same_base_domain_2.html 20:12:41 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_2.html | message data received from popup 20:12:41 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_2.html | message data received from popup 20:12:41 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_2.html | total number of cookies 20:12:41 INFO - GECKO(2367) | MEMORY STAT | vsize 3936MB | residentFast 142MB | heapAllocated 33MB 20:12:41 INFO - TEST-OK | extensions/cookie/test/test_same_base_domain_2.html | took 500ms 20:12:41 INFO - TEST-START | extensions/cookie/test/test_same_base_domain_3.html 20:12:42 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_3.html | message data received from popup 20:12:42 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_3.html | message data received from popup 20:12:42 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_3.html | total number of cookies 20:12:42 INFO - GECKO(2367) | MEMORY STAT | vsize 3935MB | residentFast 142MB | heapAllocated 27MB 20:12:42 INFO - TEST-OK | extensions/cookie/test/test_same_base_domain_3.html | took 583ms 20:12:42 INFO - TEST-START | extensions/cookie/test/test_same_base_domain_4.html 20:12:42 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_4.html | message data received from popup 20:12:42 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_4.html | message data received from popup 20:12:42 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_4.html | total number of cookies 20:12:42 INFO - GECKO(2367) | MEMORY STAT | vsize 3935MB | residentFast 142MB | heapAllocated 29MB 20:12:42 INFO - TEST-OK | extensions/cookie/test/test_same_base_domain_4.html | took 496ms 20:12:42 INFO - TEST-START | extensions/cookie/test/test_same_base_domain_5.html 20:12:43 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_5.html | message data received from popup 20:12:43 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_5.html | message data received from popup 20:12:43 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_5.html | total number of cookies 20:12:43 INFO - GECKO(2367) | MEMORY STAT | vsize 3935MB | residentFast 142MB | heapAllocated 30MB 20:12:43 INFO - TEST-OK | extensions/cookie/test/test_same_base_domain_5.html | took 706ms 20:12:43 INFO - TEST-START | extensions/cookie/test/test_same_base_domain_6.html 20:12:44 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_6.html | message data received from popup 20:12:44 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_6.html | message data received from popup 20:12:44 INFO - TEST-PASS | extensions/cookie/test/test_same_base_domain_6.html | total number of cookies 20:12:44 INFO - GECKO(2367) | MEMORY STAT | vsize 4129MB | residentFast 144MB | heapAllocated 32MB 20:12:44 INFO - TEST-OK | extensions/cookie/test/test_same_base_domain_6.html | took 793ms 20:12:44 INFO - TEST-START | extensions/cookie/test/test_samedomain.html 20:12:44 INFO - TEST-PASS | extensions/cookie/test/test_samedomain.html | message data received from popup 20:12:44 INFO - TEST-PASS | extensions/cookie/test/test_samedomain.html | message data received from popup 20:12:44 INFO - TEST-PASS | extensions/cookie/test/test_samedomain.html | total number of cookies 20:12:44 INFO - GECKO(2367) | MEMORY STAT | vsize 4130MB | residentFast 148MB | heapAllocated 34MB 20:12:45 INFO - TEST-OK | extensions/cookie/test/test_samedomain.html | took 680ms 20:12:45 INFO - TEST-START | Shutdown 20:12:45 INFO - Passed: 39 20:12:45 INFO - Failed: 0 20:12:45 INFO - Todo: 0 20:12:45 INFO - Mode: e10s 20:12:45 INFO - Slowest: 1606ms - /tests/extensions/cookie/test/test_different_domain_in_hierarchy.html 20:12:45 INFO - SimpleTest FINISHED 20:12:45 INFO - TEST-INFO | Ran 1 Loops 20:12:45 INFO - SimpleTest FINISHED 20:12:45 INFO - GECKO(2367) | JavaScript error: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js, line 861: TypeError: DebuggerServer.removeContentServerScript is not a function 20:12:46 INFO - TEST-INFO | Main app process: exit 0 20:12:46 INFO - runtests.py | Application ran for: 0:00:13.033090 20:12:46 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpDb3h8Cpidlog 20:12:46 INFO - ==> process 2367 launched child process 2368 20:12:46 INFO - ==> process 2367 launched child process 2369 20:12:46 INFO - zombiecheck | Checking for orphan process with PID: 2368 20:12:46 INFO - zombiecheck | Checking for orphan process with PID: 2369 20:12:46 INFO - Stopping web server 20:12:46 INFO - Stopping web socket server 20:12:46 INFO - Stopping ssltunnel 20:12:46 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:12:46 INFO - runtests.py | Running tests: end. 20:12:46 INFO - Buffered messages finished 20:12:46 INFO - dir: extensions/spellcheck/tests/mochitest 20:12:46 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:12:46 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:12:46 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmphrOBee.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:12:46 INFO - runtests.py | Server pid: 2377 20:12:46 INFO - runtests.py | Websocket server pid: 2378 20:12:46 INFO - runtests.py | SSL tunnel pid: 2379 20:12:46 INFO - runtests.py | Running with e10s: True 20:12:46 INFO - runtests.py | Running tests: start. 20:12:46 INFO - 20:12:46 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmphrOBee.mozrunner 20:12:46 INFO - runtests.py | Application pid: 2380 20:12:46 INFO - TEST-INFO | started process GECKO(2380) 20:12:49 INFO - GECKO(2380) | 1497409969789 Marionette INFO Listening on port 2828 20:12:49 INFO - GECKO(2380) | 1497409969954 Marionette DEBUG loaded listener.js 20:12:50 INFO - GECKO(2380) | 2017-06-13 20:12:49.996 plugin-container[2381:29923] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9937, name = 'com.apple.tsm.portname' 20:12:50 INFO - GECKO(2380) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:50 INFO - GECKO(2380) | 2017-06-13 20:12:49.996 plugin-container[2381:29923] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4907, name = 'com.apple.CFPasteboardClient' 20:12:50 INFO - GECKO(2380) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:50 INFO - GECKO(2380) | 2017-06-13 20:12:49.996 plugin-container[2381:29923] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:12:50 INFO - GECKO(2380) | 2017-06-13 20:12:50.547 plugin-container[2382:29974] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x993b, name = 'com.apple.tsm.portname' 20:12:50 INFO - GECKO(2380) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:50 INFO - GECKO(2380) | 2017-06-13 20:12:50.551 plugin-container[2382:29974] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9b0b, name = 'com.apple.CFPasteboardClient' 20:12:50 INFO - GECKO(2380) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:50 INFO - GECKO(2380) | 2017-06-13 20:12:50.551 plugin-container[2382:29974] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:12:50 INFO - SimpleTest START 20:12:50 INFO - TEST-START | extensions/spellcheck/tests/mochitest/test_bug1170484.html 20:12:51 INFO - must wait for load 20:12:51 INFO - Loaded chrome script 20:12:51 INFO - TEST-PASS | extensions/spellcheck/tests/mochitest/test_bug1170484.html | Spelling corrected properly 20:12:51 INFO - TEST-PASS | extensions/spellcheck/tests/mochitest/test_bug1170484.html | Got correct number of mutations 20:12:51 INFO - TEST-PASS | extensions/spellcheck/tests/mochitest/test_bug1170484.html | Got correct number of input events 20:12:51 INFO - GECKO(2380) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:12:51 INFO - GECKO(2380) | MEMORY STAT | vsize 3912MB | residentFast 118MB | heapAllocated 22MB 20:12:51 INFO - TEST-OK | extensions/spellcheck/tests/mochitest/test_bug1170484.html | took 1351ms 20:12:51 INFO - TEST-START | extensions/spellcheck/tests/mochitest/test_bug1272623.html 20:12:52 INFO - SpawnTask.js | Entering test 20:12:52 INFO - must wait for load 20:12:52 INFO - Loaded chrome script 20:12:52 INFO - TEST-PASS | extensions/spellcheck/tests/mochitest/test_bug1272623.html | undefined assertion name 20:12:52 INFO - TEST-PASS | extensions/spellcheck/tests/mochitest/test_bug1272623.html | Spelling corrected properly 20:12:52 INFO - Loaded chrome script 20:12:52 INFO - TEST-PASS | extensions/spellcheck/tests/mochitest/test_bug1272623.html | undefined assertion name 20:12:52 INFO - TEST-PASS | extensions/spellcheck/tests/mochitest/test_bug1272623.html | Spelling corrected properly 20:12:52 INFO - SpawnTask.js | Leaving test 20:12:52 INFO - GECKO(2380) | MEMORY STAT | vsize 3915MB | residentFast 121MB | heapAllocated 24MB 20:12:52 INFO - TEST-OK | extensions/spellcheck/tests/mochitest/test_bug1272623.html | took 233ms 20:12:52 INFO - TEST-START | Shutdown 20:12:52 INFO - Passed: 7 20:12:52 INFO - Failed: 0 20:12:52 INFO - Todo: 0 20:12:52 INFO - Mode: e10s 20:12:52 INFO - Slowest: 1352ms - /tests/extensions/spellcheck/tests/mochitest/test_bug1170484.html 20:12:52 INFO - SimpleTest FINISHED 20:12:52 INFO - TEST-INFO | Ran 1 Loops 20:12:52 INFO - SimpleTest FINISHED 20:12:52 INFO - GECKO(2380) | JavaScript error: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js, line 861: TypeError: DebuggerServer.removeContentServerScript is not a function 20:12:53 INFO - TEST-INFO | Main app process: exit 0 20:12:53 INFO - runtests.py | Application ran for: 0:00:06.409672 20:12:53 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpl3LwXapidlog 20:12:53 INFO - ==> process 2380 launched child process 2381 20:12:53 INFO - ==> process 2380 launched child process 2382 20:12:53 INFO - zombiecheck | Checking for orphan process with PID: 2381 20:12:53 INFO - zombiecheck | Checking for orphan process with PID: 2382 20:12:53 INFO - Stopping web server 20:12:53 INFO - Stopping web socket server 20:12:53 INFO - Stopping ssltunnel 20:12:53 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:12:53 INFO - runtests.py | Running tests: end. 20:12:53 INFO - Buffered messages finished 20:12:53 INFO - dir: gfx/layers/apz/test/mochitest 20:12:53 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:12:53 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:12:53 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpAV29U6.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:12:53 INFO - runtests.py | Server pid: 2389 20:12:53 INFO - runtests.py | Websocket server pid: 2390 20:12:53 INFO - runtests.py | SSL tunnel pid: 2391 20:12:53 INFO - runtests.py | Running with e10s: True 20:12:53 INFO - runtests.py | Running tests: start. 20:12:53 INFO - 20:12:53 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpAV29U6.mozrunner 20:12:53 INFO - runtests.py | Application pid: 2392 20:12:53 INFO - TEST-INFO | started process GECKO(2392) 20:12:56 INFO - GECKO(2392) | 1497409976588 Marionette INFO Listening on port 2828 20:12:56 INFO - GECKO(2392) | 1497409976789 Marionette DEBUG loaded listener.js 20:12:56 INFO - GECKO(2392) | 2017-06-13 20:12:56.839 plugin-container[2393:30157] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x983f, name = 'com.apple.tsm.portname' 20:12:56 INFO - GECKO(2392) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:56 INFO - GECKO(2392) | 2017-06-13 20:12:56.840 plugin-container[2393:30157] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9d0b, name = 'com.apple.CFPasteboardClient' 20:12:56 INFO - GECKO(2392) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:56 INFO - GECKO(2392) | 2017-06-13 20:12:56.840 plugin-container[2393:30157] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:12:57 INFO - GECKO(2392) | 2017-06-13 20:12:57.153 plugin-container[2394:30204] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x973f, name = 'com.apple.tsm.portname' 20:12:57 INFO - GECKO(2392) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:57 INFO - GECKO(2392) | 2017-06-13 20:12:57.155 plugin-container[2394:30204] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9c0f, name = 'com.apple.CFPasteboardClient' 20:12:57 INFO - GECKO(2392) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:12:57 INFO - GECKO(2392) | 2017-06-13 20:12:57.155 plugin-container[2394:30204] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:12:57 INFO - SimpleTest START 20:12:57 INFO - TEST-START | gfx/layers/apz/test/mochitest/test_bug1151663.html 20:12:58 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1151663.html | expected at least one paint in compositor test data 20:12:58 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1151663.html | found the RCD node 20:12:58 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1151663.html | expected no children on the RCD 20:12:58 INFO - GECKO(2392) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:12:58 INFO - GECKO(2392) | MEMORY STAT | vsize 3917MB | residentFast 123MB | heapAllocated 22MB 20:12:58 INFO - TEST-OK | gfx/layers/apz/test/mochitest/test_bug1151663.html | took 1514ms 20:12:59 INFO - TEST-START | gfx/layers/apz/test/mochitest/test_bug1151667.html 20:12:59 INFO - must wait for load 20:12:59 INFO - GECKO(2392) | Flushed APZ repaints, waiting for callback... 20:12:59 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1151667.html | We should have scrolled the subframe down 20:12:59 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1151667.html | We should not have scrolled the page 20:12:59 INFO - GECKO(2392) | MEMORY STAT | vsize 3922MB | residentFast 126MB | heapAllocated 23MB 20:12:59 INFO - TEST-OK | gfx/layers/apz/test/mochitest/test_bug1151667.html | took 199ms 20:12:59 INFO - TEST-START | gfx/layers/apz/test/mochitest/test_bug1253683.html 20:12:59 INFO - GECKO(2392) | Flushed APZ repaints, waiting for callback... 20:12:59 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1253683.html | Initial scrollY should be 0 20:12:59 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1253683.html | expected at least one paint 20:12:59 INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_bug1253683.html | initially 'no_layer' should not be layerized 20:18:27 INFO - Not taking screenshot here: see the one that was previously logged 20:18:27 INFO - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_bug1253683.html | Test timed out. 20:18:27 INFO - reportError@SimpleTest/TestRunner.js:121:7 20:18:27 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5 20:18:27 INFO - TestRunner.runTests@SimpleTest/TestRunner.js:380:5 20:18:27 INFO - RunSet.runtests@SimpleTest/setup.js:194:3 20:18:27 INFO - RunSet.runall@SimpleTest/setup.js:173:5 20:18:27 INFO - hookupTests@SimpleTest/setup.js:266:5 20:18:27 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5 20:18:27 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11 20:18:27 INFO - EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3 20:18:27 INFO - hookup@SimpleTest/setup.js:246:5 20:18:27 INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&hideResultsTable=1&manifestFile=tests.json&dumpOutputDirectory=%2Fvar%2Ffolders%2Fxm%2Fn27ws1sd1t3406fsw7fnw23r00000w%2FT&cleanupCrashes=true:11:1 20:18:28 INFO - GECKO(2392) | MEMORY STAT | vsize 4107MB | residentFast 123MB | heapAllocated 15MB 20:18:28 INFO - TEST-OK | gfx/layers/apz/test/mochitest/test_bug1253683.html | took 329258ms 20:18:28 INFO - TEST-START | gfx/layers/apz/test/mochitest/test_bug1277814.html 20:18:28 INFO - GECKO(2392) | Flushed APZ repaints, waiting for callback... 20:18:28 INFO - GECKO(2392) | Flushed APZ repaints, waiting for callback... 20:18:44 INFO - GECKO(2392) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x280080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 20:24:14 INFO - Buffered messages finished 20:24:14 ERROR - TEST-UNEXPECTED-TIMEOUT | gfx/layers/apz/test/mochitest/test_bug1277814.html | application timed out after 330 seconds with no output 20:24:14 ERROR - Force-terminating active process(es). 20:24:14 INFO - Determining child pids from psutil 20:24:14 INFO - Found child pids: [2394] 20:24:14 INFO - Killing process: 2394 20:24:14 INFO - Not taking screenshot here: see the one that was previously logged 20:24:14 INFO - psutil found pid 2394 dead 20:24:14 INFO - Killing process: 2392 20:24:14 INFO - Not taking screenshot here: see the one that was previously logged 20:24:14 INFO - TEST-INFO | Main app process: exit 5 20:24:14 INFO - Buffered messages finished 20:24:14 ERROR - TEST-UNEXPECTED-FAIL | gfx/layers/apz/test/mochitest/test_bug1277814.html | application terminated with exit code 5 20:24:14 INFO - runtests.py | Application ran for: 0:11:20.488402 20:24:14 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpqM_gVIpidlog 20:24:14 INFO - ==> process 2392 launched child process 2393 20:24:14 INFO - ==> process 2392 launched child process 2394 20:24:14 INFO - zombiecheck | Checking for orphan process with PID: 2393 20:24:14 INFO - zombiecheck | Checking for orphan process with PID: 2394 20:24:14 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 20:24:15 INFO - Traceback (most recent call last): 20:24:15 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2521, in doTests 20:24:15 INFO - marionette_args=marionette_args, 20:24:15 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2173, in runApp 20:24:15 INFO - test=self.lastTestSeen) 20:24:15 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 126, in log_crashes 20:24:15 INFO - stackwalk_binary=stackwalk_binary): 20:24:15 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 212, in __iter__ 20:24:15 INFO - rv = self._process_dump_file(path, extra) 20:24:15 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 234, in _process_dump_file 20:24:15 INFO - self._get_symbols() 20:24:15 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 180, in _get_symbols 20:24:15 INFO - data = urllib2.urlopen(self.symbols_path) 20:24:15 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 126, in urlopen 20:24:15 INFO - return _opener.open(url, data, timeout) 20:24:15 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 406, in open 20:24:15 INFO - response = meth(req, response) 20:24:15 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 519, in http_response 20:24:15 INFO - 'http', request, response, code, msg, hdrs) 20:24:15 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 444, in error 20:24:15 INFO - return self._call_chain(*args) 20:24:15 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 378, in _call_chain 20:24:15 INFO - result = func(*args) 20:24:15 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 527, in http_error_default 20:24:15 INFO - raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) 20:24:15 INFO - HTTPError: HTTP Error 404: Not Found 20:24:15 ERROR - Automation Error: Received unexpected exception while running application 20:24:15 ERROR - 20:24:15 INFO - Stopping web server 20:24:15 INFO - Stopping web socket server 20:24:15 INFO - Stopping ssltunnel 20:24:15 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:24:15 INFO - runtests.py | Running tests: end. 20:24:15 INFO - Buffered messages finished 20:24:15 INFO - dir: gfx/tests/mochitest 20:24:15 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:24:15 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:24:15 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpIJn6J9.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:24:15 INFO - runtests.py | Server pid: 2405 20:24:15 INFO - runtests.py | Websocket server pid: 2406 20:24:15 INFO - runtests.py | SSL tunnel pid: 2407 20:24:15 INFO - runtests.py | Running with e10s: True 20:24:15 INFO - runtests.py | Running tests: start. 20:24:15 INFO - 20:24:15 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpIJn6J9.mozrunner 20:24:15 INFO - runtests.py | Application pid: 2408 20:24:15 INFO - TEST-INFO | started process GECKO(2408) 20:24:19 INFO - GECKO(2408) | 1497410659184 Marionette INFO Listening on port 2828 20:24:19 INFO - GECKO(2408) | 2017-06-13 20:24:19.282 plugin-container[2409:31082] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4647, name = 'com.apple.tsm.portname' 20:24:19 INFO - GECKO(2408) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:19 INFO - GECKO(2408) | 2017-06-13 20:24:19.285 plugin-container[2409:31082] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9f1b, name = 'com.apple.CFPasteboardClient' 20:24:19 INFO - GECKO(2408) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:19 INFO - GECKO(2408) | 2017-06-13 20:24:19.285 plugin-container[2409:31082] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:24:19 INFO - GECKO(2408) | 1497410659372 Marionette DEBUG loaded listener.js 20:24:19 INFO - GECKO(2408) | 2017-06-13 20:24:19.703 plugin-container[2410:31132] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x953f, name = 'com.apple.tsm.portname' 20:24:19 INFO - GECKO(2408) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:19 INFO - GECKO(2408) | 2017-06-13 20:24:19.709 plugin-container[2410:31132] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9b0b, name = 'com.apple.CFPasteboardClient' 20:24:19 INFO - GECKO(2408) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:19 INFO - GECKO(2408) | 2017-06-13 20:24:19.709 plugin-container[2410:31132] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:24:20 INFO - SimpleTest START 20:24:20 INFO - TEST-START | gfx/tests/mochitest/test_bug509244.html 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_bug509244.html | not crashed 20:24:21 INFO - GECKO(2408) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:24:21 INFO - GECKO(2408) | MEMORY STAT | vsize 3907MB | residentFast 112MB | heapAllocated 16MB 20:24:21 INFO - TEST-OK | gfx/tests/mochitest/test_bug509244.html | took 1189ms 20:24:21 INFO - TEST-START | gfx/tests/mochitest/test_bug513439.html 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_bug513439.html | devPixelsPerPx wasn't set correctly 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_bug513439.html | devPixelsPerPx wasn't set correctly 20:24:21 INFO - GECKO(2408) | MEMORY STAT | vsize 3913MB | residentFast 119MB | heapAllocated 18MB 20:24:21 INFO - TEST-OK | gfx/tests/mochitest/test_bug513439.html | took 235ms 20:24:21 INFO - TEST-START | gfx/tests/mochitest/test_font_whitelist.html 20:24:21 INFO - SpawnTask.js | Entering test 20:24:21 INFO - font whitelist: [] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Courier, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Helvetica, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Times, requested Times 20:24:21 INFO - font whitelist: ["Times"] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Times, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Times, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Times, requested Times 20:24:21 INFO - font whitelist: ["Helvetica"] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Helvetica, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Helvetica, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Helvetica, requested Times 20:24:21 INFO - font whitelist: ["Helvetica","Times"] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Helvetica, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Helvetica, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Times, requested Times 20:24:21 INFO - font whitelist: ["Courier"] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Courier, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Courier, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Courier, requested Times 20:24:21 INFO - font whitelist: ["Courier","Times"] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Courier, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Times, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Times, requested Times 20:24:21 INFO - font whitelist: ["Courier","Helvetica"] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Courier, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Helvetica, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Helvetica, requested Times 20:24:21 INFO - font whitelist: ["Courier","Helvetica","Times"] 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct mono whitelisting state; got Courier, requested Courier 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct sans whitelisting state; got Helvetica, requested Helvetica 20:24:21 INFO - TEST-PASS | gfx/tests/mochitest/test_font_whitelist.html | Correct serif whitelisting state; got Times, requested Times 20:24:21 INFO - SpawnTask.js | Leaving test 20:24:21 INFO - GECKO(2408) | MEMORY STAT | vsize 3916MB | residentFast 123MB | heapAllocated 18MB 20:24:22 INFO - TEST-OK | gfx/tests/mochitest/test_font_whitelist.html | took 669ms 20:24:22 INFO - TEST-START | Shutdown 20:24:22 INFO - Passed: 27 20:24:22 INFO - Failed: 0 20:24:22 INFO - Todo: 0 20:24:22 INFO - Mode: e10s 20:24:22 INFO - Slowest: 1189ms - /tests/gfx/tests/mochitest/test_bug509244.html 20:24:22 INFO - SimpleTest FINISHED 20:24:22 INFO - TEST-INFO | Ran 1 Loops 20:24:22 INFO - SimpleTest FINISHED 20:24:22 INFO - GECKO(2408) | JavaScript error: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/client/framework/devtools-browser.js, line 861: TypeError: DebuggerServer.removeContentServerScript is not a function 20:24:23 INFO - TEST-INFO | Main app process: exit 0 20:24:23 INFO - runtests.py | Application ran for: 0:00:07.363223 20:24:23 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpa3OHJdpidlog 20:24:23 INFO - ==> process 2408 launched child process 2409 20:24:23 INFO - ==> process 2408 launched child process 2410 20:24:23 INFO - zombiecheck | Checking for orphan process with PID: 2409 20:24:23 INFO - zombiecheck | Checking for orphan process with PID: 2410 20:24:23 INFO - Stopping web server 20:24:23 INFO - Stopping web socket server 20:24:23 INFO - Stopping ssltunnel 20:24:23 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:24:23 INFO - runtests.py | Running tests: end. 20:24:23 INFO - Buffered messages finished 20:24:23 INFO - dir: image/test/mochitest 20:24:23 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:24:23 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:24:23 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpitvmfy.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:24:23 INFO - runtests.py | Server pid: 2417 20:24:23 INFO - runtests.py | Websocket server pid: 2418 20:24:23 INFO - runtests.py | SSL tunnel pid: 2419 20:24:23 INFO - runtests.py | Running with e10s: True 20:24:23 INFO - runtests.py | Running tests: start. 20:24:23 INFO - 20:24:23 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpitvmfy.mozrunner 20:24:23 INFO - runtests.py | Application pid: 2420 20:24:23 INFO - TEST-INFO | started process GECKO(2420) 20:24:26 INFO - GECKO(2420) | 1497410666601 Marionette INFO Listening on port 2828 20:24:26 INFO - GECKO(2420) | 1497410666830 Marionette DEBUG loaded listener.js 20:24:26 INFO - GECKO(2420) | 2017-06-13 20:24:26.885 plugin-container[2421:31326] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x454b, name = 'com.apple.tsm.portname' 20:24:26 INFO - GECKO(2420) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:26 INFO - GECKO(2420) | 2017-06-13 20:24:26.886 plugin-container[2421:31326] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4913, name = 'com.apple.CFPasteboardClient' 20:24:26 INFO - GECKO(2420) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:26 INFO - GECKO(2420) | 2017-06-13 20:24:26.886 plugin-container[2421:31326] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:24:27 INFO - GECKO(2420) | 2017-06-13 20:24:27.437 plugin-container[2422:31375] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4843, name = 'com.apple.tsm.portname' 20:24:27 INFO - GECKO(2420) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:27 INFO - GECKO(2420) | 2017-06-13 20:24:27.442 plugin-container[2422:31375] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9c0f, name = 'com.apple.CFPasteboardClient' 20:24:27 INFO - GECKO(2420) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:24:27 INFO - GECKO(2420) | 2017-06-13 20:24:27.442 plugin-container[2422:31375] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:24:27 INFO - SimpleTest START 20:24:27 INFO - TEST-START | image/test/mochitest/test_ImageContentLoaded.html 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_ImageContentLoaded.html | chrome listener was invoked 20:24:28 INFO - GECKO(2420) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:24:28 INFO - GECKO(2420) | MEMORY STAT | vsize 3909MB | residentFast 115MB | heapAllocated 21MB 20:24:28 INFO - TEST-OK | image/test/mochitest/test_ImageContentLoaded.html | took 1145ms 20:24:28 INFO - TEST-START | image/test/mochitest/test_animSVGImage.html 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | A valid string reason is expected 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | Reason cannot be empty 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | reference snapshot shouldn't match blank page snapshot 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | reference div should disappear when it becomes display:none 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:28 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:28 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | Animated image looks correct, at call #8 to myPoll 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | Animated image looks correct, at call #9 to myPoll 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | myPoll called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage.html | Animated image looks correct, at call #10 to myPoll 20:24:29 INFO - GECKO(2420) | MEMORY STAT | vsize 3978MB | residentFast 131MB | heapAllocated 23MB 20:24:29 INFO - TEST-OK | image/test/mochitest/test_animSVGImage.html | took 337ms 20:24:29 INFO - TEST-START | image/test/mochitest/test_animSVGImage2.html 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | A valid string reason is expected 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | Reason cannot be empty 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | reference snapshot shouldn't match blank page snapshot 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | reference div should disappear when it becomes display:none 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animSVGImage2.html | The author of the test has indicated that flaky timeouts are expected. Reason: Early failure timeout 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | myOnFrameUpdate called 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animSVGImage2.html | Animated image looks correct, at call #6 to myOnFrameUpdate 20:24:29 INFO - GECKO(2420) | MEMORY STAT | vsize 3989MB | residentFast 133MB | heapAllocated 24MB 20:24:29 INFO - TEST-OK | image/test/mochitest/test_animSVGImage2.html | took 243ms 20:24:29 INFO - TEST-START | image/test/mochitest/test_animation.html 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation.html | A valid string reason is expected 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation.html | Reason cannot be empty 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation.html | Reference image should disappear when it becomes display:none 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation.html | Animated image looks correct, at poll #4 20:24:29 INFO - GECKO(2420) | MEMORY STAT | vsize 3998MB | residentFast 137MB | heapAllocated 26MB 20:24:29 INFO - TEST-OK | image/test/mochitest/test_animation.html | took 313ms 20:24:29 INFO - TEST-START | image/test/mochitest/test_animation2.html 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation2.html | A valid string reason is expected 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation2.html | Reason cannot be empty 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animation2.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation2.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation2.html | Reference image should disappear when it becomes display:none 20:24:29 INFO - TEST-FAIL | image/test/mochitest/test_animation2.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation2.html | Animated image looks correct, at poll #2 20:24:29 INFO - GECKO(2420) | MEMORY STAT | vsize 4003MB | residentFast 138MB | heapAllocated 27MB 20:24:29 INFO - TEST-OK | image/test/mochitest/test_animation2.html | took 188ms 20:24:29 INFO - TEST-START | image/test/mochitest/test_animation_operators.html 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | A valid string reason is expected 20:24:29 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | Reason cannot be empty 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - GECKO(2420) | JavaScript error: , line 0: TypeError: can't access dead object 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (6) == over.png grey.png 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (7) != source.png grey.png 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (8) == bug900200.png bug900200-ref.png 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (2) == keep.gif green.png 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (3) == keep.png green.png 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (5) == restore-previous.png green.png 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_animation_operators.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (9) == bug1319025.png bug1319025-ref.png 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (10) == clear2.gif clear2-results.gif 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (0) == green-background.html?clear.gif green.png 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (4) == restore-previous.gif green.png 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_animation_operators.html | (1) == green-background.html?clear.png green.png 20:24:30 INFO - GECKO(2420) | MEMORY STAT | vsize 4012MB | residentFast 148MB | heapAllocated 34MB 20:24:30 INFO - TEST-OK | image/test/mochitest/test_animation_operators.html | took 636ms 20:24:30 INFO - TEST-START | image/test/mochitest/test_background_image_anim.html 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_background_image_anim.html | A valid string reason is expected 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_background_image_anim.html | Reason cannot be empty 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_background_image_anim.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_background_image_anim.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_background_image_anim.html | Reference image should disappear when it becomes display:none 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_background_image_anim.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-FAIL | image/test/mochitest/test_background_image_anim.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_background_image_anim.html | Animated image looks correct, at poll #3 20:24:30 INFO - GECKO(2420) | MEMORY STAT | vsize 4023MB | residentFast 154MB | heapAllocated 29MB 20:24:30 INFO - TEST-OK | image/test/mochitest/test_background_image_anim.html | took 340ms 20:24:30 INFO - TEST-START | image/test/mochitest/test_bug1132427.html 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | A valid string reason is expected 20:24:30 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | Reason cannot be empty 20:24:31 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:32 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-FAIL | image/test/mochitest/test_bug1132427.html | The author of the test has indicated that flaky timeouts are expected. Reason: Pre-existing timeouts when converting from mochitest-chrome 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - TEST-PASS | image/test/mochitest/test_bug1132427.html | pixels should match 20:24:33 INFO - GECKO(2420) | MEMORY STAT | vsize 4070MB | residentFast 184MB | heapAllocated 47MB 20:24:33 INFO - TEST-OK | image/test/mochitest/test_bug1132427.html | took 2762ms 20:24:33 INFO - TEST-START | image/test/mochitest/test_bug1180105.html 20:24:34 INFO - TEST-PASS | image/test/mochitest/test_bug1180105.html | Image should be loaded by now 20:24:34 INFO - GECKO(2420) | MEMORY STAT | vsize 4070MB | residentFast 184MB | heapAllocated 49MB 20:24:34 INFO - TEST-OK | image/test/mochitest/test_bug1180105.html | took 618ms 20:24:34 INFO - TEST-START | image/test/mochitest/test_bug1217571.html 20:24:34 INFO - TEST-PASS | image/test/mochitest/test_bug1217571.html | containers for identical images in different iframes should be identical 20:24:34 INFO - GECKO(2420) | MEMORY STAT | vsize 4070MB | residentFast 185MB | heapAllocated 50MB 20:24:34 INFO - TEST-OK | image/test/mochitest/test_bug1217571.html | took 123ms 20:24:34 INFO - TEST-START | image/test/mochitest/test_bug399925.html 20:24:34 INFO - TEST-PASS | image/test/mochitest/test_bug399925.html | A valid string reason is expected 20:24:34 INFO - TEST-PASS | image/test/mochitest/test_bug399925.html | Reason cannot be empty 20:24:34 INFO - TEST-PASS | image/test/mochitest/test_bug399925.html | Using normal discarding because SurfaceCache expiration is 60000 ms 20:24:34 INFO - TEST-PASS | image/test/mochitest/test_bug399925.html | we got through the drawImage call without an exception being thrown 20:26:28 INFO - TEST-PASS | image/test/mochitest/test_bug399925.html | we got through the drawImage call without an exception being thrown 20:26:28 INFO - TEST-PASS | image/test/mochitest/test_bug399925.html | got different rendered results 20:26:28 INFO - GECKO(2420) | MEMORY STAT | vsize 4254MB | residentFast 179MB | heapAllocated 16MB 20:26:28 INFO - TEST-OK | image/test/mochitest/test_bug399925.html | took 114243ms 20:26:28 INFO - TEST-START | image/test/mochitest/test_bug466586.html 20:26:28 INFO - TEST-PASS | image/test/mochitest/test_bug466586.html | HTML 'big' image width after page onload() 20:26:28 INFO - TEST-PASS | image/test/mochitest/test_bug466586.html | JS 'big' image width before its onload() 20:26:28 INFO - TEST-PASS | image/test/mochitest/test_bug466586.html | JS 'big' image width after its onload() 20:26:28 INFO - GECKO(2420) | MEMORY STAT | vsize 4253MB | residentFast 179MB | heapAllocated 17MB 20:26:28 INFO - TEST-OK | image/test/mochitest/test_bug466586.html | took 103ms 20:26:28 INFO - TEST-START | image/test/mochitest/test_bug468160.html 20:26:28 INFO - TEST-PASS | image/test/mochitest/test_bug468160.html | test passed 20:26:28 INFO - GECKO(2420) | MEMORY STAT | vsize 4253MB | residentFast 179MB | heapAllocated 16MB 20:26:28 INFO - TEST-OK | image/test/mochitest/test_bug468160.html | took 73ms 20:26:28 INFO - TEST-START | image/test/mochitest/test_bug490949.html 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug490949.html | We got the wrong image. 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug490949.html | We got the wrong image. 20:26:29 INFO - GECKO(2420) | MEMORY STAT | vsize 4255MB | residentFast 179MB | heapAllocated 21MB 20:26:29 INFO - TEST-OK | image/test/mochitest/test_bug490949.html | took 185ms 20:26:29 INFO - TEST-START | image/test/mochitest/test_bug496292.html 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug496292.html | The default Accept header used by image loader is correct 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug496292.html | The modified Accept header used by image loader is correct 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug496292.html | The Accept header used by image loader should be correctly reset 20:26:29 INFO - GECKO(2420) | MEMORY STAT | vsize 4257MB | residentFast 180MB | heapAllocated 25MB 20:26:29 INFO - TEST-OK | image/test/mochitest/test_bug496292.html | took 270ms 20:26:29 INFO - TEST-START | image/test/mochitest/test_bug497665.html 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug497665.html | We got different images, but shouldn't have. 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug497665.html | We got different images after a force-reload, but shouldn't have. 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug497665.html | We got the same images after a force-reload. 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug497665.html | We got different images after a reload, but shouldn't have. 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug497665.html | We got the same images after a reload. 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug497665.html | We didn't loop back to the first image. 20:26:29 INFO - GECKO(2420) | MEMORY STAT | vsize 4257MB | residentFast 180MB | heapAllocated 26MB 20:26:29 INFO - TEST-OK | image/test/mochitest/test_bug497665.html | took 186ms 20:26:29 INFO - TEST-START | image/test/mochitest/test_bug552605-1.html 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug552605-1.html | Image should be the same for all loads. 20:26:29 INFO - GECKO(2420) | MEMORY STAT | vsize 4258MB | residentFast 180MB | heapAllocated 27MB 20:26:29 INFO - TEST-OK | image/test/mochitest/test_bug552605-1.html | took 138ms 20:26:29 INFO - TEST-START | image/test/mochitest/test_bug552605-2.html 20:26:29 INFO - TEST-PASS | image/test/mochitest/test_bug552605-2.html | Image should be the same for all loads. 20:26:29 INFO - GECKO(2420) | MEMORY STAT | vsize 4259MB | residentFast 180MB | heapAllocated 28MB 20:26:29 INFO - TEST-OK | image/test/mochitest/test_bug552605-2.html | took 129ms 20:26:29 INFO - TEST-START | image/test/mochitest/test_bug553982.html 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug553982.html | onerror should fire 20:26:30 INFO - GECKO(2420) | MEMORY STAT | vsize 4259MB | residentFast 180MB | heapAllocated 28MB 20:26:30 INFO - TEST-OK | image/test/mochitest/test_bug553982.html | took 122ms 20:26:30 INFO - TEST-START | image/test/mochitest/test_bug601470.html 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug601470.html | we should be using a nonzero amount of memory 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug601470.html | yay, didn't crash! 20:26:30 INFO - GECKO(2420) | MEMORY STAT | vsize 4259MB | residentFast 173MB | heapAllocated 30MB 20:26:30 INFO - TEST-OK | image/test/mochitest/test_bug601470.html | took 146ms 20:26:30 INFO - TEST-START | image/test/mochitest/test_bug614392.html 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug614392.html | yay, our animationMode tweak took effect (and we didn't crash!) 20:26:30 INFO - GECKO(2420) | MEMORY STAT | vsize 4259MB | residentFast 174MB | heapAllocated 30MB 20:26:30 INFO - TEST-OK | image/test/mochitest/test_bug614392.html | took 54ms 20:26:30 INFO - TEST-START | image/test/mochitest/test_bug657191.html 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug657191.html | test passed 20:26:30 INFO - GECKO(2420) | MEMORY STAT | vsize 4259MB | residentFast 175MB | heapAllocated 30MB 20:26:30 INFO - TEST-OK | image/test/mochitest/test_bug657191.html | took 118ms 20:26:30 INFO - TEST-START | image/test/mochitest/test_bug671906.html 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug671906.html | Image should have changed after changing the iframe's src. 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug671906.html | Image should have changed after changing the iframe's src. 20:26:30 INFO - TEST-PASS | image/test/mochitest/test_bug671906.html | Image should be the same on the third load. 20:26:30 INFO - GECKO(2420) | MEMORY STAT | vsize 4259MB | residentFast 177MB | heapAllocated 32MB 20:26:30 INFO - TEST-OK | image/test/mochitest/test_bug671906.html | took 234ms 20:26:30 INFO - TEST-START | image/test/mochitest/test_bug733553.html 20:26:32 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 0 red.png width correct 20:26:34 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 1 animated-gif2.gif width correct 20:26:36 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 2 red.png width correct 20:26:38 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 3 lime100x100.svg width correct 20:26:40 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 4 lime100x100.svg width correct 20:26:42 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 5 animated-gif2.gif width correct 20:26:44 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 6 red.png width correct 20:26:46 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 7 shaver.png width correct 20:26:48 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 8 red.png width correct 20:26:50 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 9 damon.jpg width correct 20:26:52 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 10 damon.jpg width correct 20:26:54 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 11 damon.jpg width correct 20:26:56 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 12 rillybad.jpg width correct 20:26:58 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 13 damon.jpg width correct 20:27:00 INFO - GECKO(2420) | Corrupt JPEG data: 1865 extraneous bytes before marker 0xd9 20:27:00 INFO - GECKO(2420) | Corrupt JPEG data: 1865 extraneous bytes before marker 0xd9 20:27:00 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 14 bad.jpg width correct 20:27:02 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 15 red.png width correct 20:27:04 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 16 invalid.jpg width correct 20:27:06 INFO - TEST-PASS | image/test/mochitest/test_bug733553.html | Test 17 animated-gif2.gif width correct 20:27:06 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 180MB | heapAllocated 22MB 20:27:07 INFO - TEST-OK | image/test/mochitest/test_bug733553.html | took 36300ms 20:27:07 INFO - TEST-START | image/test/mochitest/test_bug767779.html 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug767779.html | A valid string reason is expected 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug767779.html | Reason cannot be empty 20:27:11 INFO - TEST-FAIL | image/test/mochitest/test_bug767779.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug767779.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug767779.html | Reference image should disappear when it becomes display:none 20:27:11 INFO - TEST-FAIL | image/test/mochitest/test_bug767779.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:11 INFO - TEST-FAIL | image/test/mochitest/test_bug767779.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:11 INFO - TEST-FAIL | image/test/mochitest/test_bug767779.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:11 INFO - TEST-FAIL | image/test/mochitest/test_bug767779.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug767779.html | Animated image looks correct, at poll #5 20:27:11 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 180MB | heapAllocated 24MB 20:27:11 INFO - TEST-OK | image/test/mochitest/test_bug767779.html | took 4850ms 20:27:11 INFO - TEST-START | image/test/mochitest/test_bug865919.html 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug865919.html | Request for file succeeded. 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug865919.html | `outstandingCallbacks` should be non-negative. 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug865919.html | Got expected onerror for INT32_MIN.bmp 20:27:11 INFO - TEST-PASS | image/test/mochitest/test_bug865919.html | `outstandingCallbacks` should be non-negative. 20:27:11 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 180MB | heapAllocated 25MB 20:27:11 INFO - TEST-OK | image/test/mochitest/test_bug865919.html | took 97ms 20:27:11 INFO - TEST-START | image/test/mochitest/test_bug89419-1.html 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bug89419-1.html | Image should have changed after the first reload. 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bug89419-1.html | Image should have changed after the second reload. 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bug89419-1.html | Third image should match first image. 20:27:12 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 180MB | heapAllocated 24MB 20:27:12 INFO - TEST-OK | image/test/mochitest/test_bug89419-1.html | took 309ms 20:27:12 INFO - TEST-START | image/test/mochitest/test_bug89419-2.html 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bug89419-2.html | Image should have changed after the first reload. 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bug89419-2.html | Image should have changed after the second reload. 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bug89419-2.html | Third image should match first image. 20:27:12 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 181MB | heapAllocated 25MB 20:27:12 INFO - TEST-OK | image/test/mochitest/test_bug89419-2.html | took 238ms 20:27:12 INFO - TEST-START | image/test/mochitest/test_bullet_animation.html 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bullet_animation.html | A valid string reason is expected 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bullet_animation.html | Reason cannot be empty 20:27:12 INFO - TEST-FAIL | image/test/mochitest/test_bullet_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bullet_animation.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bullet_animation.html | Reference image should disappear when it becomes display:none 20:27:12 INFO - TEST-FAIL | image/test/mochitest/test_bullet_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:12 INFO - TEST-FAIL | image/test/mochitest/test_bullet_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:12 INFO - TEST-PASS | image/test/mochitest/test_bullet_animation.html | Animated image looks correct, at poll #3 20:27:12 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 181MB | heapAllocated 27MB 20:27:12 INFO - TEST-OK | image/test/mochitest/test_bullet_animation.html | took 354ms 20:27:12 INFO - TEST-START | image/test/mochitest/test_changeOfSource.html 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | A valid string reason is expected 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Reason cannot be empty 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Reference image should disappear when it becomes display:none 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Animated image looks correct, at poll #0 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | A valid string reason is expected 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Reason cannot be empty 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Reference image should disappear when it becomes display:none 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource.html | Animated image looks correct, at poll #6 20:27:13 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 181MB | heapAllocated 29MB 20:27:13 INFO - TEST-OK | image/test/mochitest/test_changeOfSource.html | took 339ms 20:27:13 INFO - TEST-START | image/test/mochitest/test_changeOfSource2.html 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource2.html | A valid string reason is expected 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource2.html | Reason cannot be empty 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource2.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource2.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource2.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-FAIL | image/test/mochitest/test_changeOfSource2.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_changeOfSource2.html | Animated image looks correct, at poll #3 20:27:13 INFO - GECKO(2420) | MEMORY STAT | vsize 4261MB | residentFast 181MB | heapAllocated 29MB 20:27:13 INFO - TEST-OK | image/test/mochitest/test_changeOfSource2.html | took 211ms 20:27:13 INFO - TEST-START | image/test/mochitest/test_discardAnimatedImage.html 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got image discard 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got image discard 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got image discard 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got image discard 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | we got through the drawImage call without an exception being thrown 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | drawImage drew something 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:13 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:14 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:15 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:16 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got frame update 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_discardAnimatedImage.html | got expected frame updates 20:27:17 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 30MB 20:27:17 INFO - TEST-OK | image/test/mochitest/test_discardAnimatedImage.html | took 4099ms 20:27:17 INFO - TEST-START | image/test/mochitest/test_drawDiscardedImage.html 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_drawDiscardedImage.html | Same image before and after iframe display:none 20:27:17 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 182MB | heapAllocated 31MB 20:27:17 INFO - TEST-OK | image/test/mochitest/test_drawDiscardedImage.html | took 75ms 20:27:17 INFO - TEST-START | image/test/mochitest/test_error_events.html 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_error_events.html | Got onload for shaver 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_error_events.html | Got onerror for error-early 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_error_events.html | Got page load before all onload/onerror callbacks? 20:27:17 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 28MB 20:27:17 INFO - TEST-OK | image/test/mochitest/test_error_events.html | took 176ms 20:27:17 INFO - TEST-START | image/test/mochitest/test_has_transparency.html 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | A valid string reason is expected 20:27:17 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Reason cannot be empty 20:27:18 INFO - TEST-FAIL | image/test/mochitest/test_has_transparency.html | The author of the test has indicated that flaky timeouts are expected. Reason: Early failure timeout 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/red.png 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was not called for non-transparent file http://mochi.test:8888/tests/image/test/mochitest/red.png 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/transparent.png 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was called for transparent file http://mochi.test:8888/tests/image/test/mochitest/transparent.png 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/red.gif 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was not called for non-transparent file http://mochi.test:8888/tests/image/test/mochitest/red.gif 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/transparent.gif 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was called for transparent file http://mochi.test:8888/tests/image/test/mochitest/transparent.gif 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/first-frame-padding.gif 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was called for transparent file http://mochi.test:8888/tests/image/test/mochitest/first-frame-padding.gif 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/damon.jpg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was not called for non-transparent file http://mochi.test:8888/tests/image/test/mochitest/damon.jpg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/opaque.bmp 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was not called for non-transparent file http://mochi.test:8888/tests/image/test/mochitest/opaque.bmp 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/ico-bmp-opaque.ico 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was called for transparent file http://mochi.test:8888/tests/image/test/mochitest/ico-bmp-opaque.ico 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | Should successfully load http://mochi.test:8888/tests/image/test/mochitest/ico-bmp-transparent.ico 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was called for transparent file http://mochi.test:8888/tests/image/test/mochitest/ico-bmp-transparent.ico 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_has_transparency.html | onHasTransparency was called for transparent file http://mochi.test:8888/tests/image/test/mochitest/lime100x100.svg 20:27:18 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 29MB 20:27:18 INFO - TEST-OK | image/test/mochitest/test_has_transparency.html | took 192ms 20:27:18 INFO - TEST-START | image/test/mochitest/test_image_crossorigin_data_url.html 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_image_crossorigin_data_url.html | Test for handling of 'crossorigin' attribute on CSS link with data: URL - Test for handling of 'crossorigin' attribute on CSS link with data: URL: Elided 2 passes or known failures. 20:27:18 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 29MB 20:27:18 INFO - TEST-OK | image/test/mochitest/test_image_crossorigin_data_url.html | took 137ms 20:27:18 INFO - TEST-START | image/test/mochitest/test_net_failedtoprocess.html 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_net_failedtoprocess.html | wrong topic 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_net_failedtoprocess.html | wrong subject 20:27:18 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 30MB 20:27:18 INFO - TEST-OK | image/test/mochitest/test_net_failedtoprocess.html | took 70ms 20:27:18 INFO - TEST-START | image/test/mochitest/test_removal_ondecode.html 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | A valid string reason is expected 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | Reason cannot be empty 20:27:18 INFO - TEST-FAIL | image/test/mochitest/test_removal_ondecode.html | The author of the test has indicated that flaky timeouts are expected. Reason: Early failure timeout 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/[object%20Object] 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/invalid.jpg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | AfterLoad.onSizeAvailable called for http://mochi.test:8888/tests/image/test/mochitest/lime100x100.svg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | AfterLoad.onDecodeComplete called for http://mochi.test:8888/tests/image/test/mochitest/lime100x100.svg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/lime100x100.svg 20:27:18 INFO - GECKO(2420) | Corrupt JPEG data: 1865 extraneous bytes before marker 0xd9 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/bad.jpg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_ondecode.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/rillybad.jpg 20:27:18 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 31MB 20:27:18 INFO - TEST-OK | image/test/mochitest/test_removal_ondecode.html | took 125ms 20:27:18 INFO - TEST-START | image/test/mochitest/test_removal_onload.html 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | A valid string reason is expected 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | Reason cannot be empty 20:27:18 INFO - TEST-FAIL | image/test/mochitest/test_removal_onload.html | The author of the test has indicated that flaky timeouts are expected. Reason: Early failure timeout 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/[object%20Object] 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/invalid.jpg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | AfterLoad.onSizeAvailable called for http://mochi.test:8888/tests/image/test/mochitest/lime100x100.svg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | AfterLoad.onDecodeComplete called for http://mochi.test:8888/tests/image/test/mochitest/lime100x100.svg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/lime100x100.svg 20:27:18 INFO - GECKO(2420) | Corrupt JPEG data: 1865 extraneous bytes before marker 0xd9 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/bad.jpg 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_removal_onload.html | AfterLoad.onLoadComplete called for http://mochi.test:8888/tests/image/test/mochitest/rillybad.jpg 20:27:18 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 31MB 20:27:18 INFO - TEST-OK | image/test/mochitest/test_removal_onload.html | took 72ms 20:27:18 INFO - TEST-START | image/test/mochitest/test_short_gif_header.html 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_short_gif_header.html | Image loaded. 20:27:18 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 33MB 20:27:18 INFO - TEST-OK | image/test/mochitest/test_short_gif_header.html | took 105ms 20:27:18 INFO - TEST-START | image/test/mochitest/test_staticClone.html 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_staticClone.html | hooray, we didn't crash! 20:27:18 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 33MB 20:27:18 INFO - TEST-OK | image/test/mochitest/test_staticClone.html | took 48ms 20:27:18 INFO - TEST-START | image/test/mochitest/test_svg_animatedGIF.html 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_svg_animatedGIF.html | A valid string reason is expected 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_svg_animatedGIF.html | Reason cannot be empty 20:27:18 INFO - TEST-FAIL | image/test/mochitest/test_svg_animatedGIF.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_svg_animatedGIF.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:27:18 INFO - TEST-PASS | image/test/mochitest/test_svg_animatedGIF.html | Reference image should disappear when it becomes display:none 20:27:18 INFO - TEST-FAIL | image/test/mochitest/test_svg_animatedGIF.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:19 INFO - TEST-PASS | image/test/mochitest/test_svg_animatedGIF.html | Animated image looks correct, at poll #2 20:27:19 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 183MB | heapAllocated 34MB 20:27:19 INFO - TEST-OK | image/test/mochitest/test_svg_animatedGIF.html | took 214ms 20:27:19 INFO - TEST-START | image/test/mochitest/test_svg_filter_animation.html 20:27:19 INFO - TEST-PASS | image/test/mochitest/test_svg_filter_animation.html | A valid string reason is expected 20:27:19 INFO - TEST-PASS | image/test/mochitest/test_svg_filter_animation.html | Reason cannot be empty 20:27:19 INFO - TEST-FAIL | image/test/mochitest/test_svg_filter_animation.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:27:19 INFO - TEST-PASS | image/test/mochitest/test_svg_filter_animation.html | Reference snapshot shouldn't match clean (non-image) snapshot 20:27:19 INFO - TEST-PASS | image/test/mochitest/test_svg_filter_animation.html | Reference image should disappear when it becomes display:none 20:27:19 INFO - TEST-PASS | image/test/mochitest/test_svg_filter_animation.html | Animated image looks correct, at poll #1 20:27:19 INFO - GECKO(2420) | MEMORY STAT | vsize 4264MB | residentFast 184MB | heapAllocated 37MB 20:27:19 INFO - TEST-OK | image/test/mochitest/test_svg_filter_animation.html | took 245ms 20:27:19 INFO - TEST-START | image/test/mochitest/test_undisplayed_iframe.html 20:27:19 INFO - GECKO(2420) | [Parent 2420] WARNING: pipe error: Broken pipe: file /builds/slave/gfx-m64-0000000000000000000000/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 709 20:27:19 INFO - GECKO(2420) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x280080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 20:32:49 INFO - Buffered messages finished 20:32:49 ERROR - TEST-UNEXPECTED-TIMEOUT | image/test/mochitest/test_undisplayed_iframe.html | application timed out after 330 seconds with no output 20:32:49 ERROR - Force-terminating active process(es). 20:32:49 INFO - Determining child pids from psutil 20:32:49 INFO - Found child pids: [2422] 20:32:49 INFO - Killing process: 2422 20:32:49 INFO - Not taking screenshot here: see the one that was previously logged 20:32:49 INFO - psutil found pid 2422 dead 20:32:49 INFO - Killing process: 2420 20:32:49 INFO - Not taking screenshot here: see the one that was previously logged 20:32:49 INFO - TEST-INFO | Main app process: exit 5 20:32:49 INFO - Buffered messages finished 20:32:49 ERROR - TEST-UNEXPECTED-FAIL | image/test/mochitest/test_undisplayed_iframe.html | application terminated with exit code 5 20:32:49 INFO - runtests.py | Application ran for: 0:08:25.796744 20:32:49 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpaeZie_pidlog 20:32:49 INFO - ==> process 2420 launched child process 2421 20:32:49 INFO - ==> process 2420 launched child process 2422 20:32:49 INFO - zombiecheck | Checking for orphan process with PID: 2421 20:32:49 INFO - zombiecheck | Checking for orphan process with PID: 2422 20:32:49 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 20:32:50 INFO - Traceback (most recent call last): 20:32:50 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2521, in doTests 20:32:50 INFO - marionette_args=marionette_args, 20:32:50 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2173, in runApp 20:32:50 INFO - test=self.lastTestSeen) 20:32:50 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 126, in log_crashes 20:32:50 INFO - stackwalk_binary=stackwalk_binary): 20:32:50 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 212, in __iter__ 20:32:50 INFO - rv = self._process_dump_file(path, extra) 20:32:50 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 234, in _process_dump_file 20:32:50 INFO - self._get_symbols() 20:32:50 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 180, in _get_symbols 20:32:50 INFO - data = urllib2.urlopen(self.symbols_path) 20:32:50 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 126, in urlopen 20:32:50 INFO - return _opener.open(url, data, timeout) 20:32:50 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 406, in open 20:32:50 INFO - response = meth(req, response) 20:32:50 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 519, in http_response 20:32:50 INFO - 'http', request, response, code, msg, hdrs) 20:32:50 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 444, in error 20:32:50 INFO - return self._call_chain(*args) 20:32:50 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 378, in _call_chain 20:32:50 INFO - result = func(*args) 20:32:50 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 527, in http_error_default 20:32:50 INFO - raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) 20:32:50 INFO - HTTPError: HTTP Error 404: Not Found 20:32:50 ERROR - Automation Error: Received unexpected exception while running application 20:32:50 ERROR - 20:32:50 INFO - Stopping web server 20:32:50 INFO - Stopping web socket server 20:32:50 INFO - Stopping ssltunnel 20:32:50 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:32:50 INFO - runtests.py | Running tests: end. 20:32:50 INFO - Buffered messages finished 20:32:50 INFO - dir: intl/uconv/tests 20:32:50 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:32:50 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:32:50 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpPikTW9.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:32:50 INFO - runtests.py | Server pid: 2434 20:32:50 INFO - runtests.py | Websocket server pid: 2435 20:32:50 INFO - runtests.py | SSL tunnel pid: 2436 20:32:50 INFO - runtests.py | Running with e10s: True 20:32:50 INFO - runtests.py | Running tests: start. 20:32:50 INFO - 20:32:50 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpPikTW9.mozrunner 20:32:50 INFO - runtests.py | Application pid: 2437 20:32:50 INFO - TEST-INFO | started process GECKO(2437) 20:32:53 INFO - GECKO(2437) | 1497411173725 Marionette INFO Listening on port 2828 20:32:53 INFO - GECKO(2437) | 1497411173890 Marionette DEBUG loaded listener.js 20:32:54 INFO - GECKO(2437) | 2017-06-13 20:32:54.031 plugin-container[2438:32126] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x983f, name = 'com.apple.tsm.portname' 20:32:54 INFO - GECKO(2437) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:32:54 INFO - GECKO(2437) | 2017-06-13 20:32:54.034 plugin-container[2438:32126] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9d0b, name = 'com.apple.CFPasteboardClient' 20:32:54 INFO - GECKO(2437) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:32:54 INFO - GECKO(2437) | 2017-06-13 20:32:54.035 plugin-container[2438:32126] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:32:54 INFO - GECKO(2437) | 2017-06-13 20:32:54.361 plugin-container[2439:32175] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4947, name = 'com.apple.tsm.portname' 20:32:54 INFO - GECKO(2437) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:32:54 INFO - GECKO(2437) | 2017-06-13 20:32:54.362 plugin-container[2439:32175] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x460f, name = 'com.apple.CFPasteboardClient' 20:32:54 INFO - GECKO(2437) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:32:54 INFO - GECKO(2437) | 2017-06-13 20:32:54.362 plugin-container[2439:32175] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:32:54 INFO - SimpleTest START 20:32:54 INFO - TEST-START | intl/uconv/tests/test_big5_encoder.html 20:32:55 INFO - TEST-PASS | intl/uconv/tests/test_big5_encoder.html | Should have gotten the expected encode. 20:32:55 INFO - GECKO(2437) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:32:55 INFO - GECKO(2437) | MEMORY STAT | vsize 3911MB | residentFast 116MB | heapAllocated 21MB 20:32:55 INFO - TEST-OK | intl/uconv/tests/test_big5_encoder.html | took 1133ms 20:32:55 INFO - TEST-START | intl/uconv/tests/test_bug335816.html 20:32:55 INFO - TEST-PASS | intl/uconv/tests/test_bug335816.html | Hidden script not executed 20:32:55 INFO - GECKO(2437) | MEMORY STAT | vsize 3912MB | residentFast 116MB | heapAllocated 22MB 20:32:55 INFO - TEST-OK | intl/uconv/tests/test_bug335816.html | took 48ms 20:32:55 INFO - TEST-START | intl/uconv/tests/test_bug843434.html 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_bug843434.html | Test for no prior assertion. 20:32:56 INFO - GECKO(2437) | MEMORY STAT | vsize 3914MB | residentFast 118MB | heapAllocated 22MB 20:32:56 INFO - TEST-OK | intl/uconv/tests/test_bug843434.html | took 72ms 20:32:56 INFO - TEST-START | intl/uconv/tests/test_bug959058-1.html 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_bug959058-1.html | Should have gotten a hamburger. 20:32:56 INFO - GECKO(2437) | MEMORY STAT | vsize 3914MB | residentFast 119MB | heapAllocated 23MB 20:32:56 INFO - TEST-OK | intl/uconv/tests/test_bug959058-1.html | took 64ms 20:32:56 INFO - TEST-START | intl/uconv/tests/test_bug959058-2.html 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_bug959058-2.html | Should have gotten euro. 20:32:56 INFO - GECKO(2437) | MEMORY STAT | vsize 3915MB | residentFast 120MB | heapAllocated 23MB 20:32:56 INFO - TEST-OK | intl/uconv/tests/test_bug959058-2.html | took 86ms 20:32:56 INFO - TEST-START | intl/uconv/tests/test_long_doc.html 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as Big5 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as Big5-HKSCS 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as EUC-JP 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as EUC-KR 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as gb18030 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as IBM866 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-2022-JP 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-3 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-4 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-5 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-6 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-7 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-8 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-8-I 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-10 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-13 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-14 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-15 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-16 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as ISO-8859-2 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as KOI8-R 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as KOI8-U 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as Shift_JIS 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1250 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1251 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1252 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1253 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1254 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1255 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1256 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1257 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-1258 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as windows-874 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as x-mac-cyrillic 20:32:56 INFO - TEST-PASS | intl/uconv/tests/test_long_doc.html | content decoded as UTF-8 20:32:56 INFO - GECKO(2437) | MEMORY STAT | vsize 3943MB | residentFast 138MB | heapAllocated 34MB 20:32:56 INFO - TEST-OK | intl/uconv/tests/test_long_doc.html | took 656ms 20:32:56 INFO - TEST-START | intl/uconv/tests/test_ncr_fallback.html 20:32:57 INFO - GECKO(2437) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x800017,name=PHttpChannel::Msg_DeleteSelf) Channel error: cannot send/recv 20:32:57 INFO - GECKO(2437) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x280080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 20:38:27 INFO - Buffered messages finished 20:38:27 ERROR - TEST-UNEXPECTED-TIMEOUT | intl/uconv/tests/test_ncr_fallback.html | application timed out after 330 seconds with no output 20:38:27 ERROR - Force-terminating active process(es). 20:38:27 INFO - Determining child pids from psutil 20:38:27 INFO - Found child pids: [2439] 20:38:27 INFO - Killing process: 2439 20:38:27 INFO - Not taking screenshot here: see the one that was previously logged 20:38:27 INFO - psutil found pid 2439 dead 20:38:27 INFO - Killing process: 2437 20:38:27 INFO - Not taking screenshot here: see the one that was previously logged 20:38:27 INFO - TEST-INFO | Main app process: exit 5 20:38:27 INFO - Buffered messages finished 20:38:27 ERROR - TEST-UNEXPECTED-FAIL | intl/uconv/tests/test_ncr_fallback.html | application terminated with exit code 5 20:38:27 INFO - runtests.py | Application ran for: 0:05:36.359419 20:38:27 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpDknHmYpidlog 20:38:27 INFO - ==> process 2437 launched child process 2438 20:38:27 INFO - ==> process 2437 launched child process 2439 20:38:27 INFO - zombiecheck | Checking for orphan process with PID: 2438 20:38:27 INFO - zombiecheck | Checking for orphan process with PID: 2439 20:38:27 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 20:38:28 INFO - Traceback (most recent call last): 20:38:28 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2521, in doTests 20:38:28 INFO - marionette_args=marionette_args, 20:38:28 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2173, in runApp 20:38:28 INFO - test=self.lastTestSeen) 20:38:28 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 126, in log_crashes 20:38:28 INFO - stackwalk_binary=stackwalk_binary): 20:38:28 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 212, in __iter__ 20:38:28 INFO - rv = self._process_dump_file(path, extra) 20:38:28 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 234, in _process_dump_file 20:38:28 INFO - self._get_symbols() 20:38:28 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 180, in _get_symbols 20:38:28 INFO - data = urllib2.urlopen(self.symbols_path) 20:38:28 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 126, in urlopen 20:38:28 INFO - return _opener.open(url, data, timeout) 20:38:28 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 406, in open 20:38:28 INFO - response = meth(req, response) 20:38:28 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 519, in http_response 20:38:28 INFO - 'http', request, response, code, msg, hdrs) 20:38:28 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 444, in error 20:38:28 INFO - return self._call_chain(*args) 20:38:28 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 378, in _call_chain 20:38:28 INFO - result = func(*args) 20:38:28 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 527, in http_error_default 20:38:28 INFO - raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) 20:38:28 INFO - HTTPError: HTTP Error 404: Not Found 20:38:28 ERROR - Automation Error: Received unexpected exception while running application 20:38:28 ERROR - 20:38:28 INFO - Stopping web server 20:38:28 INFO - Stopping web socket server 20:38:28 INFO - Stopping ssltunnel 20:38:28 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:38:28 INFO - runtests.py | Running tests: end. 20:38:28 INFO - Buffered messages finished 20:38:28 INFO - dir: js/xpconnect/tests/mochitest 20:38:28 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:38:28 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:38:28 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpWQrqMj.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:38:28 INFO - runtests.py | Server pid: 2451 20:38:28 INFO - runtests.py | Websocket server pid: 2452 20:38:28 INFO - runtests.py | SSL tunnel pid: 2453 20:38:28 INFO - runtests.py | Running with e10s: True 20:38:28 INFO - runtests.py | Running tests: start. 20:38:28 INFO - 20:38:28 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpWQrqMj.mozrunner 20:38:28 INFO - runtests.py | Application pid: 2454 20:38:28 INFO - TEST-INFO | started process GECKO(2454) 20:38:31 INFO - GECKO(2454) | 1497411511772 Marionette INFO Listening on port 2828 20:38:31 INFO - GECKO(2454) | 2017-06-13 20:38:31.818 plugin-container[2455:32802] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9943, name = 'com.apple.tsm.portname' 20:38:31 INFO - GECKO(2454) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:38:31 INFO - GECKO(2454) | 2017-06-13 20:38:31.821 plugin-container[2455:32802] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4923, name = 'com.apple.CFPasteboardClient' 20:38:31 INFO - GECKO(2454) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:38:31 INFO - GECKO(2454) | 2017-06-13 20:38:31.821 plugin-container[2455:32802] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:38:31 INFO - GECKO(2454) | 1497411511900 Marionette DEBUG loaded listener.js 20:38:32 INFO - GECKO(2454) | 2017-06-13 20:38:32.437 plugin-container[2456:32858] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x963f, name = 'com.apple.tsm.portname' 20:38:32 INFO - GECKO(2454) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:38:32 INFO - GECKO(2454) | 2017-06-13 20:38:32.439 plugin-container[2456:32858] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x990b, name = 'com.apple.CFPasteboardClient' 20:38:32 INFO - GECKO(2454) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:38:32 INFO - GECKO(2454) | 2017-06-13 20:38:32.439 plugin-container[2456:32858] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:38:32 INFO - SimpleTest START 20:38:32 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug1005806.html 20:38:33 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug1005806.html | Controllers property should not appear for content 20:38:33 INFO - GECKO(2454) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:38:33 INFO - GECKO(2454) | MEMORY STAT | vsize 3910MB | residentFast 114MB | heapAllocated 20MB 20:38:33 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug1005806.html | took 1104ms 20:38:33 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug1094930.html 20:38:33 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug1094930.html | createdCallback was called 20:38:33 INFO - GECKO(2454) | MEMORY STAT | vsize 3912MB | residentFast 116MB | heapAllocated 21MB 20:38:33 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug1094930.html | took 61ms 20:38:33 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug1158558.html 20:38:33 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug1158558.html | Do something so the test harness doesn't get angry 20:38:33 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 118MB | heapAllocated 21MB 20:38:33 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug1158558.html | took 123ms 20:38:33 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug384632.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug384632.html | nsIVariant works with regular objects 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug384632.html | nsIVariant works with bizarre objects 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 118MB | heapAllocated 19MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug384632.html | took 55ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug390488.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug390488.html | Stack from walking caller chain should be correct - got " 1. checkForStacks 2. onclick 3. simulateClick", expected a string matching /checkForStacks .* onclick .* simulateClick/ 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug390488.html | Stack from |new Error().stack| should include simulateClick 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 119MB | heapAllocated 20MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug390488.html | took 63ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug393269.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug393269.html | control, getting a property 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug393269.html | can get a property after 1 document.open 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug393269.html | can get a property after 2 document.opens 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3914MB | residentFast 120MB | heapAllocated 20MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug393269.html | took 78ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug396851.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug396851.html | Weird exception thrown 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug396851.html | Able to access the cross-origin document 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 119MB | heapAllocated 17MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug396851.html | took 129ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug428021.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug428021.html | Exception caught: undefined 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug428021.html | Failed to run getter 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug428021.html | Failed to run setter 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 119MB | heapAllocated 18MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug428021.html | took 42ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug446584.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception 0 of type number. Thrown value was 0. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception 1 of type number. Thrown value was 1. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception 3.14 of type number. Thrown value was 3.14. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception roses of type string. Thrown value was roses. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception [object Object] of type object. Thrown value was [object Object]. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception false of type boolean. Thrown value was false. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception true of type boolean. Thrown value was true. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception 1,2,3 of type object. Thrown value was 1,2,3. 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug446584.html | NodeIterator did not properly forward exception function(){} of type function. Thrown value was function(){}. 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 120MB | heapAllocated 18MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug446584.html | took 45ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug462428.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug462428.html | But able to look it up the normal way 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug462428.html | property should still be on the prototype 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug462428.html | property should be enumerable 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug462428.html | the getter actually works 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug462428.html | the getter works after defineSetter 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug462428.html | the setter is bound correctly 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 120MB | heapAllocated 18MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug462428.html | took 44ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug478438.html 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug478438.html | able to resolve/get allAccess property iwin.focus 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug478438.html | able to call allAccess method iwin.focus 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug478438.html | unable to resolve/get restricted property iwin.alert 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug478438.html | unable to call restricted method iwin.alert 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug478438.html | unable to call restricted method iwin.location.toString 20:38:34 INFO - TEST-PASS | js/xpconnect/tests/mochitest/test_bug478438.html | able to set writable property iwin.location 20:38:34 INFO - GECKO(2454) | MEMORY STAT | vsize 3913MB | residentFast 120MB | heapAllocated 20MB 20:38:34 INFO - TEST-OK | js/xpconnect/tests/mochitest/test_bug478438.html | took 118ms 20:38:34 INFO - TEST-START | js/xpconnect/tests/mochitest/test_bug500691.html 20:38:34 INFO - GECKO(2454) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x800017,name=PHttpChannel::Msg_DeleteSelf) Channel error: cannot send/recv 20:38:34 INFO - GECKO(2454) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x280080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 20:44:04 INFO - Buffered messages finished 20:44:04 ERROR - TEST-UNEXPECTED-TIMEOUT | js/xpconnect/tests/mochitest/test_bug500691.html | application timed out after 330 seconds with no output 20:44:04 ERROR - Force-terminating active process(es). 20:44:04 INFO - Determining child pids from psutil 20:44:04 INFO - Found child pids: [2456] 20:44:04 INFO - Killing process: 2456 20:44:04 INFO - Not taking screenshot here: see the one that was previously logged 20:44:04 INFO - psutil found pid 2456 dead 20:44:04 INFO - Killing process: 2454 20:44:04 INFO - Not taking screenshot here: see the one that was previously logged 20:44:05 INFO - TEST-INFO | Main app process: exit 5 20:44:05 INFO - Buffered messages finished 20:44:05 ERROR - TEST-UNEXPECTED-FAIL | js/xpconnect/tests/mochitest/test_bug500691.html | application terminated with exit code 5 20:44:05 INFO - runtests.py | Application ran for: 0:05:36.211560 20:44:05 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpQW_MLlpidlog 20:44:05 INFO - ==> process 2454 launched child process 2455 20:44:05 INFO - ==> process 2454 launched child process 2456 20:44:05 INFO - zombiecheck | Checking for orphan process with PID: 2455 20:44:05 INFO - zombiecheck | Checking for orphan process with PID: 2456 20:44:05 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 20:44:06 INFO - Traceback (most recent call last): 20:44:06 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2521, in doTests 20:44:06 INFO - marionette_args=marionette_args, 20:44:06 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2173, in runApp 20:44:06 INFO - test=self.lastTestSeen) 20:44:06 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 126, in log_crashes 20:44:06 INFO - stackwalk_binary=stackwalk_binary): 20:44:06 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 212, in __iter__ 20:44:06 INFO - rv = self._process_dump_file(path, extra) 20:44:06 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 234, in _process_dump_file 20:44:06 INFO - self._get_symbols() 20:44:06 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 180, in _get_symbols 20:44:06 INFO - data = urllib2.urlopen(self.symbols_path) 20:44:06 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 126, in urlopen 20:44:06 INFO - return _opener.open(url, data, timeout) 20:44:06 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 406, in open 20:44:06 INFO - response = meth(req, response) 20:44:06 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 519, in http_response 20:44:06 INFO - 'http', request, response, code, msg, hdrs) 20:44:06 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 444, in error 20:44:06 INFO - return self._call_chain(*args) 20:44:06 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 378, in _call_chain 20:44:06 INFO - result = func(*args) 20:44:06 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 527, in http_error_default 20:44:06 INFO - raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) 20:44:06 INFO - HTTPError: HTTP Error 404: Not Found 20:44:06 ERROR - Automation Error: Received unexpected exception while running application 20:44:06 ERROR - 20:44:06 INFO - Stopping web server 20:44:06 INFO - Stopping web socket server 20:44:06 INFO - Stopping ssltunnel 20:44:06 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:44:06 INFO - runtests.py | Running tests: end. 20:44:06 INFO - Buffered messages finished 20:44:06 INFO - dir: layout/base/tests 20:44:06 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:44:06 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:44:06 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpQVD9kt.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:44:06 INFO - runtests.py | Server pid: 2467 20:44:06 INFO - runtests.py | Websocket server pid: 2468 20:44:06 INFO - runtests.py | SSL tunnel pid: 2469 20:44:06 INFO - runtests.py | Running with e10s: True 20:44:06 INFO - runtests.py | Running tests: start. 20:44:06 INFO - 20:44:06 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpQVD9kt.mozrunner 20:44:06 INFO - runtests.py | Application pid: 2470 20:44:06 INFO - TEST-INFO | started process GECKO(2470) 20:44:09 INFO - GECKO(2470) | 1497411849314 Marionette INFO Listening on port 2828 20:44:09 INFO - GECKO(2470) | 1497411849472 Marionette DEBUG loaded listener.js 20:44:09 INFO - GECKO(2470) | 2017-06-13 20:44:09.528 plugin-container[2471:33440] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x453f, name = 'com.apple.tsm.portname' 20:44:09 INFO - GECKO(2470) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:44:09 INFO - GECKO(2470) | 2017-06-13 20:44:09.531 plugin-container[2471:33440] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4813, name = 'com.apple.CFPasteboardClient' 20:44:09 INFO - GECKO(2470) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:44:09 INFO - GECKO(2470) | 2017-06-13 20:44:09.531 plugin-container[2471:33440] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:44:10 INFO - GECKO(2470) | 2017-06-13 20:44:10.049 plugin-container[2472:33498] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9743, name = 'com.apple.tsm.portname' 20:44:10 INFO - GECKO(2470) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:44:10 INFO - GECKO(2470) | 2017-06-13 20:44:10.053 plugin-container[2472:33498] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x9c0b, name = 'com.apple.CFPasteboardClient' 20:44:10 INFO - GECKO(2470) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:44:10 INFO - GECKO(2470) | 2017-06-13 20:44:10.053 plugin-container[2472:33498] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:44:10 INFO - SimpleTest START 20:44:10 INFO - TEST-START | layout/base/tests/test_after_paint_pref.html 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | A valid string reason is expected 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | Reason cannot be empty 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | pref defaults to true in mochitest harness 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | loaded 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | step1 reached: boundingClientRect=(top=0,left=0,width=0,height=undefined) 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | step2 reached: boundingClientRect=(top=0,left=0,width=0,height=undefined) 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | got MozAfterPaint (timeout for next step is 900ms) 20:44:11 INFO - TEST-PASS | layout/base/tests/test_after_paint_pref.html | step3 reached 20:44:11 INFO - TEST-FAIL | layout/base/tests/test_after_paint_pref.html | The author of the test has indicated that flaky timeouts are expected. Reason: untriaged 20:44:11 INFO - GECKO(2470) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x280080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 20:49:41 INFO - Buffered messages finished 20:49:41 ERROR - TEST-UNEXPECTED-TIMEOUT | layout/base/tests/test_after_paint_pref.html | application timed out after 330 seconds with no output 20:49:41 ERROR - Force-terminating active process(es). 20:49:41 INFO - Determining child pids from psutil 20:49:41 INFO - Found child pids: [2472] 20:49:41 INFO - Killing process: 2472 20:49:41 INFO - Not taking screenshot here: see the one that was previously logged 20:49:41 INFO - psutil found pid 2472 dead 20:49:41 INFO - Killing process: 2470 20:49:41 INFO - Not taking screenshot here: see the one that was previously logged 20:49:41 INFO - TEST-INFO | Main app process: exit 5 20:49:41 INFO - Buffered messages finished 20:49:41 ERROR - TEST-UNEXPECTED-FAIL | layout/base/tests/test_after_paint_pref.html | application terminated with exit code 5 20:49:41 INFO - runtests.py | Application ran for: 0:05:35.077930 20:49:41 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpceJre9pidlog 20:49:41 INFO - ==> process 2470 launched child process 2471 20:49:41 INFO - ==> process 2470 launched child process 2472 20:49:41 INFO - zombiecheck | Checking for orphan process with PID: 2471 20:49:41 INFO - zombiecheck | Checking for orphan process with PID: 2472 20:49:41 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 20:49:42 INFO - Traceback (most recent call last): 20:49:42 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2521, in doTests 20:49:42 INFO - marionette_args=marionette_args, 20:49:42 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2173, in runApp 20:49:42 INFO - test=self.lastTestSeen) 20:49:42 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 126, in log_crashes 20:49:42 INFO - stackwalk_binary=stackwalk_binary): 20:49:42 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 212, in __iter__ 20:49:42 INFO - rv = self._process_dump_file(path, extra) 20:49:42 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 234, in _process_dump_file 20:49:42 INFO - self._get_symbols() 20:49:42 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 180, in _get_symbols 20:49:42 INFO - data = urllib2.urlopen(self.symbols_path) 20:49:42 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 126, in urlopen 20:49:42 INFO - return _opener.open(url, data, timeout) 20:49:42 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 406, in open 20:49:42 INFO - response = meth(req, response) 20:49:42 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 519, in http_response 20:49:42 INFO - 'http', request, response, code, msg, hdrs) 20:49:42 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 444, in error 20:49:42 INFO - return self._call_chain(*args) 20:49:42 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 378, in _call_chain 20:49:42 INFO - result = func(*args) 20:49:42 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 527, in http_error_default 20:49:42 INFO - raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) 20:49:42 INFO - HTTPError: HTTP Error 404: Not Found 20:49:42 ERROR - Automation Error: Received unexpected exception while running application 20:49:42 ERROR - 20:49:42 INFO - Stopping web server 20:49:42 INFO - Stopping web socket server 20:49:42 INFO - Stopping ssltunnel 20:49:42 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:49:42 INFO - runtests.py | Running tests: end. 20:49:42 INFO - Buffered messages finished 20:49:42 INFO - dir: layout/forms/test 20:49:42 INFO - mozprofile.addons WARNING | Could not install /builds/slave/test/build/tests/mochitest/extensions/mozscreenshots: [Errno 2] No such file or directory: '/builds/slave/test/build/tests/mochitest/extensions/mozscreenshots/install.rdf' 20:49:43 INFO - pk12util: PKCS12 IMPORT SUCCESSFUL 20:49:43 INFO - MochitestServer : launching [u'/builds/slave/test/build/tests/bin/xpcshell', '-g', '/builds/slave/test/build/application/Nightly.app/Contents/Resources', '-v', '170', '-f', '/builds/slave/test/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpYStVfY.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/slave/test/build/tests/mochitest/server.js'] 20:49:43 INFO - runtests.py | Server pid: 2483 20:49:43 INFO - runtests.py | Websocket server pid: 2484 20:49:43 INFO - runtests.py | SSL tunnel pid: 2485 20:49:43 INFO - runtests.py | Running with e10s: True 20:49:43 INFO - runtests.py | Running tests: start. 20:49:43 INFO - 20:49:43 INFO - Application command: /builds/slave/test/build/application/Nightly.app/Contents/MacOS/firefox -marionette -foreground -profile /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpYStVfY.mozrunner 20:49:43 INFO - runtests.py | Application pid: 2486 20:49:43 INFO - TEST-INFO | started process GECKO(2486) 20:49:46 INFO - GECKO(2486) | 1497412186370 Marionette INFO Listening on port 2828 20:49:46 INFO - GECKO(2486) | 2017-06-13 20:49:46.390 plugin-container[2487:34028] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x983f, name = 'com.apple.tsm.portname' 20:49:46 INFO - GECKO(2486) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:49:46 INFO - GECKO(2486) | 2017-06-13 20:49:46.393 plugin-container[2487:34028] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x4917, name = 'com.apple.CFPasteboardClient' 20:49:46 INFO - GECKO(2486) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:49:46 INFO - GECKO(2486) | 2017-06-13 20:49:46.393 plugin-container[2487:34028] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:49:46 INFO - GECKO(2486) | 1497412186505 Marionette DEBUG loaded listener.js 20:49:47 INFO - GECKO(2486) | 2017-06-13 20:49:47.050 plugin-container[2488:34083] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x973f, name = 'com.apple.tsm.portname' 20:49:47 INFO - GECKO(2486) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:49:47 INFO - GECKO(2486) | 2017-06-13 20:49:47.051 plugin-container[2488:34083] *** CFMessagePort: bootstrap_register(): failed 1100 (0x44c) 'Permission denied', port = 0x471b, name = 'com.apple.CFPasteboardClient' 20:49:47 INFO - GECKO(2486) | See /usr/include/servers/bootstrap_defs.h for the error codes. 20:49:47 INFO - GECKO(2486) | 2017-06-13 20:49:47.051 plugin-container[2488:34083] Failed to allocate communication port for com.apple.CFPasteboardClient; this is likely due to sandbox restrictions 20:49:47 INFO - SimpleTest START 20:49:47 INFO - TEST-START | layout/forms/test/test_bug1111995.html 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1111995.html | click events outside border with radius 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1111995.html | click events on border with radius 20:49:48 INFO - GECKO(2486) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration. 20:49:48 INFO - GECKO(2486) | MEMORY STAT | vsize 3910MB | residentFast 116MB | heapAllocated 21MB 20:49:48 INFO - TEST-OK | layout/forms/test/test_bug1111995.html | took 1188ms 20:49:48 INFO - TEST-START | layout/forms/test/test_bug1301290.html 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1301290.html | width did not increase 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1301290.html | height did not increase 20:49:48 INFO - GECKO(2486) | MEMORY STAT | vsize 3918MB | residentFast 119MB | heapAllocated 22MB 20:49:48 INFO - TEST-OK | layout/forms/test/test_bug1301290.html | took 76ms 20:49:48 INFO - TEST-START | layout/forms/test/test_bug1305282.html 20:49:48 INFO - must wait for load 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1305282.html | 'b a r' option is selected 20:49:48 INFO - GECKO(2486) | MEMORY STAT | vsize 3920MB | residentFast 122MB | heapAllocated 24MB 20:49:48 INFO - TEST-OK | layout/forms/test/test_bug1305282.html | took 124ms 20:49:48 INFO - TEST-START | layout/forms/test/test_bug1327129.html 20:49:48 INFO - must wait for load 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: SHIFT+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: CTRL+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: CTRL+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: CTRL+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: CTRL+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: CTRL+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: CTRL+DOWN selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: CTRL+DOWN did NOT select first any option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: CTRL+DOWN did NOT select first any option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: CTRL+DOWN did NOT select first any option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: CTRL+DOWN did NOT select first any option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: CTRL+DOWN did NOT select first any option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: CTRL+DOWN did NOT select first any option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: CTRL+SPACE selected first non-disabled option 20:49:48 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 13: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 14: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 15: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 16: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 17: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 18: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 19: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 20: CTRL+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: CTRL+SHIFT+DOWN selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 1: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 2: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 3: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 4: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 5: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 6: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 7: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 8: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 9: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 10: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 11: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 12: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 13: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 14: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 15: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 16: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 17: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 18: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 19: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug1327129.html | element 20: CTRL+SHIFT+SPACE selected first non-disabled option 20:49:49 INFO - GECKO(2486) | MEMORY STAT | vsize 3923MB | residentFast 127MB | heapAllocated 27MB 20:49:49 INFO - TEST-OK | layout/forms/test/test_bug1327129.html | took 944ms 20:49:49 INFO - TEST-START | layout/forms/test/test_bug231389.html 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug231389.html | The textarea should not be scrolled initially 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug231389.html | The textarea's insertion point should be scrolled into view 20:49:49 INFO - GECKO(2486) | MEMORY STAT | vsize 3932MB | residentFast 137MB | heapAllocated 29MB 20:49:49 INFO - TEST-OK | layout/forms/test/test_bug231389.html | took 56ms 20:49:49 INFO - TEST-START | layout/forms/test/test_bug287446.html 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | test is not testing cross-site 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | Shouldn't be able to access cross-site 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | toggling display failed 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | toggling display back failed 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | Shouldn't have lost our initial value 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | Typing should work 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | toggling display second time failed 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | toggling display back second time failed 20:49:49 INFO - TEST-PASS | layout/forms/test/test_bug287446.html | Unexpected message 20:49:49 INFO - GECKO(2486) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x280080,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv 20:55:19 INFO - Buffered messages finished 20:55:19 ERROR - TEST-UNEXPECTED-TIMEOUT | layout/forms/test/test_bug287446.html | application timed out after 330 seconds with no output 20:55:19 ERROR - Force-terminating active process(es). 20:55:19 INFO - Determining child pids from psutil 20:55:19 INFO - Found child pids: [2488] 20:55:19 INFO - Killing process: 2488 20:55:19 INFO - Not taking screenshot here: see the one that was previously logged 20:55:20 INFO - psutil found pid 2488 dead 20:55:20 INFO - Killing process: 2486 20:55:20 INFO - Not taking screenshot here: see the one that was previously logged 20:55:20 INFO - TEST-INFO | Main app process: exit 5 20:55:20 INFO - Buffered messages finished 20:55:20 ERROR - TEST-UNEXPECTED-FAIL | layout/forms/test/test_bug287446.html | application terminated with exit code 5 20:55:20 INFO - runtests.py | Application ran for: 0:05:36.741810 20:55:20 INFO - zombiecheck | Reading PID log: /var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/tmpSeOQVdpidlog 20:55:20 INFO - ==> process 2486 launched child process 2487 20:55:20 INFO - ==> process 2486 launched child process 2488 20:55:20 INFO - zombiecheck | Checking for orphan process with PID: 2487 20:55:20 INFO - zombiecheck | Checking for orphan process with PID: 2488 20:55:20 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/target.crashreporter-symbols.zip 20:55:21 INFO - Traceback (most recent call last): 20:55:21 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2521, in doTests 20:55:21 INFO - marionette_args=marionette_args, 20:55:21 INFO - File "/builds/slave/test/build/tests/mochitest/runtests.py", line 2173, in runApp 20:55:21 INFO - test=self.lastTestSeen) 20:55:21 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 126, in log_crashes 20:55:21 INFO - stackwalk_binary=stackwalk_binary): 20:55:21 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 212, in __iter__ 20:55:21 INFO - rv = self._process_dump_file(path, extra) 20:55:21 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 234, in _process_dump_file 20:55:21 INFO - self._get_symbols() 20:55:21 INFO - File "/builds/slave/test/build/venv/lib/python2.7/site-packages/mozcrash/mozcrash.py", line 180, in _get_symbols 20:55:21 INFO - data = urllib2.urlopen(self.symbols_path) 20:55:21 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 126, in urlopen 20:55:21 INFO - return _opener.open(url, data, timeout) 20:55:21 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 406, in open 20:55:21 INFO - response = meth(req, response) 20:55:21 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 519, in http_response 20:55:21 INFO - 'http', request, response, code, msg, hdrs) 20:55:21 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 444, in error 20:55:21 INFO - return self._call_chain(*args) 20:55:21 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 378, in _call_chain 20:55:21 INFO - result = func(*args) 20:55:21 INFO - File "/tools/python27/lib/python2.7/urllib2.py", line 527, in http_error_default 20:55:21 INFO - raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) 20:55:21 INFO - HTTPError: HTTP Error 404: Not Found 20:55:21 ERROR - Automation Error: Received unexpected exception while running application 20:55:21 ERROR - 20:55:21 INFO - Stopping web server 20:55:21 INFO - Stopping web socket server 20:55:21 INFO - Stopping ssltunnel 20:55:21 WARNING - leakcheck | refcount logging is off, so leaks can't be detected! 20:55:21 INFO - runtests.py | Running tests: end. 20:55:21 INFO - Buffered messages finished 20:55:21 INFO - 0 INFO TEST-START | Shutdown 20:55:21 INFO - 1 INFO Passed: 4492 20:55:21 INFO - 2 INFO Failed: 0 20:55:21 INFO - 3 INFO Todo: 27 20:55:21 INFO - 4 INFO Mode: e10s 20:55:21 INFO - 5 INFO SimpleTest FINISHED 20:55:21 INFO - Buffered messages finished 20:55:21 INFO - SUITE-END | took 5880s 20:55:21 ERROR - Return code: 1 20:55:21 INFO - TinderboxPrint: mochitest-plain-chunked
5474/1/150 20:55:21 ERROR - # TBPL FAILURE # 20:55:21 WARNING - setting return code to 2 20:55:21 ERROR - The mochitest suite: plain-chunked ran with return status: FAILURE 20:55:21 INFO - Running post-action listener: _package_coverage_data 20:55:21 INFO - Running post-action listener: _resource_record_post_action 20:55:21 INFO - [mozharness: 2017-06-14 03:55:21.401415Z] Finished run-tests step (success) 20:55:21 INFO - Running post-run listener: _resource_record_post_run 20:55:21 INFO - Validating Perfherder data against /builds/slave/test/scripts/external_tools/performance-artifact-schema.json 20:55:21 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"subtests": [{"name": "cpu_percent", "value": 36.81495426054556}, {"name": "io_write_bytes", "value": 1477955584}, {"name": "io.read_bytes", "value": 19554304}, {"name": "io_write_time", "value": 7164}, {"name": "io_read_time", "value": 117}], "extraOptions": ["e10s", "buildbot-unknown"], "name": "mochitest.plain-chunked.4.overall"}, {"subtests": [{"name": "time", "value": 21.92164182662964}, {"name": "cpu_percent", "value": 54.026250000000005}], "name": "mochitest.plain-chunked.4.install"}, {"subtests": [{"name": "time", "value": 0.00031495094299316406}], "name": "mochitest.plain-chunked.4.stage-files"}, {"subtests": [{"name": "time", "value": 5883.510246992111}, {"name": "cpu_percent", "value": 36.75044635266119}], "name": "mochitest.plain-chunked.4.run-tests"}]} 20:55:21 INFO - Total resource usage - Wall time: 5905s; CPU: 37.0%; Read bytes: 19554304; Write bytes: 1477955584; Read time: 117; Write time: 7164 20:55:21 INFO - TinderboxPrint: CPU usage
36.8% 20:55:21 INFO - TinderboxPrint: I/O read bytes / time
19,554,304 / 117 20:55:21 INFO - TinderboxPrint: I/O write bytes / time
1,477,955,584 / 7,164 20:55:21 INFO - TinderboxPrint: CPU idle
14,924.0 (63.2%) 20:55:21 INFO - TinderboxPrint: CPU system
5,404.5 (22.9%) 20:55:21 INFO - TinderboxPrint: CPU user
3,291.4 (13.9%) 20:55:21 INFO - TinderboxPrint: Swap in / out
268,591,104 / 0 20:55:21 INFO - install - Wall time: 22s; CPU: 54.0%; Read bytes: 227017216; Write bytes: 221079040; Read time: 16806; Write time: 461 20:55:21 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0 20:55:21 INFO - run-tests - Wall time: 5884s; CPU: 37.0%; Read bytes: 19013632; Write bytes: 1228564992; Read time: 115; Write time: 6626 20:55:23 INFO - Running post-run listener: _upload_blobber_files 20:55:23 INFO - Blob upload gear active. 20:55:23 INFO - Preparing to upload files from /builds/slave/test/build/blobber_upload_dir. 20:55:23 INFO - Files from /builds/slave/test/build/blobber_upload_dir are to be uploaded withbranch at the following location(s): https://blobupload.elasticbeanstalk.com 20:55:23 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', 'graphics', '-d', '/builds/slave/test/build/blobber_upload_dir', '--output-manifest', '/builds/slave/test/build/uploaded_files.json'] 20:55:23 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 graphics -d /builds/slave/test/build/blobber_upload_dir --output-manifest /builds/slave/test/build/uploaded_files.json 20:55:24 INFO - (blobuploader) - INFO - Open directory for files ... 20:55:24 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/manifests.list ... 20:55:24 INFO - (blobuploader) - INFO - Skipped /builds/slave/test/build/blobber_upload_dir/manifests.list. File type not allowed on server. 20:55:24 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/mozilla-test-fail-screenshot__LAq7H.png ... 20:55:24 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 20:55:24 INFO - (blobuploader) - INFO - Uploading, attempt #1. 20:55:26 INFO - (blobuploader) - INFO - TinderboxPrint: mozilla-test-fail-screenshot__LAq7H.png: uploaded 20:55:26 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 20:55:26 INFO - (blobuploader) - INFO - Done attempting. 20:55:26 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/plain-chunked_errorsummary.log ... 20:55:26 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 20:55:26 INFO - (blobuploader) - INFO - Uploading, attempt #1. 20:55:27 INFO - (blobuploader) - INFO - TinderboxPrint: plain-chunked_errorsummary.log: uploaded 20:55:27 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 20:55:27 INFO - (blobuploader) - INFO - Done attempting. 20:55:27 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/plain-chunked_raw.log ... 20:55:27 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 20:55:27 INFO - (blobuploader) - INFO - Uploading, attempt #1. 20:55:28 INFO - (blobuploader) - INFO - TinderboxPrint: plain-chunked_raw.log: uploaded 20:55:28 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 20:55:28 INFO - (blobuploader) - INFO - Done attempting. 20:55:28 INFO - (blobuploader) - INFO - Uploading /builds/slave/test/build/blobber_upload_dir/resource-usage.json ... 20:55:28 INFO - (blobuploader) - INFO - Using https://blobupload.elasticbeanstalk.com 20:55:28 INFO - (blobuploader) - INFO - Uploading, attempt #1. 20:55:33 INFO - (blobuploader) - INFO - TinderboxPrint: resource-usage.json: uploaded 20:55:33 INFO - (blobuploader) - INFO - Blobserver returned 202. File uploaded! 20:55:33 INFO - (blobuploader) - INFO - Done attempting. 20:55:33 INFO - (blobuploader) - INFO - Iteration through files over. 20:55:33 INFO - Return code: 0 20:55:33 INFO - rmtree: /builds/slave/test/build/uploaded_files.json 20:55:33 INFO - retry: Calling remove with args: ('/builds/slave/test/build/uploaded_files.json',), kwargs: {}, attempt #1 20:55:33 INFO - Setting buildbot property blobber_files to {"mozilla-test-fail-screenshot__LAq7H.png": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/7ca135aa9d984a1a124e42875aa41d885aaae9ab5e396c15c1ddf856eb594a849e7c666559978fa9727920ee888cd27dbf364a31b766bb5c939e9d7a648e624d", "plain-chunked_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/04fb2c50c2eac69b4f0b4d7f5163aabe1a0c9b51f6fa0deb51f64c7b583bf722bceb90b7ab8fa64696245c2fca5726fb8917e0bf763577a710af8ca7ab4eed51", "manifests.list": null, "plain-chunked_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/d68fb50bdbe6d8acdc083c6075b6a6db98fbbb92aaceae1c60555e99d15cca5b6fd9e77db348aee02ca8bc0f39730b2971710ee8dae5f0930b0b11d7eb251747", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/106dd05468fa836fcaa45fe4bf1c21e4dbb45a4e9e58708754e264ef19f7b57a70911421318da10ac54e989e52d09de6b1ed610c51ea749a0c849313661041a4"} 20:55:33 INFO - Writing buildbot properties ['blobber_files'] to /builds/slave/test/properties/blobber_files 20:55:33 INFO - Writing to file /builds/slave/test/properties/blobber_files 20:55:33 INFO - Contents: 20:55:33 INFO - blobber_files:{"mozilla-test-fail-screenshot__LAq7H.png": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/7ca135aa9d984a1a124e42875aa41d885aaae9ab5e396c15c1ddf856eb594a849e7c666559978fa9727920ee888cd27dbf364a31b766bb5c939e9d7a648e624d", "plain-chunked_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/04fb2c50c2eac69b4f0b4d7f5163aabe1a0c9b51f6fa0deb51f64c7b583bf722bceb90b7ab8fa64696245c2fca5726fb8917e0bf763577a710af8ca7ab4eed51", "manifests.list": null, "plain-chunked_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/d68fb50bdbe6d8acdc083c6075b6a6db98fbbb92aaceae1c60555e99d15cca5b6fd9e77db348aee02ca8bc0f39730b2971710ee8dae5f0930b0b11d7eb251747", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/106dd05468fa836fcaa45fe4bf1c21e4dbb45a4e9e58708754e264ef19f7b57a70911421318da10ac54e989e52d09de6b1ed610c51ea749a0c849313661041a4"} 20:55:33 INFO - Running post-run listener: copy_logs_to_upload_dir 20:55:33 INFO - Copying logs to upload dir... 20:55:33 INFO - mkdir: /builds/slave/test/build/upload/logs 20:55:33 INFO - Copying logs to upload dir... 20:55:33 WARNING - returning nonzero exit status 2 program finished with exit code 2 elapsedTime=5992.012485 ========= master_lag: 0.18 ========= ========= Finished '/tools/buildbot/bin/python -u ...' failed (results: 2, elapsed: 1 hrs, 39 mins, 52 secs) (at 2017-06-13 20:55:33.751009) ========= ========= Started set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-06-13 20:55:33.756001) ========= 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: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.Us01N6b4Wi/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test/properties RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners TMPDIR=/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False blobber_files:{"mozilla-test-fail-screenshot__LAq7H.png": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/7ca135aa9d984a1a124e42875aa41d885aaae9ab5e396c15c1ddf856eb594a849e7c666559978fa9727920ee888cd27dbf364a31b766bb5c939e9d7a648e624d", "plain-chunked_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/04fb2c50c2eac69b4f0b4d7f5163aabe1a0c9b51f6fa0deb51f64c7b583bf722bceb90b7ab8fa64696245c2fca5726fb8917e0bf763577a710af8ca7ab4eed51", "manifests.list": null, "plain-chunked_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/d68fb50bdbe6d8acdc083c6075b6a6db98fbbb92aaceae1c60555e99d15cca5b6fd9e77db348aee02ca8bc0f39730b2971710ee8dae5f0930b0b11d7eb251747", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/106dd05468fa836fcaa45fe4bf1c21e4dbb45a4e9e58708754e264ef19f7b57a70911421318da10ac54e989e52d09de6b1ed610c51ea749a0c849313661041a4"} build_url:https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg program finished with exit code 0 elapsedTime=0.011218 build_url: 'https://queue.taskcluster.net/v1/task/S9Ns3CFNSWyKVBvfR9ry8g/artifacts/public/build/firefox-55.0a1.en-US.mac.dmg' blobber_files: '{"mozilla-test-fail-screenshot__LAq7H.png": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/7ca135aa9d984a1a124e42875aa41d885aaae9ab5e396c15c1ddf856eb594a849e7c666559978fa9727920ee888cd27dbf364a31b766bb5c939e9d7a648e624d", "plain-chunked_raw.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/04fb2c50c2eac69b4f0b4d7f5163aabe1a0c9b51f6fa0deb51f64c7b583bf722bceb90b7ab8fa64696245c2fca5726fb8917e0bf763577a710af8ca7ab4eed51", "manifests.list": null, "plain-chunked_errorsummary.log": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/d68fb50bdbe6d8acdc083c6075b6a6db98fbbb92aaceae1c60555e99d15cca5b6fd9e77db348aee02ca8bc0f39730b2971710ee8dae5f0930b0b11d7eb251747", "resource-usage.json": "http://mozilla-releng-blobs.s3.amazonaws.com/blobs/graphics/sha512/106dd05468fa836fcaa45fe4bf1c21e4dbb45a4e9e58708754e264ef19f7b57a70911421318da10ac54e989e52d09de6b1ed610c51ea749a0c849313661041a4"}' ========= master_lag: 0.03 ========= ========= Finished set props: build_url blobber_files (results: 0, elapsed: 0 secs) (at 2017-06-13 20:55:33.798984) ========= ========= Started 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-06-13 20:55:33.799319) ========= rm -f oauth.txt in dir /builds/slave/test/. (timeout 1200 secs) watching logfiles {} argv: ['rm', '-f', 'oauth.txt'] environment: Apple_PubSub_Socket_Render=/private/tmp/com.apple.launchd.Us01N6b4Wi/Render GIT_SHARE_BASE_DIR=/builds/git-shared HG_SHARE_BASE_DIR=/builds/hg-shared HOME=/Users/cltbld IDLEIZER_DISABLE_SHUTDOWN=true LOGNAME=cltbld PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/bin/X11 PWD=/builds/slave/test RUNNER_CONFIG_CMD=/opt/runner/bin/python2.7 /opt/runner/bin/runner -c /opt/runner/runner.cfg SHELL=/bin/bash SSH_AUTH_SOCK=/private/tmp/com.apple.launchd.Nj1ubDzMy5/Listeners TMPDIR=/var/folders/xm/n27ws1sd1t3406fsw7fnw23r00000w/T/ TWISTD_LOG_PATH=/builds/slave/twistd.log USER=cltbld VERSIONER_PYTHON_PREFER_32_BIT=no VERSIONER_PYTHON_VERSION=2.7 XPC_FLAGS=0x0 XPC_SERVICE_NAME=0 __CF_USER_TEXT_ENCODING=0x1C:0:0 using PTY: False program finished with exit code 0 elapsedTime=0.005310 ========= master_lag: 0.04 ========= ========= Finished 'rm -f ...' (results: 0, elapsed: 0 secs) (at 2017-06-13 20:55:33.847347) ========= ========= Started reboot skipped (results: 3, elapsed: 0 secs) (at 2017-06-13 20:55:33.850704) ========= ========= Finished reboot skipped (results: 3, elapsed: 0 secs) (at 2017-06-13 20:55:33.851022) ========= ========= Total master_lag: 0.52 =========