795086 - nsConsoleService posts LogMessageRunnables to the event queue uselessly even when there are no observers

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[Seth Fowler [:seth] [:s2h]]

Attachment: 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]]

I've got a patch already which I'm preparing to upload now.

Comment 2

[Daniel Holbert [:dholbert] (on leave until Dec 1)]

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]]

Attachment: 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]]

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] (on leave until Dec 1)]

(--> 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]]

Ah, whoops, thanks.

Comment 7

[Boris Zbarsky [:bzbarsky]]

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] (on leave until Dec 1)]

Try run: https://tbpl.mozilla.org/?tree=Try&rev=b5fec0d9d9e9

Comment 9

[Daniel Holbert [:dholbert] (on leave until Dec 1)]

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)]

https://hg.mozilla.org/mozilla-central/rev/8e0593f974bb