Intermittent browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | Test timed out -
Categories
(WebExtensions :: General, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: btara [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=185800098&repo=autoland https://queue.taskcluster.net/v1/task/IByQl4t-S8a7aYSbQVCqVQ/runs/0/artifacts/public/logs/live_backing.log 23:33:06 INFO - 534 INFO TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js 23:33:06 INFO - GECKO(5472) | [Parent 5472, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 23:33:06 INFO - GECKO(5472) | [Child 5664, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 23:33:51 INFO - TEST-INFO | started process screenshot 23:33:51 INFO - TEST-INFO | screenshot: exit 0 23:33:51 INFO - Buffered messages logged at 23:33:06 23:33:51 INFO - 535 INFO Entering test bound test_slow_content_script 23:33:51 INFO - 536 INFO Extension loaded 23:33:51 INFO - 537 INFO Console message: Warning: attempting to write 16053 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes. 23:33:51 INFO - 538 INFO Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/FileUtils.jsm" line: 170}] 23:33:51 INFO - Buffered messages finished 23:33:51 ERROR - 539 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | Test timed out - 23:33:51 INFO - Not taking screenshot here: see the one that was previously logged 23:33:51 ERROR - 540 INFO TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | Extension left running at test shutdown - 23:33:51 INFO - Stack trace: 23:33:51 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109 23:33:51 INFO - chrome://mochikit/content/browser-test.js:nextTest:699 23:33:51 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1195 23:33:51 INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1157 23:33:51 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:991 23:33:51 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:795 23:33:59 INFO - 541 INFO Console message: [JavaScript Error: "Timeout while waiting for extension child to shutdown: "Slow Script Extension" (ID: 0f0f10d070fefa9aa127ae75a220ea0cd0cd1b5f@temporary-addon, moz-extension://64f50575-2a52-4a88-87bf-88fa3f48e16d/)" {file: "resource://gre/modules/Extension.jsm" line: 1832}] 23:33:59 INFO - shutdown@resource://gre/modules/Extension.jsm:1832:7 23:33:59 INFO - async*shutdown@resource://gre/modules/Extension.jsm:1195:18 23:33:59 INFO - callBootstrapMethod@resource://gre/modules/addons/XPIProvider.jsm:1588:20 23:33:59 INFO - async*_shutdown@resource://gre/modules/addons/XPIProvider.jsm:1724:12 23:33:59 INFO - async*shutdown@resource://gre/modules/addons/XPIProvider.jsm:1717:28 23:33:59 INFO - async*_uninstall@resource://gre/modules/addons/XPIProvider.jsm:1802:13 23:33:59 INFO - async*uninstall@resource://gre/modules/addons/XPIProvider.jsm:1797:12 23:33:59 INFO - uninstallAddon@resource://gre/modules/addons/XPIInstall.jsm:3993:15 23:33:59 INFO - async*uninstall@resource://gre/modules/addons/XPIDatabase.jsm:1012:12 23:33:59 INFO - async*shutdown@resource://testing-common/ExtensionTestCommon.jsm:151:5 23:33:59 INFO - _receiveMessageAPI@chrome://mochikit/content/tests/SimpleTest/SpecialPowersObserverAPI.js:647:9 23:33:59 INFO - ChromePowers.prototype._receiveMessage@chrome://mochikit/content/tests/SimpleTest/ChromePowers.js:83:14 23:33:59 INFO - ChromePowers.prototype._sendAsyncMessage@chrome://mochikit/content/tests/SimpleTest/ChromePowers.js:45:3 23:33:59 INFO - unload@chrome://mochikit/content/tests/SimpleTest/specialpowersAPI.js:2043:9 23:33:59 INFO - ExtensionTestUtils.loadExtension/<@chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:110:14 23:33:59 INFO - nextTest@chrome://mochikit/content/browser-test.js:699:30 23:33:59 INFO - async*timeoutFn@chrome://mochikit/content/browser-test.js:1195:9 23:33:59 INFO - setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:1157:9 23:33:59 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:991:9 23:33:59 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:795:59 23:33:59 INFO - 542 INFO Console message: Warning: attempting to write 15955 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes. 23:40:09 INFO - Buffered messages finished 23:40:09 WARNING - TEST-UNEXPECTED-TIMEOUT | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | application timed out after 370 seconds with no output 23:40:09 INFO - 543 ERROR Force-terminating active process(es). 23:40:09 INFO - Determining child pids from psutil... 23:40:09 INFO - [2536, 3656, 2404, 4248, 6100, 2708] 23:40:09 INFO - ==> process 5472 launched child process 1188 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.0.2081002330\53179654" -childID 1 -isForBrowser -prefsHandle 1764 -prefsLen 16366 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 1804 tab) 23:40:09 INFO - ==> process 5472 launched child process 2404 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.6.1372630678\1871162962" -childID 2 -isForBrowser -prefsHandle 2152 -prefsLen 16366 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 2164 tab) 23:40:09 INFO - ==> process 5472 launched child process 2536 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.12.1501379370\1724034585" -childID 3 -isForBrowser -prefsHandle 1784 -prefsLen 17676 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 2392 tab) 23:40:09 INFO - ==> process 5472 launched child process 3656 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.18.196358396\1733018084" -childID 4 -isForBrowser -prefsHandle 3008 -prefsLen 22655 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 2888 tab) 23:40:09 INFO - ==> process 5472 launched child process 5664 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.24.966870875\1482341648" -childID 5 -isForBrowser -prefsHandle 3276 -prefsLen 22656 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 2984 tab) 23:40:09 INFO - ==> process 5472 launched child process 4864 ("Z:\task_1530400491\build\application\firefox\plugin-container.exe" --channel="5472.30.1510196081\883120807" "C:\Users\task_1530400491\AppData\Local\Temp\tmp0cqrax.mozrunner\plugins\nptest.dll" -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 2632 plugin) 23:40:09 INFO - ==> process 5472 launched child process 2708 ("Z:\task_1530400491\build\application\firefox\plugin-container.exe" --channel="5472.34.484662457\1530252048" "C:\Users\task_1530400491\AppData\Local\Temp\tmp0cqrax.mozrunner\plugins\npswftest.dll" -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 2676 plugin) 23:40:09 INFO - ==> process 5472 launched child process 5004 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.38.1570313849\1791459448" -childID 6 -isForBrowser -prefsHandle 4424 -prefsLen 24645 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 1940 tab) 23:40:09 INFO - ==> process 5472 launched child process 4248 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.44.1762547011\538606346" -childID 7 -isForBrowser -prefsHandle 3836 -prefsLen 24645 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 2040 tab) 23:40:09 INFO - ==> process 5472 launched child process 6100 ("Z:\task_1530400491\build\application\firefox\firefox.exe" -contentproc --channel="5472.50.424588407\496565593" -childID 8 -isForBrowser -prefsHandle 3368 -prefsLen 24756 -schedulerPrefs 0001,2 -parentBuildID 20180630215631 -greomni "Z:\task_1530400491\build\application\firefox\omni.ja" -appomni "Z:\task_1530400491\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1530400491\build\application\firefox\browser" - 5472 "\\.\pipe\gecko-crash-server-pipe.5472" 3308 tab) 23:40:09 INFO - Found child pids: set([5664, 4864, 1188, 2404, 2536, 5004, 3656, 6100, 4248, 2708]) 23:40:09 INFO - Failed to get child procs 23:40:09 INFO - Killing process: 5664 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:09 INFO - mozcrash kill_pid(): unable to terminate pid 5664: 5 23:40:09 INFO - Killing process: 4864 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:09 INFO - mozcrash kill_pid(): unable to terminate pid 4864: 5 23:40:09 INFO - Killing process: 1188 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:09 INFO - mozcrash kill_pid(): unable to terminate pid 1188: 5 23:40:09 INFO - Killing process: 2404 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:09 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 2404: error 5 23:40:09 INFO - Killing process: 2536 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:09 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 2536: error 5 23:40:09 INFO - Killing process: 5004 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:09 INFO - mozcrash kill_pid(): unable to terminate pid 5004: 5 23:40:09 INFO - Killing process: 3656 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:09 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 3656: error 5 23:40:09 INFO - Killing process: 6100 23:40:09 INFO - Not taking screenshot here: see the one that was previously logged 23:40:10 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 6100: error 5 23:40:10 INFO - Killing process: 4248 23:40:10 INFO - Not taking screenshot here: see the one that was previously logged 23:40:10 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 4248: error 5 23:40:10 INFO - Killing process: 2708 23:40:10 INFO - Not taking screenshot here: see the one that was previously logged 23:40:10 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 2708: error 5 23:40:10 INFO - Killing process: 5472 23:40:10 INFO - Not taking screenshot here: see the one that was previously logged 23:40:10 INFO - mozcrash kill_pid(): wait failed (-1) terminating pid 5472: error 5 23:40:10 INFO - psutil found pid 5472 dead 23:44:44 INFO - JavaScript error: jar:file:///Z:/task_1530400491/build/application/firefox/omni.ja!/components/nsPlacesExpiration.js, line 804: TypeError: this._db is undefined 23:53:44 INFO - JavaScript error: jar:file:///Z:/task_1530400491/build/application/firefox/omni.ja!/components/nsPlacesExpiration.js, line 804: TypeError: this._db is undefined 00:02:44 INFO - JavaScript error: jar:file:///Z:/task_1530400491/build/application/firefox/omni.ja!/components/nsPlacesExpiration.js, line 804: TypeError: this._db is undefined 00:11:44 INFO - JavaScript error: jar:file:///Z:/task_1530400491/build/application/firefox/omni.ja!/components/nsPlacesExpiration.js, line 804: TypeError: this._db is undefined 00:20:44 INFO - JavaScript error: jar:file:///Z:/task_1530400491/build/application/firefox/omni.ja!/components/nsPlacesExpiration.js, line 804: TypeError: this._db is undefined [taskcluster:error] Aborting task... [taskcluster 2018-07-01T00:22:02.049Z] SUCCESS: The process with PID 5656 (child process of PID 4100) has been terminated. [taskcluster 2018-07-01T00:22:02.049Z] SUCCESS: The process with PID 3552 (child process of PID 4100) has been terminated. [taskcluster 2018-07-01T00:22:02.049Z] SUCCESS: The process with PID 1140 (child process of PID 4100) has been terminated. [taskcluster 2018-07-01T00:22:02.049Z] SUCCESS: The process with PID 5976 (child process of PID 3144) has been terminated. [taskcluster 2018-07-01T00:22:02.049Z] SUCCESS: The process with PID 4100 (child process of PID 3144) has been terminated. [taskcluster 2018-07-01T00:22:02.049Z] SUCCESS: The process with PID 3144 (child process of PID 4836) has been terminated. [taskcluster 2018-07-01T00:22:02.049Z] SUCCESS: The process with PID 4836 (child process of PID 1056) has been terminated. [taskcluster 2018-07-01T00:22:02.049Z] [taskcluster 2018-07-01T00:22:02.050Z] === Task Finished ===
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•5 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
|
||
Comment 3•5 years ago
|
||
Recent log failure: https://treeherder.mozilla.org/logviewer.html#?job_id=191773414&repo=mozilla-inbound&lineNumber=2882
|
|
||
Comment 4•5 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
|
||
Comment 5•5 years ago
|
||
Fail reappeared on autoland Log link: https://treeherder.mozilla.org/logviewer.html#?job_id=200103596&repo=autoland&lineNumber=3046
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 8•5 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
|
||
Comment 10•5 years ago
|
||
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=218395732&repo=mozilla-inbound&lineNumber=3411 19:37:47 INFO - Buffered messages logged at 19:37:02 19:37:47 INFO - Entering test bound test_slow_content_script 19:37:47 INFO - Extension loaded 19:37:47 INFO - Console message: Warning: attempting to write 21660 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes. 19:37:47 INFO - Buffered messages finished 19:37:47 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | Test timed out - 19:37:47 INFO - Not taking screenshot here: see the one that was previously logged 19:37:47 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | Extension left running at test shutdown - 19:37:47 INFO - Stack trace: 19:37:47 INFO - chrome://mochikit/content/browser-test.js:test_ok:1305 19:37:47 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109 19:37:47 INFO - chrome://mochikit/content/browser-test.js:nextTest:705 19:37:47 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1203 19:37:47 INFO - setTimeout handler*chrome://mochikit/content/browser-test.js:Tester_execTest:1165 19:37:47 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:995 19:37:47 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:focusedOrLoaded/<:803 19:37:55 INFO - Console message: [JavaScript Error: "Timeout while waiting for extension child to shutdown: "Slow Script Extension" (ID: 603d39caaeae55166140d29c2724f1eaaafa1f98@temporary-addon, moz-extension://fa1ecd3b-c65f-4924-bc8a-8cf9671e2a92/)" {file: "resource://gre/modules/Extension.jsm" line: 2022}] 19:37:55 INFO - shutdown@resource://gre/modules/Extension.jsm:2022:7 19:37:55 INFO - async*shutdown@resource://gre/modules/Extension.jsm:1251:24 19:37:55 INFO - async*callBootstrapMethod@resource://gre/modules/addons/XPIProvider.jsm:1639:20 19:37:55 INFO - async*_shutdown@resource://gre/modules/addons/XPIProvider.jsm:1767:12 19:37:55 INFO - async*shutdown@resource://gre/modules/addons/XPIProvider.jsm:1760:28 19:37:55 INFO - async*_uninstall@resource://gre/modules/addons/XPIProvider.jsm:1845:13 19:37:55 INFO - async*uninstall@resource://gre/modules/addons/XPIProvider.jsm:1840:12 19:37:55 INFO - uninstallAddon@resource://gre/modules/addons/XPIInstall.jsm:3827:15 19:37:55 INFO - async*uninstall@resource://gre/modules/addons/XPIDatabase.jsm:968:12 19:37:55 INFO - async*shutdown@resource://testing-common/ExtensionTestCommon.jsm:148:5 19:37:55 INFO - _receiveMessageAPI@chrome://mochikit/content/tests/SimpleTest/SpecialPowersObserverAPI.js:644:9 19:37:55 INFO - ChromePowers.prototype._receiveMessage@chrome://mochikit/content/tests/SimpleTest/ChromePowers.js:81:14 19:37:55 INFO - ChromePowers.prototype._sendAsyncMessage@chrome://mochikit/content/tests/SimpleTest/ChromePowers.js:43:3 19:37:55 INFO - unload@chrome://mochikit/content/tests/SimpleTest/specialpowersAPI.js:2075:9 19:37:55 INFO - ExtensionTestUtils.loadExtension/<@chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:110:14 19:37:55 INFO - nextTest@chrome://mochikit/content/browser-test.js:705:30 19:37:55 INFO - async*timeoutFn@chrome://mochikit/content/browser-test.js:1203:9 19:37:55 INFO - setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:1165:9 19:37:55 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:995:9 19:37:55 INFO - focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59 19:37:55 INFO - 19:37:55 INFO - Console message: Warning: attempting to write 21562 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes. 19:44:05 INFO - Buffered messages finished 19:44:05 ERROR - TEST-UNEXPECTED-TIMEOUT | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | application timed out after 370 seconds with no output 19:44:05 ERROR - Force-terminating active process(es). 19:44:05 INFO - Determining child pids from psutil...
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 12•4 years ago
|
||
|
|
||
Comment 13•4 years ago
|
||
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=224076302&repo=mozilla-inbound&lineNumber=2765
19:12:07 INFO - TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_simple.js
19:12:07 INFO - GECKO(4368) | MEMORY STAT | vsize 1151MB | vsizeMaxContiguous 244MB | residentFast 560MB | heapAllocated 238MB
19:12:07 INFO - TEST-OK | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_simple.js | took 112ms
19:12:07 INFO - checking window state
19:12:07 INFO - TEST-START | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js
19:12:08 INFO - GECKO(4368) | [Parent 4524, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
19:12:08 INFO - GECKO(4368) | [Child 5976, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 332
19:12:53 INFO - TEST-INFO | started process screenshot
19:12:53 INFO - TEST-INFO | screenshot: exit 0
19:12:53 INFO - Buffered messages logged at 19:12:07
19:12:53 INFO - Entering test bound test_slow_content_script
19:12:53 INFO - Buffered messages logged at 19:12:08
19:12:53 INFO - Extension loaded
19:12:53 INFO - Console message: Warning: attempting to write 21660 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
19:12:53 INFO - Buffered messages finished
19:12:53 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | Test timed out -
19:12:53 INFO - Not taking screenshot here: see the one that was previously logged
19:12:53 INFO - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/test-oop-extensions/browser_ext_slow_script.js | Extension left running at test shutdown -
19:12:53 INFO - Stack trace:
19:12:53 INFO - chrome://mochikit/content/browser-test.js:test_ok:1307
19:12:53 INFO - chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:ExtensionTestUtils.loadExtension/<:109
19:12:53 INFO - chrome://mochikit/content/browser-test.js:nextTest:707
19:12:53 INFO - chrome://mochikit/content/browser-test.js:timeoutFn:1205
19:12:53 INFO - setTimeout handlerchrome://mochikit/content/browser-test.js:Tester_execTest:1167
19:12:53 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:997
19:12:53 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
19:13:01 INFO - Console message: [JavaScript Error: "Timeout while waiting for extension child to shutdown: "Slow Script Extension" (ID: cc515472592154862adaacc85dce6c833098eb01@temporary-addon, moz-extension://979f82ca-71ea-48f4-9d77-b5bbb7379ef9/)" {file: "resource://gre/modules/Extension.jsm" line: 2015}]
19:13:01 INFO - shutdown@resource://gre/modules/Extension.jsm:2015:7
19:13:01 INFO - asyncshutdown@resource://gre/modules/Extension.jsm:1260:24
19:13:01 INFO - asynccallBootstrapMethod@resource://gre/modules/addons/XPIProvider.jsm:1637:26
19:13:01 INFO - async_shutdown@resource://gre/modules/addons/XPIProvider.jsm:1757:12
19:13:01 INFO - asyncshutdown@resource://gre/modules/addons/XPIProvider.jsm:1750:28
19:13:01 INFO - async_uninstall@resource://gre/modules/addons/XPIProvider.jsm:1835:13
19:13:01 INFO - asyncuninstall@resource://gre/modules/addons/XPIProvider.jsm:1830:12
19:13:01 INFO - uninstallAddon@resource://gre/modules/addons/XPIInstall.jsm:3827:15
19:13:01 INFO - asyncuninstall@resource://gre/modules/addons/XPIDatabase.jsm:968:12
19:13:01 INFO - asyncshutdown@resource://testing-common/ExtensionTestCommon.jsm:148:5
19:13:01 INFO - _receiveMessageAPI@chrome://mochikit/content/tests/SimpleTest/SpecialPowersObserverAPI.js:645:9
19:13:01 INFO - ChromePowers.prototype._receiveMessage@chrome://mochikit/content/tests/SimpleTest/ChromePowers.js:81:14
19:13:01 INFO - ChromePowers.prototype._sendAsyncMessage@chrome://mochikit/content/tests/SimpleTest/ChromePowers.js:43:3
19:13:01 INFO - unload@chrome://mochikit/content/tests/SimpleTest/specialpowersAPI.js:2069:9
19:13:01 INFO - ExtensionTestUtils.loadExtension/<@chrome://mochikit/content/tests/SimpleTest/ExtensionTestUtils.js:110:14
19:13:01 INFO - nextTest@chrome://mochikit/content/browser-test.js:707:30
19:13:01 INFO - asynctimeoutFn@chrome://mochikit/content/browser-test.js:1205:9
19:13:01 INFO - setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:1167:9
19:13:01 INFO - nextTest/<@chrome://mochikit/content/browser-test.js:997:9
19:13:01 INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:803:59
19:13:01 INFO -
19:13:01 INFO - Console message: Warning: attempting to write 21562 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 16•4 years ago
|
||
Description
•