Last Comment Bug 795086 - nsConsoleService posts LogMessageRunnables to the event queue uselessly even when there are no observers
: nsConsoleService posts LogMessageRunnables to the event queue uselessly even ...
Status: RESOLVED FIXED
[MemShrink:P3]
:
Product: Core
Classification: Components
Component: XPCOM (show other bugs)
: Trunk
: All All
: -- normal (vote)
: mozilla18
Assigned To: Seth Fowler [:seth] [:s2h]
:
Mentors:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2012-09-27 13:08 PDT by Seth Fowler [:seth] [:s2h]
Modified: 2012-09-28 22:26 PDT (History)
2 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Sample web page that triggers the bug by generating huge numbers of CSS errors during the parsing of an SVG file built from a long data URI. (1.03 MB, text/html)
2012-09-27 13:08 PDT, Seth Fowler [:seth] [:s2h]
no flags Details
Bug 795086 - Make nsConsoleService only post a LogMessageRunnable to the event queue if there are any observers for it. (2.22 KB, patch)
2012-09-27 13:22 PDT, Seth Fowler [:seth] [:s2h]
bzbarsky: review+
bzbarsky: feedback+
Details | Diff | Review

Description Seth Fowler [:seth] [:s2h] 2012-09-27 13:08:09 PDT
Created attachment 665615 [details]
Sample web page that triggers the bug by generating huge numbers of CSS errors during the parsing of an SVG file built from a long data URI.

nsConsoleService posts LogMessageRunnables to the event queue uselessly even when there are no observers. This results in huge amounts of memory being retained uselessly until the LogMessageRunnables execute. If there are very many or very large messages (or both, in the worst case) this can easily push the system into swap.
Comment 1 Seth Fowler [:seth] [:s2h] 2012-09-27 13:10:45 PDT
I've got a patch already which I'm preparing to upload now.
Comment 2 Daniel Holbert [:dholbert] 2012-09-27 13:22:08 PDT
To elaborate slightly: Quoting Neil from bug 786108 comment #8...
> > There are 892 instances of the string "writing-mode" in the encoded SVG
> > document, each of which triggers a warning-message with a ~1 MB URL embedded
> > in it.  So that's 1 GB of memory right there.
> 
> Fortunately we only keep the last 250 console messages.

So, as Seth said in comment 0 here, we create a runnable for every errors to be posted to the error console, and the runnable keeps its URI-string alive until it's executed.  These _runnables_ aren't capped to 250 (though the actual list of error-console-messages is).

So, while we parse a stylesheet, we can generate an unbounded number of these runnables in the event queue and hence generate an unbounded number of copies of the URI-string.  (After bug 786108, they should all share the same URI-string, but it's still worth avoiding them in the first place if we can.)
Comment 3 Seth Fowler [:seth] [:s2h] 2012-09-27 13:22:13 PDT
Created attachment 665624 [details] [diff] [review]
Bug 795086 - Make nsConsoleService only post a LogMessageRunnable to the event queue if there are any observers for it.

Lazily create and launch the LogMessageRunnable only if we have observers. Shows massive reduction in memory usage on the test case; before it was entering swap on a machine with 16 GB of RAM, while with this patch it tops out at ~1 GB.
Comment 4 Seth Fowler [:seth] [:s2h] 2012-09-27 13:25:11 PDT
Indeed; bug 786108 greatly reduces the impact of this issue for this specific test case because of sharing between the URI strings, but even with that fix in place, a huge number of unnecessary LogMessageRunnables are still created. And, of course, this may happen in other circumstances that bug 786108 doesn't address, so it's worth fixing this issue directly.
Comment 5 Daniel Holbert [:dholbert] 2012-09-27 13:27:08 PDT
(--> Clearing "See Also" field -- that's reserved for "duplicates of this bug in external bug trackers" (e.g. in the Ubuntu bug-tracker or in the bug-tracker of a tool that we're interacting with).  See the hover-text for that field for more info.)
Comment 6 Seth Fowler [:seth] [:s2h] 2012-09-27 13:28:01 PDT
Ah, whoops, thanks.
Comment 7 Boris Zbarsky [:bz] (Out June 25-July 6) 2012-09-27 13:32:18 PDT
Comment on attachment 665624 [details] [diff] [review]
Bug 795086 - Make nsConsoleService only post a LogMessageRunnable to the event queue if there are any observers for it.

r=me.
Comment 8 Daniel Holbert [:dholbert] 2012-09-27 13:44:40 PDT
Try run: https://tbpl.mozilla.org/?tree=Try&rev=b5fec0d9d9e9
Comment 9 Daniel Holbert [:dholbert] 2012-09-28 09:59:52 PDT
There was some infra-related purple/red in that try run, but there was enough green (and the change is minimally-invasive-enough) that I don't think we need to worry about missing those jobs.

Pushed to inbound:
  https://hg.mozilla.org/integration/mozilla-inbound/rev/8e0593f974bb
Comment 10 Phil Ringnalda (:philor) 2012-09-28 22:26:48 PDT
https://hg.mozilla.org/mozilla-central/rev/8e0593f974bb

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