969415 - add pref to dump about:memory to file from js_ReportOutOfMemory

Status: RESOLVED FIXED

(Toolkit :: about:memory, defect)

Description

[Luke Wagner [:luke]]

We've been running into bugs where a big Emscripten game OOMs somewhere during load time and, by the time we can click "Measure" in about:memory, the memory usage causing the spike has since gone away.  (A LifoAlloc on the stack would be a good example.)  This makes these temporary memory spikes difficult to diagnose.

A really helpful feature would be if we could set a pref that tells the JS engine to take an about:memory dump (written to a file) in js_ReportOutOfMemory.  Perhaps the pref could be the filename of the dump.  Presumably we'd want this in many more places than js_ReportOutOfMemory, but that can be a followup.

Initially, I wanted a checkbox in about:memory to make this feature more discoverable (if you are opening about:memory at all, chances are you'd like this feature), but a pref makes more sense since it's a global option.  Perhaps then just a bit of text in about:config naming the pref?  (Which I can copy/paste when I forget :)

Comment 1

[Luke Wagner [:luke]]

I forgot another piece of the feature: printing to the web console that a dump was written (and probably the path).

Comment 2

[Luke Wagner [:luke]]

Attachment: add-hooks

Here's the JS-engine-side of the callback.  Another option is that the callback would return the filename of the dump so that the JS engine could emit the warning, but it seems more natural for the callback impl to do that.

Comment 3

[Luke Wagner [:luke]]

Attachment: add-hooks

qref'ing helps

Comment 4

[Nicholas Nethercote [inactive]]

Thanks. I'll work on the non-SpiderMonkey part on Monday.

Comment 5

[Nicholas Nethercote [inactive]]

> Thanks. I'll work on the non-SpiderMonkey part on Monday.

It must be Monday somewhere in the world still, right? Either way, I'm looking at this now. My desktop machine has 32 GiB of RAM so OOMs aren't common for me, but I should be able to use cgroups to artificially limit the available memory. Is there any particular test I should work with? I'll try http://www.unrealengine.com/html5/ to start with.

Comment 6

[Nicholas Nethercote [inactive]]

Dumping reports is slow, and takes up disk space. Should we limit how often this can happen in some fashion? The simplest possible limit would be to restrict it to N times per session.

Comment 7

[Nicholas Nethercote [inactive]]

Attachment: (part 2) - Add a pref to enable memory report dumping on JS OOMs.

This patch implement an option to dump reports on a JS OOM, controlled by the 
new memory.dump_reports_on_oom pref.
 
When it happens, you get output like this on the error console:

> nsIMemoryInfoDumper dumped reports to /tmp/memory-report-due-to-JS-OOM-11077.json.gz
> uncaught exception: out of memory

The "nsIMemoryInfoDumper" message is the default message that was already
printed any time memory reports are dumped to file. The fact that it comes
before the "out of memory" message isn't ideal... this could be changed by
moving the OOM callback call after onError() in js_ReportOutOfMemory().

The location is always some kind of tmp directory. This patch has control over
the "due-to-JS-OOM" part of the filename -- and it hardwires that -- but not
the other parts.

----

One thing that surprised me is that there seem to be many places in
SpiderMonkey where we can OOM but don't call into js_ReportOutOfMemory().
What's the policy behind its use?

Also, I had trouble causing a crash via cgroups. (Though I did succeed in
utterly freezing my machine at one point. Boo!) That's why I have an
"njn"-marked hack to force an OOM in MapObject.cpp.

Comment 8

[Luke Wagner [:luke]]

(In reply to Nicholas Nethercote [:njn] from comment #7)
Thanks!  I'll give this a spin on Win32 later today (where it is quite easy to OOM).

> The "nsIMemoryInfoDumper" message is the default message that was already
> printed any time memory reports are dumped to file. The fact that it comes
> before the "out of memory" message isn't ideal... this could be changed by
> moving the OOM callback call after onError() in js_ReportOutOfMemory().

Actually, assuming JS is running, onError doesn't even get called until the exception has unwound the entire stack and failed to be caught, so the sequencing seems right.

> One thing that surprised me is that there seem to be many places in
> SpiderMonkey where we can OOM but don't call into js_ReportOutOfMemory().
> What's the policy behind its use?

Well, we're supposed to :)

Comment 9

[Luke Wagner [:luke]]

Comment on attachment 8375264 [details] [diff] [review]
(part 2) - Add a pref to enable memory report dumping on JS OOMs.

Great!  From a quick test this seems to work.

One thing that hopefully we could fix: once the pref is enabled, it seems like a bunch of different types of GCs spew about:memory logs.  One example is clicking "Minimize Memory Usage", but I also notice them just over the course of normal browsing (close a tab and wait a bit for the GC/CC that happen).  It'd be nice if these only happened when a real OOM occurred.

Comment 10

[Nicholas Nethercote [inactive]]

> One thing that hopefully we could fix: once the pref is enabled, it seems
> like a bunch of different types of GCs spew about:memory logs.  One example
> is clicking "Minimize Memory Usage", but I also notice them just over the
> course of normal browsing (close a tab and wait a bit for the GC/CC that
> happen).  It'd be nice if these only happened when a real OOM occurred.

Let me guess: you didn't disable the hack in builtin/MapObjects.cpp? Remove the "1 ||" and it should work more as you expect :)

Comment 11

[Luke Wagner [:luke]]

lol, yep

Comment 12

[Luke Wagner [:luke]]

Oh, one other point of feedback: initially I was expecting the messages on the normal content Web Console, not the Browser Console.  Since this isn't a normal user-facing feature, perhaps it doesn't matter.

Comment 13

[Nicholas Nethercote [inactive]]

What's the difference between the Web Console and the Browser Console?

Comment 14

[Luke Wagner [:luke]]

The Web Console is the thing that everyone opens by default: it is docked in the tab and it provides the stream of warnings from the tab containing it and JS executes in the context of the tab's global.  The Browser Console is necessarily a separate window, refers to chrome JS, and I don't think anyone ever uses unless they are a FF/addon dev.

Comment 15

[Nicholas Nethercote [inactive]]

Attachment: (part 2) - Add a pref to enable memory report dumping on JS OOMs.

Same as the last patch, except I removed the force-OOM-on-MapObject-clear hack.

I figure we might as well land this and get it in the hands of the game devs,
and then we can tweak it based on feedback.

Comment 16

[Nicholas Nethercote [inactive]]

Comment on attachment 8372338 [details] [diff] [review]
add-hooks

Review of attachment 8372338 [details] [diff] [review]:
-----------------------------------------------------------------

This looks fine to me. I'm happy to land it with part 2.

Comment 17

[Luke Wagner [:luke]]

Comment on attachment 8378580 [details] [diff] [review]
(part 2) - Add a pref to enable memory report dumping on JS OOMs.

Review of attachment 8378580 [details] [diff] [review]:
-----------------------------------------------------------------

Great!  One request: since I wrote the original hooks patch, we added the LargeAllocationFailureCallback to jsapi.h.  Since this logically related, it'd be nice to group them together at in jsapi.h/cpp and Runtime.h and explain the interaction between both in jsapi.h.  I'll do that real quick and attach a new patch to use.

Comment 18

[Luke Wagner [:luke]]

Attachment: add-hooks

I also noticed, while reviewing the patch, that I was missing JS_PUBLIC_API(void) on SetOutOfMemoryCallback and I failed to init oomCallback in Runtime's constructor.

Comment 19

[Nicholas Nethercote [inactive]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/4a83d046db82
https://hg.mozilla.org/integration/mozilla-inbound/rev/b677573f964b

Comment 20

[Luke Wagner [:luke]]

And one more to fix the Hf failure:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2d935f3e9587

Comment 21

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/4a83d046db82
https://hg.mozilla.org/mozilla-central/rev/b677573f964b
https://hg.mozilla.org/mozilla-central/rev/2d935f3e9587

Comment 22

[Luke Wagner [:luke]]

Chris: it'd be great if we could add this to any "tips and tricks for debugging Emscripten" page we have on MDN.  The pref is memory.dump_reports_on_oom.  When this is set, about:memory dumps are written to a file whose name is printed on the Browser Console.

Comment 23

[Chris Mills [:cmills]]

Added:

https://developer.mozilla.org/en-US/docs/Emscripten/Techniques/Out_of_memory_error_reports