[Shutdown] js::NukeCrossCompartmentWrappers takes up to 300ms on shutdown. Avoid doing it for optimized shutdown

VERIFIED FIXED in mozilla20

Status

()

Core
DOM
VERIFIED FIXED
5 years ago
4 months ago

People

(Reporter: BenWa, Assigned: BenWa)

Tracking

(Blocks: 1 bug)

unspecified
mozilla20
x86
Mac OS X
Points:
---

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [Snappy:P1])

Attachments

(1 attachment)

(Assignee)

Description

5 years ago
Startup report:
https://people.mozilla.com/~bgirard/startup_report/report.html#js::NukeCrossCompartmentWrappers

This currently list 10 shutdown profiles sorted from longest to shortest time spent in js::NukeCrossCompartmentWrappers recorded on my system. Click on the profile will preview the profile + highlight the function.

Note that the function time is highly variable that takes significantly longer as uptimes increases.

Is this required to persist our shutdown state?
No, these are entirely unnecessary during shutdown.
(Assignee)

Comment 2

5 years ago
Excellent. Is there someone that has time to either look into this or mentor someone such as myself on how to remove it?
Hmm.  I think Glandium filed a similar bug, with his 10,000 tabs.
Ah, yes, bug 816784.
Glandium's is different, I believe.  This has an addon explicitly invoking nukeSandbox.
(Assignee)

Comment 6

5 years ago
The shutdown is trigged by the profiler addon which initiates a shutdown profile. I'd expect to see it without the add-on involve. Let me know if you think having the addon trigger the restart could skew the results.
I don't think having the addon trigger the restart skews the results, I think having the addon skews the results.  If I'm reading the profiler output correctly, the stack for this NukeCCW call is

js::UnwrapObject(JSObject*, bool, unsigned int*)
js::NukeCrossCompartmentWrappers(JSContext*, js::CompartmentFilter const&, js::CompartmentFilter const&, js::NukeReferencesToWindow)
nsXPCComponents_Utils::NukeSandbox(JS::Value const&, JSContext*)
NS_InvokeByIndex_P
XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode)
XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*)
js::InvokeKernel(JSContext*, JS::CallArgs, js::MaybeConstruct)
js::Interpret(JSContext*, js::StackFrame*, js::InterpMode)
js::RunScript(JSContext*, JS::Handle<JSScript*>, js::StackFrame*)
unloadSandbox() @ bootstrap.js:214
nukeModules() @ bootstrap.js:240
js::RunScript
js::InvokeKernel(JSContext*, JS::CallArgs, js::MaybeConstruct)
js::Invoke(JSContext*, JS::Value const&, JS::Value const&, unsigned int, JS::Value*, JS::Value*)
JS_CallFunctionValue(JSContext*, JSObject*, JS::Value, unsigned int, JS::Value*, JS::Value*)

So it looks like bootstrap.js (I assume this is part of the SDK) is calling this function.
(Assignee)

Updated

5 years ago
Assignee: general → nobody
Component: JavaScript Engine → General
Product: Core → Add-on SDK
Version: Trunk → unspecified
(Assignee)

Updated

5 years ago
Summary: [Shutdown] js::NukeCrossCompartmentWrappers takes up 300ms on shutdown → [Shutdown] unloadSandbox/js::NukeCrossCompartmentWrappers takes up 300ms on shutdown
Hmm yeah we shouldn't need to do this on shutdown at all
(Assignee)

Comment 9

5 years ago
Actually some but not all comes from the addons' SDK so perhaps we should split this off into two issues.

This is the one I see called from non addon SDK:
http://mxr.mozilla.org/mozilla-central/source/dom/base/nsGlobalWindow.cpp#6951
(In reply to Benoit Girard (:BenWa) from comment #9)
> This is the one I see called from non addon SDK:
> http://mxr.mozilla.org/mozilla-central/source/dom/base/nsGlobalWindow.
> cpp#6951

That'd be bug 816784, right?
Indeed.  It would easy to patch that to not run at shutdown if we had some global concept of when shutdown starts.
(Assignee)

Comment 12

5 years ago
How about I add a global flag to toolkit:
SHUTDOWN_NOT_REQUESTED
SHUTDOWN_FAST
SHUTDOWN_CLEAN

When we're in the SHUTDOWN_FAST state we can skip NukeCrossCompartment and similar book keeping while we can continue to run them for debug builds.

If that's all we need I can file a followup and get it done.
(In reply to Benoit Girard (:BenWa) from comment #12)
> How about I add a global flag to toolkit:
> SHUTDOWN_NOT_REQUESTED
> SHUTDOWN_FAST
> SHUTDOWN_CLEAN
> 
> When we're in the SHUTDOWN_FAST state we can skip NukeCrossCompartment and
> similar book keeping while we can continue to run them for debug builds.
> 
> If that's all we need I can file a followup and get it done.

nsIAppStartup.shuttingDown already exists and should be true when the app is closing.
(Assignee)

Comment 14

5 years ago
(In reply to Dave Townsend (:Mossop) from comment #13)
> (In reply to Benoit Girard (:BenWa) from comment #12)
> > How about I add a global flag to toolkit:
> > SHUTDOWN_NOT_REQUESTED
> > SHUTDOWN_FAST
> > SHUTDOWN_CLEAN
> > 
> > When we're in the SHUTDOWN_FAST state we can skip NukeCrossCompartment and
> > similar book keeping while we can continue to run them for debug builds.
> > 
> > If that's all we need I can file a followup and get it done.
> 
> nsIAppStartup.shuttingDown already exists and should be true when the app is
> closing.

Alright we might want to provide a slightly more informative wrapper to expose a fast vs. clean shutdown that we can use in optimize/debug builds.

With that in place kyle what needs to be done to remove NukeCrossCompartment safely? Is it more involved then an early return?
(In reply to Benoit Girard (:BenWa) from comment #14)
> With that in place kyle what needs to be done to remove NukeCrossCompartment
> safely? Is it more involved then an early return?

Well I don't know what the addon sdk needs to do (which is what this bug is about).  For bug 816784 we just need to skip calling the function if we are shutting down.
(In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #15
> For bug 816784 we just need to skip calling the function if we are shutting down.

Note bug 816784 is also about private browsing ; I suspect it also happens when switching tab groups.
(I also wonder if there wouldn't be a way to make NukeCrossCompartment faster)
(Assignee)

Comment 18

5 years ago
Alright sorry for changing my mind. Let's make this bug about avoiding doing NukeCrossCompartment on shutdown from WindowDestroyedEvent. Bug 816784 can investigate how to speed it up for the general browsing case. I'll file a new bug to find a solution for the jetpack SDK.
Component: General → DOM
Product: Add-on SDK → Core
Summary: [Shutdown] unloadSandbox/js::NukeCrossCompartmentWrappers takes up 300ms on shutdown → [Shutdown] js::NukeCrossCompartmentWrappers takes up to 300ms on shutdown. Avoid doing it for optimized shutdown

Updated

5 years ago
Priority: -- → P1
Oops, midaired your move to Core during Jetpack triage.
Priority: P1 → --
(Assignee)

Comment 20

5 years ago
Created attachment 689339 [details] [diff] [review]
Don't NukeCrossCompartment on optimized shutdown

Are you a good reviewer from that Kyle? I didn't add anything of the sort SHUTDOWN_FAST/SHUTDOWN_CLEAN but perhaps it would be worth it.
Assignee: nobody → bgirard
Status: NEW → ASSIGNED
Attachment #689339 - Flags: review?(khuey)
(Assignee)

Updated

5 years ago
No longer blocks: 810156
(Assignee)

Updated

5 years ago
Blocks: 819063
I would expect that skipping this in debug builds will turn tinderbox orange with leaks.  Can you run this by try?
(Assignee)

Comment 22

5 years ago
(In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #21)
> I would expect that skipping this in debug builds will turn tinderbox orange
> with leaks.  Can you run this by try?

Note '#ifndef DEBUG' that should cover this. I'll push to try. Feel free to make your review conditional on green try run (which is always implicit).
(Assignee)

Comment 23

5 years ago
https://tbpl.mozilla.org/?tree=Try&rev=8cd7360339b3
Comment on attachment 689339 [details] [diff] [review]
Don't NukeCrossCompartment on optimized shutdown

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

Oh, I missed that bit.  That's what I get for skimming.

Please brace one-line ifs.
Attachment #689339 - Flags: review?(khuey) → review+
Whiteboard: [Snappy:P1]
Kyle: If we stop destroying these wrappers on shutdown, are we interfering with the destruction of other objects? e.g. if a cross-compartment wrapper references a native object that only saves data on destruction, would this change lead to data loss?
(Assignee)

Comment 26

5 years ago
I landed this patch for now but feel free to keep discussing. If we have doubts we can back this out.

https://hg.mozilla.org/integration/mozilla-inbound/rev/59f96e3a86d3
Flags: needinfo?(khuey)
(In reply to Vladan Djeric (:vladan) from comment #25)
> Kyle: If we stop destroying these wrappers on shutdown, are we interfering
> with the destruction of other objects? e.g. if a cross-compartment wrapper
> references a native object that only saves data on destruction, would this
> change lead to data loss?

Only if without cutting these wrappers we leak.
Flags: needinfo?(khuey)
(In reply to Benoit Girard (:BenWa) from comment #18)
> Alright sorry for changing my mind. Let's make this bug about avoiding doing
> NukeCrossCompartment on shutdown from WindowDestroyedEvent. Bug 816784 can
> investigate how to speed it up for the general browsing case. I'll file a
> new bug to find a solution for the jetpack SDK.

Did this bug get filed?
(Assignee)

Comment 29

5 years ago
I filed bug 819454 for the SDK.
(In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #27)
> (In reply to Vladan Djeric (:vladan) from comment #25)
> > Kyle: If we stop destroying these wrappers on shutdown, are we interfering
> > with the destruction of other objects? e.g. if a cross-compartment wrapper
> > references a native object that only saves data on destruction, would this
> > change lead to data loss?
> 
> Only if without cutting these wrappers we leak.

Hmm, and why is that OK?
Comment on attachment 689339 [details] [diff] [review]
Don't NukeCrossCompartment on optimized shutdown

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

::: dom/base/nsGlobalWindow.cpp
@@ +6935,5 @@
>        }
>      }
>  
> +    bool skipNukeCrossCompartment = false;
> +#ifndef DEBUG

Hmm, you want to also check for NS_TRACE_MALLOC here, otherwise you're breaking trace-malloc builds.
(In reply to Ehsan Akhgari [:ehsan] from comment #30)
> (In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #27)
> > (In reply to Vladan Djeric (:vladan) from comment #25)
> > > Kyle: If we stop destroying these wrappers on shutdown, are we interfering
> > > with the destruction of other objects? e.g. if a cross-compartment wrapper
> > > references a native object that only saves data on destruction, would this
> > > change lead to data loss?
> > 
> > Only if without cutting these wrappers we leak.
> 
> Hmm, and why is that OK?

Why is what ok?
(In reply to comment #32)
> (In reply to Ehsan Akhgari [:ehsan] from comment #30)
> > (In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #27)
> > > (In reply to Vladan Djeric (:vladan) from comment #25)
> > > > Kyle: If we stop destroying these wrappers on shutdown, are we interfering
> > > > with the destruction of other objects? e.g. if a cross-compartment wrapper
> > > > references a native object that only saves data on destruction, would this
> > > > change lead to data loss?
> > > 
> > > Only if without cutting these wrappers we leak.
> > 
> > Hmm, and why is that OK?
> 
> Why is what ok?

Not running some destructors if there is a leak caused by a cross-compartment reference.  (This is a problem in theory if those destructors persist data that will be accessible after shutdown -- I'm not sure if the implications are going to matter in practice, but I couldn't see any evidence either way in this bug.)
Because at least in theory that shouldn't cause a leak past shutdown.

I'll paste in my irc conversation with vladan.

[11:06:01] -!- Irssi: Starting query in moznet with vladan
[11:06:01] <vladan> hi. i'd like to ask for a bit more clarification on your
                    comment in the "NukeCrossCompartmentWrappers on shutdown"
                    bug.. i apologize in advance if my question misses the
                    point, i'm not at all familiar with how this part of the
                    code works.
[11:06:01] <vladan> are you saying that a cross-compartment wrapper on its own
                    can keep a native object alive during a GC, but if we
                    destroy the content pages or whatever compartment holds the
                    wrapper, everything will get properly destroyed (assuming
                    no bugs)?
[11:07:58] <khuey> well, first
[11:08:07] <khuey> a cross compartment wrapper only holds alive other JSObjects
[11:08:25] <khuey> so a cross compartment wrapper can hold alive a JSObject
                   which holds alive a native object
[11:08:29] <vladan> right
[11:08:36] <vladan> i knew that bit
[11:08:44] <khuey> k
[11:08:50] <vladan> but i did get a little loose with phrasing
[11:09:11] <khuey> so cutting the cross-compartment wrapper is essentially a
                   shortcut
[11:09:38] <khuey> normally the CCW gets destroyed when the compartment it
                   lives in gets destroyed
[11:09:49] <khuey> and that stops holding alive the JSObject in another
                   compartment
[11:10:09] <khuey> "cutting" the wrapper decouples those, so the JSObject in
                   the other compartment can (potentially) be collected before
                   the CCW is destroyed
[11:10:38] <khuey> but if everything goes according to plan when we exit all
                   the compartments will be destroyed, so the final end state
                   is the same
[11:12:34] <vladan> gotcha. we're trying to do as little cleanup as possible on
                    shutdown and instead trying to force a quick save of user
                    data & then exit(0), but it sounds like we'll have to keep
                    destroying compartments at shutdown but we can skip over
                    the nuking-wrappers step
[11:13:00] <khuey> I believe you should be able to skip nuking-wrappers, yes
[11:13:27] <khuey> it's primarily a mechanism for turning leaks-until-shutdown
                   (but not beyond) into leaks-until-the-page-is-closed
I see, thanks!
Normally, nuking shouldn't do anything except with buggy addons, but as we're testing debug builds with nuking right now, it is possible that we're in a state where we only leak without nuking, or will get into that state later.

I don't recall how the nuking works right now, but is it going to take something like O(number of content compartments * number of compartments), because it is nuking each compartment one at a time? I could imagine a faster approach that just iterates over all CCW maps once, and nukes any pointers to content compartments. Maybe not worth the effort, though.
(Assignee)

Comment 37

5 years ago
(In reply to Andrew McCreight [:mccr8] from comment #36)
> I could imagine a
> faster approach that just iterates over all CCW maps once, and nukes any
> pointers to content compartments. Maybe not worth the effort, though.

If you think it can be faster it's worth investigating. This function show up in normal profiles too so it should help navigation speed.
(In reply to Benoit Girard (:BenWa) from comment #37)
> If you think it can be faster it's worth investigating. This function show
> up in normal profiles too so it should help navigation speed.

It would depend on how many compartments we're destroying at a time. (And whether I'm right about how it is done, I may not be.) If we're just doing one at a time, then I'm not sure what we could do. Maybe we could defer destruction until some other point when we're iterating over all CCW maps anyways.
We could improve the algorithmic efficiency at shutdown where we're nuking all of the content compartments.  Not nuking at shutdown improves it even more, of course.  It's not at all clear to me how we would make it more efficient during navigation.
https://hg.mozilla.org/mozilla-central/rev/59f96e3a86d3
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla20
(Assignee)

Comment 41

5 years ago
After this landed metrics show a drop of about 1 second or 1/3. We only have 2 days of data but it looks very promising.
(In reply to Benoit Girard (:BenWa) from comment #41)
> After this landed metrics show a drop of about 1 second or 1/3. We only have
> 2 days of data but it looks very promising.

That's amazing
(Assignee)

Comment 43

5 years ago
With the metrics reprocessed I don't see any drops during that day but it makes a big difference when looking at individual profiles. I don't understand why metrics and profiling results are showing such a difference.
Is there any way I can test this?
(Assignee)

Comment 45

5 years ago
Yes:
For a build with and without this patch
1) Install the Gecko Profiler Extension:
https://developer.mozilla.org/en-US/docs/Performance/Profiling_with_the_Built-in_Profiler#Running_the_profiler
2) Select 'Profile Restart'
3) When the browser re-opens the second profile should be of the shutdown. There should be significantly less time spent in NukeCrossCompartmentWrappers. Note that the addon SDK is still calling this function on shutdown so it wont be totally gone.
(Assignee)

Comment 46

5 years ago
Alternatively you might be able to just measure the apparent difference.

1) Create a fresh firefox profile
2) Enable telemetry from about:telemetry
3) In a nightly from the 9th and the 10th repeat the following to get a few data point
 a) Open the browser, load cnn.com and wait 20 seconds for the start-up to stabilize (otherwise it will impact shutdown).
 b) Close the browser
 c) Open about:telemetry and under 'Simple Measurement' note 'shutdownDuration'

This should give a few data point of shutdown time for 9th and the 10th.
(In reply to Benoit Girard (:BenWa) from comment #46)
> Alternatively you might be able to just measure the apparent difference.
> 
> 1) Create a fresh firefox profile
> 2) Enable telemetry from about:telemetry
> 3) In a nightly from the 9th and the 10th repeat the following to get a few
> data point
>  a) Open the browser, load cnn.com and wait 20 seconds for the start-up to
> stabilize (otherwise it will impact shutdown).
>  b) Close the browser
>  c) Open about:telemetry and under 'Simple Measurement' note
> 'shutdownDuration'
> 
> This should give a few data point of shutdown time for 9th and the 10th.

Sorry for the delay. I tested on a nightly from 10th January (build ID: 20130110030939)using this scenario. Here is a google doc of the results: https://docs.google.com/spreadsheet/ccc?key=0AjbDkQ2Zlg86dDk3Z2RaOFMzS084enBqVmRPc2JFMVE&usp=sharing
If you think this should be reopened please do so, Thanks.
Status: RESOLVED → VERIFIED

Comment 49

11 months ago
cleopatra still points to this bug when nuke-CCW jank occurs during a session (not just during shutdown).

maybe it should point to bug 816784 instead

Updated

4 months ago
See Also: → bug 816784
You need to log in before you can comment on or make changes to this bug.