https://tbpl.mozilla.org/php/getParsedLog.php?id=37020990&tree=Fx-Team Windows 7 32-bit fx-team debug test mochitest-other on 2014-03-31 12:57:16 PDT for push 6b01c16172c2 slave: t-w732-ix-104 13:06:25 INFO - 2238 INFO TEST-END | chrome://mochitests/content/chrome/dom/workers/test/test_fileSubWorker.xul | finished in 200ms 13:06:25 INFO - ++DOMWINDOW == 62 (0A1733C0) [pid = 3400] [serial = 2194] [outer = 18C3FFF8] 13:06:25 INFO - 2239 INFO TEST-START | chrome://mochitests/content/chrome/dom/workers/test/test_url.xul 13:06:25 INFO - ++DOMWINDOW == 63 (18C3F6D8) [pid = 3400] [serial = 2195] [outer = 18C3FFF8] 13:06:25 INFO - Hit MOZ_CRASH() at c:\builds\moz2_slave\fx-team-w32-d-0000000000000000\build\xpcom\base\CycleCollectedJSRuntime.cpp:463 13:06:27 INFO - [3372] ###!!! ABORT: Aborting on channel error.: file c:\builds\moz2_slave\fx-team-w32-d-0000000000000000\build\ipc\glue\MessageChannel.cpp, line 1522 13:06:27 INFO - [3372] ###!!! ASSERTION: Cannot call AnnotateCrashReport in child processes from non-main thread.: 'Error', file c:\builds\moz2_slave\fx-team-w32-d-0000000000000000\build\toolkit\crashreporter\nsExceptionHandler.cpp, line 1691 13:06:27 INFO - NS_DebugBreak [xpcom/base/nsDebugImpl.cpp:367] 13:06:27 INFO - mozilla::ipc::MessageChannel::OnChannelErrorFromLink() [ipc/glue/MessageChannel.cpp:1522] 13:06:27 INFO - base::MessagePumpForIO::WaitForIOCompletion(unsigned long,base::MessagePumpForIO::IOHandler *) [ipc/chromium/src/base/message_pump_win.cc:524] 13:06:27 INFO - base::MessagePumpForIO::WaitForWork() [ipc/chromium/src/base/message_pump_win.cc:501] 13:06:27 INFO - base::MessagePumpForIO::DoRunLoop() [ipc/chromium/src/base/message_pump_win.cc:463] 13:06:27 INFO - base::MessagePumpWin::RunWithDispatcher(base::MessagePump::Delegate *,base::MessagePumpWin::Dispatcher *) [ipc/chromium/src/base/message_pump_win.cc:55] 13:06:27 INFO - base::MessagePumpWin::Run(base::MessagePump::Delegate *) [ipc/chromium/src/base/message_pump_win.h:78] 13:06:27 INFO - MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:226] 13:06:27 INFO - MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:220] 13:06:27 INFO - MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:194] 13:06:27 INFO - base::Thread::ThreadMain() [ipc/chromium/src/base/thread.cc:165] 13:06:27 INFO - `anonymous namespace'::ThreadFunc(void *) [ipc/chromium/src/base/platform_thread_win.cc:27] 13:06:27 INFO - kernel32 + 0x53c45 13:06:27 INFO - ntdll + 0x637f5 13:06:27 INFO - ntdll + 0x637c8 13:06:27 INFO - [3372] ###!!! ASSERTION: Cannot call AnnotateCrashReport in child processes from non-main thread.: 'Error', file c:\builds\moz2_slave\fx-team-w32-d-0000000000000000\build\toolkit\crashreporter\nsExceptionHandler.cpp, line 1641 13:06:27 INFO - TEST-INFO | Main app process: exit status 80000003 13:06:27 WARNING - TEST-UNEXPECTED-FAIL | chrome://mochitests/content/chrome/dom/workers/test/test_url.xul | application terminated with exit code 2147483651 13:06:27 INFO - INFO | runtests.py | Application ran for: 0:06:45.631000 13:06:27 INFO - INFO | zombiecheck | Reading PID log: c:\users\cltbld\appdata\local\temp\tmpnmdwlnpidlog 13:06:27 INFO - ==> process 3400 launched child process 380 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.19141048.1182140125 -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" tab) 13:06:27 INFO - ==> process 3400 launched child process 3220 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.16d66510.885939145 -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" tab) 13:06:27 INFO - ==> process 3400 launched child process 4080 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.1d374b40.455277296 "c:\users\cltbld\appdata\local\temp\tmppmmq6l\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" plugin) 13:06:27 INFO - ==> process 3400 launched child process 3812 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.1d36f698.1690112210 "c:\users\cltbld\appdata\local\temp\tmppmmq6l\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" plugin) 13:06:27 INFO - ==> process 3400 launched child process 3512 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.1d372c58.1504141869 "c:\users\cltbld\appdata\local\temp\tmppmmq6l\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" plugin) 13:06:27 INFO - ==> process 3400 launched child process 1660 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.1d373060.1027741559 "c:\users\cltbld\appdata\local\temp\tmppmmq6l\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" plugin) 13:06:27 INFO - ==> process 3400 launched child process 3864 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.1d373b20.1467872609 "c:\users\cltbld\appdata\local\temp\tmppmmq6l\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" plugin) 13:06:27 INFO - ==> process 3400 launched child process 3384 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.1d3760c0.453635851 "c:\users\cltbld\appdata\local\temp\tmppmmq6l\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" plugin) 13:06:27 INFO - ==> process 3400 launched child process 3372 ("C:\slave\test\build\application\firefox\plugin-container.exe" --channel=3400.1d3731b8.665793241 "c:\users\cltbld\appdata\local\temp\tmppmmq6l\plugins\nptest.dll" -greomni "C:\slave\test\build\application\firefox\omni.ja" -appomni "C:\slave\test\build\application\firefox\browser\omni.ja" -appdir "C:\slave\test\build\application\firefox\browser" - 3400 "\\.\pipe\gecko-crash-server-pipe.3400" plugin) 13:06:29 WARNING - PROCESS-CRASH | chrome://mochitests/content/chrome/dom/workers/test/test_url.xul | application crashed [@ xul.dll + 0x457f1] 13:06:29 INFO - Crash dump filename: c:\users\cltbld\appdata\local\temp\tmppmmq6l\minidumps\67ef81d6-2351-42f3-ac6e-95de98822d33.dmp 13:06:29 INFO - Operating system: Windows NT 13:06:29 INFO - 6.1.7601 Service Pack 1 13:06:29 INFO - CPU: x86 13:06:29 INFO - GenuineIntel family 6 model 30 stepping 5 13:06:29 INFO - 8 CPUs 13:06:29 INFO - Crash reason: EXCEPTION_BREAKPOINT 13:06:29 INFO - Crash address: 0x64ac57f1 13:06:29 INFO - Thread 109 (crashed) 13:06:29 INFO - 0 xul.dll + 0x457f1 13:06:29 INFO - eip = 0x64ac57f1 esp = 0x3e4ff690 ebp = 0x3e4ff694 ebx = 0x00000000 13:06:29 INFO - esi = 0x3e4ff6b4 edi = 0x1f5e1dd0 eax = 0x00000000 ecx = 0xd7e6794c 13:06:29 INFO - edx = 0x689ee4d8 efl = 0x00000216 13:06:29 INFO - Found by: given as instruction pointer in context 13:06:29 INFO - 1 xul.dll + 0xeb994d 13:06:29 INFO - eip = 0x6593994e esp = 0x3e4ff69c ebp = 0x3e4ff7e8 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 2 xul.dll + 0x8c431 13:06:29 INFO - eip = 0x64b0c432 esp = 0x3e4ff7f0 ebp = 0x3e4ff84c 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 3 xul.dll + 0x1dd14 13:06:29 INFO - eip = 0x64a9dd15 esp = 0x3e4ff854 ebp = 0x3e4ff860 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 4 xul.dll + 0x2d905b 13:06:29 INFO - eip = 0x64d5905c esp = 0x3e4ff868 ebp = 0x3e4ff88c 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 5 xul.dll + 0x29972f 13:06:29 INFO - eip = 0x64d19730 esp = 0x3e4ff894 ebp = 0x3e4ff8ac 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 6 xul.dll + 0x29a99a 13:06:29 INFO - eip = 0x64d1a99b esp = 0x3e4ff8b4 ebp = 0x3e4ff8e0 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 7 xul.dll + 0x29ba89 13:06:29 INFO - eip = 0x64d1ba8a esp = 0x3e4ff8e8 ebp = 0x3e4ff900 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 8 xul.dll + 0x8a8e4 13:06:29 INFO - eip = 0x64b0a8e5 esp = 0x3e4ff908 ebp = 0x3e4ff924 13:06:29 INFO - Found by: previous frame's frame pointer 13:06:29 INFO - 9 nss3.dll!_PR_NativeRunThread [pruthr.c:6b01c16172c2 : 397 + 0x8]

Not sure what we can do here. The machine ran out of memory and purposefully crashed.

Looks like we can neatly fix it by disabling your test on Win7 debug.

Looks like a dupe of bug #981181

(In reply to ben turner [:bent] (use the needinfo? flag!) from comment #1) > Not sure what we can do here. The machine ran out of memory and purposefully > crashed. If you can't fix this, we need to disable the test. It's not acceptable to just leave it failing frequently.

The JS folks have been working to better handle memory use for multiple JS runtimes, maybe they have some ideas on what to do here.

Bug 990613 seems like almost certainly a dupe of this.

(In reply to ben turner [:bent] (use the needinfo? flag!) from comment #17) > The JS folks have been working to better handle memory use for multiple JS > runtimes, maybe they have some ideas on what to do here. Naveed, can you help find someone to investigate these crashes? This and bug 990613 are frequently occurring on TBPL and we will need to disable these tests per the link below if we can't make any progress on getting them fixed. Thanks! https://wiki.mozilla.org/Sheriffing/Test_Disabling_Policy

(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #29) This kind of OOM is unlikely to be hidden by simply disabling tests... It will just move the OOM to some other test most likely.

(In reply to ben turner [:bent] (use the needinfo? flag!) from comment #31) > (In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #29) > > This kind of OOM is unlikely to be hidden by simply disabling tests... It > will just move the OOM to some other test most likely. So that basically means nobody can do anything here? We continue to hit this across multiple branches on a regular basis. Naveed, per my needinfo? request from early May, can we please work to find someone who can investigate this?

Chris, I've been told you might be able to help find an owner for this otherwise?

Bill: this bug is described as a JS OOM crash, but it looks like IPC is calling NS_RUNTIMEABORT() after a channel error. Can channel errors be caused by OOM?

The channel error happens in the child because we purposefully MOZ_CRASH'd the parent process. The channel error is not really relevant.

Yeah, I agree with Ben. This is definitely an OOM crash. Looking at two logs, I see: - after test_fileSlice.xul finishes, vsizeMaxContiguous is about 140MB - after the next test, test_fileSubWorker.xul, finishes, vsizeMaxContiguous is about 13MB So it seems like the latter test is probably using a lot of memory. vsize also goes up by quite a bit.

test_fileSlice.xul is sending file data as a blob param: > var params = {blob: blob, start: start, end: end, contentType: contentType}; > worker.postMessage(params); whereas test_fileSubWorker.xul is sending file data directly: > worker.postMessage(file); Does postMessage() make a (shallow) copy of the data it is sending? Is a problem with GC on workers?

The filesize of these blobs is pretty small (they're created in the file there) so I don't think they're relevant. The large memory usage is almost certainly due to the extra JSRuntimes being created for all the workers/subworkers. There are probably other workers created from previous tests that haven't shut down fully also.

Is there any kind of ++JSRuntime --JSRuntime in the debug spew? :)

Inactive; closing (see bug 1180138).