Last Comment Bug 848615 - B2G: IPC's nsStringBuffer leak
: B2G: IPC's nsStringBuffer leak
Product: Core
Classification: Components
Component: IPC (show other bugs)
: unspecified
: ARM Gonk (Firefox OS)
: -- normal (vote)
: mozilla22
Assigned To: [:fabrice] Fabrice Desré
: Bill McCloskey (:billm)
Depends on:
  Show dependency treegraph
Reported: 2013-03-06 17:37 PST by Nicolas B. Pierron [:nbp]
Modified: 2013-03-17 21:16 PDT (History)
9 users (show)
See Also:
Crash Signature:
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---

dmd-warning.txt.gz (1.00 MB, application/gzip)
2013-03-06 17:37 PST, Nicolas B. Pierron [:nbp]
no flags Details
wip (2.38 KB, patch)
2013-03-08 22:36 PST, [:fabrice] Fabrice Desré
no flags Details | Diff | Splinter Review
wip v2 (1.80 KB, patch)
2013-03-08 22:39 PST, [:fabrice] Fabrice Desré
no flags Details | Diff | Splinter Review
patch v3 (3.63 KB, patch)
2013-03-11 14:45 PDT, [:fabrice] Fabrice Desré
bent.mozilla: review+
Details | Diff | Splinter Review

Description Nicolas B. Pierron [:nbp] 2013-03-06 17:37:57 PST
Created attachment 721957 [details]

This issue appeared when I was testing, and closed the application after leaving the game running for multiple hours (~12).  It appears that the full memory used by the game has been transferred to another process, and that this other process retain this memory and does not do anything with it.

It also appears that every application doing an oom after the fact is adding memory to this process.

My blind guess would be: The crash reporter which is present on the phone is having a oom due to the fact that it holds too much memory, but never show-up on the device and thus never get any chance to discard the total amount of memory accumulated.

This bug also cause what is observed in Bug 848605.
Possible duplicates: Bug 841774, Bug 840670?

-------- DMD report ---------
Unreported: ~101 blocks in stack trace record 1 of 718
 ~51,920,893 bytes (~51,837,919 requested / ~82,974 slop)
 41.10% of the heap (41.10% cumulative);  49.96% of unreported (49.96% cumulative)
 Allocated at
   replace_malloc /root/B2G/gecko/memory/replace/dmd/DMD.cpp:1226 (0x4001d77a
   malloc /root/B2G/gecko/memory/build/replace_malloc.c:152 (0x4016c2fa
   ppalloc /root/B2G/objdir-gecko/gfx/angle/Tokenizer.cpp:2260 (0x40eb8246
   nsStringBuffer::Alloc(unsigned int) /root/B2G/gecko/xpcom/string/src/nsSubstring.cpp:178 (0x40ce2b80
   nsAString_internal::MutatePrep(unsigned int, unsigned short**, unsigned int*) /root/B2G/gecko/xpcom/string/src/nsTSubstring.cpp:131 (0x40ce2cba
   nsAString_internal::ReplacePrepInternal(unsigned int, unsigned int, unsigned int, unsigned int) /root/B2G/gecko/xpcom/string/src/nsTSubstring.cpp:166 (0x40ce31d6
   nsAString_internal::ReplacePrep(unsigned int, unsigned int, unsigned int) /root/B2G/objdir-gecko/dist/include/nsTSubstring.h:738 (0x40ce3298
   nsAString_internal::Assign(unsigned short const*, unsigned int, mozilla::fallible_t const&) /root/B2G/gecko/xpcom/string/src/nsTSubstring.cpp:311 (0x40ce36b2
   nsAString_internal::Assign(unsigned short const*, unsigned int) /root/B2G/gecko/xpcom/string/src/nsTSubstring.cpp:290 (0x40ce36c8
   IPC::ParamTraits<nsAString_internal>::Read(IPC::Message const*, void**, nsAString_internal*) /root/B2G/objdir-gecko/dist/include/ipc/IPCMessageUtils.h:305 (0x40b18480
   mozilla::dom::PContentParent::OnMessageReceived(IPC::Message const&) /root/B2G/objdir-gecko/ipc/ipdl/PContentParent.cpp:2089 (0x410d7e0e
   mozilla::ipc::AsyncChannel::OnDispatchMessage(IPC::Message const&) /root/B2G/gecko/ipc/glue/AsyncChannel.cpp:473 (0x40b0ea50
   mozilla::ipc::RPCChannel::OnMaybeDequeueOne() /root/B2G/gecko/ipc/glue/RPCChannel.cpp:404 (0x40b13ab6
   RunnableMethod<mozilla::layers::ImageContainerChild, void (mozilla::layers::ImageContainerChild::*)(), Tuple0>::Run() /root/B2G/gecko/ipc/chromium/src/base/task.h:308 (0x40af63b6
   mozilla::ipc::RPCChannel::DequeueTask::Run() /root/B2G/objdir-gecko/dist/include/mozilla/ipc/RPCChannel.h:448 (0x40b1246c
   MessageLoop::RunTask(Task*) /root/B2G/gecko/ipc/chromium/src/base/ (0x40cf44d0
   MessageLoop::DeferOrRunPendingTask(MessageLoop::PendingTask const&) /root/B2G/gecko/ipc/chromium/src/base/ (0x40cf5302
   MessageLoop::DoWork() /root/B2G/gecko/ipc/chromium/src/base/ (0x40cf5ee0
   mozilla::ipc::DoWorkRunnable::Run() /root/B2G/gecko/ipc/glue/MessagePump.cpp:43 (0x40b11e2c
   nsThread::ProcessNextEvent(bool, bool*) /root/B2G/gecko/xpcom/threads/nsThread.cpp:627 (0x40cd16fa
   NS_ProcessNextEvent_P(nsIThread*, bool) /root/B2G/objdir-gecko/dist/include/nsError.h:179 (0x40cb1d6e
   mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) /root/B2G/gecko/ipc/glue/MessagePump.cpp:83 (0x40b11f3c
   MessageLoop::RunInternal() /root/B2G/gecko/ipc/chromium/src/base/ (0x40cf448c
   ~AutoRunState /root/B2G/gecko/ipc/chromium/src/base/ (0x40cf4536
Comment 1 Justin Lebar (not reading bugmail) 2013-03-06 19:21:47 PST
Thanks a lot for this bug report.

To be clear, is this DMD report from the main process, or from the app process?

Also, how did you launch   Do you have some kind of wrapper app?
Comment 2 Ben Turner (not reading bugmail, use the needinfo flag!) 2013-03-06 20:12:56 PST
Looks like this is parent process, receiving 101+ PContent::Msg_ScriptError__ID messages from the child. The string in question is the 'sourceLine' string, I think.
Comment 3 Ben Turner (not reading bugmail, use the needinfo flag!) 2013-03-06 20:24:40 PST
Oh, these console messages just stick around forever.
Comment 4 Justin Lebar (not reading bugmail) 2013-03-06 21:52:10 PST
bent suggested that we

 * Add a memory reporter for the console service,
 * Restrict the size of the messages it saves, and
 * Disable it on B2G if we can.

Hope I'm not forgetting anything.
Comment 5 [:fabrice] Fabrice Desré 2013-03-06 21:58:28 PST
I would rather not disabling it totally, since this is where the offline cache errors end up, and it's really useful to see them.
Comment 6 Justin Lebar (not reading bugmail) 2013-03-06 21:59:50 PST
(In reply to Fabrice Desré [:fabrice] from comment #5)
> I would rather not disabling it totally, since this is where the offline
> cache errors end up, and it's really useful to see them.

Can we disable the service without breaking logcat?  At the very least maybe we could have it purge its ring buffer more frequently (e.g. after notifying all existing observers).
Comment 7 Nicolas B. Pierron [:nbp] 2013-03-06 22:43:40 PST
(In reply to Justin Lebar [:jlebar] (PTO 3/11-3/15, then GMT+9 until 3/24) from comment #1)
> To be clear, is this DMD report from the main process, or from the app
> process?

I have to processes, it appear as being the main process under about:memory report, but the dmd report is under dmd-warning and not dmd-homescreen, which are only 2 extracted.  I can attach the about:memory report if you want, but I didn't found it as informative as the dmd-warning-110.txt.gz which is attached to this bug.

> Also, how did you launch   Do you have some kind of wrapper
> app?

I have a version of gecko in which I enabled IonMonkey, because I was checking for IonMonkey leaks. In the browser app, I bookmarked as a homescreen application before starting it.
Comment 8 [:fabrice] Fabrice Desré 2013-03-08 22:36:17 PST
Created attachment 723049 [details] [diff] [review]

With this patch we still get all the output in logcat, but we should not store any message. I guess we could also not pre-allocate the space for 250 string pointers since we don't use any...
Comment 9 [:fabrice] Fabrice Desré 2013-03-08 22:39:03 PST
Created attachment 723050 [details] [diff] [review]
wip v2

Now with less debugging.
Comment 10 Justin Lebar (not reading bugmail) 2013-03-09 08:04:55 PST
Two things:

* Let's use a pref instead of ifdefs?
* Would it be worthwhile to place a limit on the size of strings we store here (maybe also specified as a pref?)  We don't want to store 50mb of strings here on desktop or Fennec either.
Comment 11 [:fabrice] Fabrice Desré 2013-03-11 14:45:06 PDT
Created attachment 723653 [details] [diff] [review]
patch v3

Now using a preference to toggle the buffering of messages in nsConsoleService.

I did not implement a size limitation on message strings themselves. I don't think we want to truncate messages since they may be useless. We currently have a hard-coded count of 250 messages in the circular buffer, which looks reasonable but I can make it a pref also.
Comment 12 Ben Turner (not reading bugmail, use the needinfo flag!) 2013-03-12 16:13:16 PDT
Comment on attachment 723653 [details] [diff] [review]
patch v3

Review of attachment 723653 [details] [diff] [review]:

r=me with these fixed:

::: xpcom/base/nsConsoleService.cpp
@@ +66,3 @@
>  }
>  class AddConsoleEnabledPrefWatcher : public nsRunnable

Nit: I guess you should rename this now to something like "AddPrefWatchers" or something.

@@ +70,5 @@
>  public:
>      NS_IMETHOD Run()
>      {
>          Preferences::AddBoolVarCache(&sLoggingEnabled, "consoleservice.enabled", true);
> +        Preferences::AddBoolVarCache(&sLoggingBuffered, "consoleservice.buffered", true);

So, for a little while on the main thread sLoggingBuffered will be true while we wait for the pref service to tell us the value it has when this runnable runs. On B2G the pref service will eventually set it to false. However, if we log a message in the period in between then we will hold it alive forever. That's certainly better than what we have today but I think you could make this even better by calling Reset() here.
Comment 13 [:fabrice] Fabrice Desré 2013-03-13 12:13:56 PDT
Pushing to try with comments addressed:
Comment 14 Ben Turner (not reading bugmail, use the needinfo flag!) 2013-03-13 12:35:52 PDT
(In reply to Fabrice Desré [:fabrice] from comment #13)
> ...
> +class AddConsolePrefWatchers : public nsRunnable
>  {
> ...
> +private:
> +    nsConsoleService* mConsole;
>  };

You should use |nsRefPtr<nsConsoleService>| there to be safe.
Comment 15 [:fabrice] Fabrice Desré 2013-03-13 22:55:43 PDT
Comment 16 Ed Morley [:emorley] 2013-03-14 05:23:41 PDT
Comment 18 Justin Lebar (not reading bugmail) 2013-03-17 21:16:40 PDT
I filed bug 852018 on the remaining issue on desktop.

Note You need to log in before you can comment on or make changes to this bug.