1274074 - console.log()ging too much data can crash e10s via IPC call from mozilla::dom::ProcessGlobal::SendAsyncMessage

Status: RESOLVED FIXED

(Core :: DOM: Content Processes, defect)

Description

[Jukka Jylänki]

As per https://bugzilla.mozilla.org/show_bug.cgi?id=1271102#c9, reporting as a separate entry from bug 1271102.

STR (same as https://bugzilla.mozilla.org/show_bug.cgi?id=1271102#c5):

https://dl.dropboxusercontent.com/u/40949268/dump/streamed_download_test.html

This will crash in call stack

mozilla::ipc::ProcessLink::SendMessageW
mozilla::ipc::MessageChannel::Send
mozilla::dom::PContentChild::SendAsyncMessage
ChildProcessMessageManagerCallback::DoSendAsyncMessage
nsFrameMessageManager::DispatchAsyncMessageInternal
nsFrameMessageManager::DispatchAsyncMessage
nsFrameMessageManager::SendAsyncMessage
mozilla::dom::ProcessGlobal::SendAsyncMessage
XPTC__InvokebyIndex	

What the page does is it console.log()s a lot of binary data to web page console.

Some crash reports:
https://crash-stats.mozilla.com/report/index/8c86c26e-b1c6-4344-918b-b0a1e2160511
https://crash-stats.mozilla.com/report/index/eea27751-2b9b-4d88-8815-3072f2160511
https://crash-stats.mozilla.com/report/index/5317ab9a-666b-4b6a-9345-02c0a2160511

Comment 1

[Emil Pasca [:emilpasca]]

User Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:46.0) Gecko/20100101 Firefox/46.0

I have tested this issue on the latest Firefox release (46.0.1, Build ID: 20160502172042) and on the latest Nightly(49.0a1, Build ID: 20160518030234) and managed to reproduce it, but only on the Nightly version with e10s enabled. I've visited the page provided in comment 0 and Nightly crashes.

Comment 2

[Andrew McCreight [:mccr8]]

I'm going to implement bug 1272423, which should keep us from crashing here. I think this is just using the message manager with a gigantic message.

Comment 3

[Haik Aftandilian [:haik]]

Attachment: MozReview Request: Bug 1274074 - console.log()ging too much data can crash e10s via IPC call from mozilla::dom::ProcessGlobal::SendAsyncMessage; r=mconley

Prevent huge IPC messages from being generated for console.log event messages by
truncating large console.log messages before forwarding them from content to the
main process.

Review commit: https://reviewboard.mozilla.org/r/55534/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/55534/

Comment 4

[Haik Aftandilian [:haik]]

Regarding the above review (comment 3), the changes don't affect what is displayed to the developer console, only what is sent to the parent to be consumed by addons or test code.

Try run:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=b2faef243f2b

Comment 5

[Mike Conley (:mconley) (:⚙️)]

Comment on attachment 8757053 [details]
MozReview Request: Bug 1274074 - console.log()ging too much data can crash e10s via IPC call from mozilla::dom::ProcessGlobal::SendAsyncMessage; r=mconley

https://reviewboard.mozilla.org/r/55534/#review52642

Makes sense to me. Thanks Haik!

::: toolkit/components/processsingleton/ContentProcessSingleton.js:26
(Diff revision 1)
> + * total size > MSG_MGR_CONSOLE_MAX_SIZE (bytes) have their arguments
> + * completely truncated. MSG_MGR_CONSOLE_VAR_SIZE is an approximation of how
> + * much space (in bytes) a JS non-string variable will require in the manager's
> + * implementation. For strings, we use 2 bytes per char. We don't attempt to
> + * calculate the exact amount of space the message manager implementation
> + * will require for a given message so this is imperfect.

You might want to also mention the fragmentation issue you told me about in IRC.

Comment 6

[Haik Aftandilian [:haik]]

Comment on attachment 8757053 [details]
MozReview Request: Bug 1274074 - console.log()ging too much data can crash e10s via IPC call from mozilla::dom::ProcessGlobal::SendAsyncMessage; r=mconley

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/55534/diff/1-2/

Comment 7

[Haik Aftandilian [:haik]]

https://reviewboard.mozilla.org/r/55534/#review52642

> You might want to also mention the fragmentation issue you told me about in IRC.

Thanks. New patch incoming with the comment change you suggested and, per mccr8's recommendation on IRC, some changes to limit the console file and function strings to 1024 characters.

Comment 8

[Haik Aftandilian [:haik]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=9b8c02f2af59

Comment 9

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/4b44dee24a77
console.log()ging too much data can crash e10s via IPC call from mozilla::dom::ProcessGlobal::SendAsyncMessage; r=mconley

Comment 10

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

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

Comment 11

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/4b44dee24a77

Comment 12

[Jim Mathies [:jimm]]

lets get this flagged for uplift.

Comment 13

[Haik Aftandilian [:haik]]

Doing some quick validation of the fix on Aurora right now.

The STR don't cause a crash on Aurora for now because bug 1268616 (which reduced the max message size from 256M to 128M and added a RELEASE_ASSERT), but the problem still exists. console.log messages can generate log messages that result in huge messages resulting in crashes.

Comment 14

[Haik Aftandilian [:haik]]

Comment on attachment 8757053 [details]
MozReview Request: Bug 1274074 - console.log()ging too much data can crash e10s via IPC call from mozilla::dom::ProcessGlobal::SendAsyncMessage; r=mconley

Approval Request Comment
[Feature/regressing bug #]:e10s
[User impact if declined]:Can result in OOM crashes on sites that pass large strings to console.log()
[Describe test coverage new/current, TreeHerder]:

Did manual tests confirming the test case does not cause a crash and that messages are truncated as expected. The crash wasn't reproducible on Aurora for me without added test code to trigger crashes on large IPC messages (like we have in central). With the test code, confirmed the fix prevented the crash.

(Patch is the same as the nightly patch)
49 nightly: 
https://treeherder.mozilla.org/#/jobs?repo=try&revision=9b8c02f2af59

[Risks and why]: 

The risks are that an addon subscribing to console event messages gets broken by this change which truncates console.log events that require ~ 1MB of space or more.

The motivation for the fix is to reduce OOM crashes. console.log arguments are serialized into a single IPC message and as a result can require large allocations.
[String/UUID change made/needed]:N/A

Comment 15

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8757053 [details]
MozReview Request: Bug 1274074 - console.log()ging too much data can crash e10s via IPC call from mozilla::dom::ProcessGlobal::SendAsyncMessage; r=mconley

Fix an OOM, taking it

Comment 16

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/4c6311b611e9