1324176 - Storage test paths (enabled in official builds) create thousands of main process compartments

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect)

Description

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

# Context

As part of investigating perf issues with my main profile, I noticed many thousands of main process compartments being created in about:memory:

1,769 (100.0%) -- js-main-runtime-compartments
├──1,043 (58.96%) -- user
   ├────813 (45.96%) -- (813 tiny)

Nearly of all of these are listed as "moz-nullprincipal:{some GUID here}".

# Code Path

After debugging compartment creation in various places, I learned that the following stack trace is triggering these compartments:

    XUL`xpc::CreateGlobalObject(cx=0x00000001087ae000, clasp=0x000000010ec34040, principal=0x00000001833a6160, aOptions=0x00007fff5bfb9c20) + 298 at nsXPConnect.cpp:398 [opt]
    XUL`mozilla::dom::SimpleGlobalObject::Create(globalType=BindingDetail, proto=<unavailable>) + 390 at SimpleGlobalObject.cpp:117 [opt]
    XUL`mozilla::dom::OriginAttributesPatternDictionary::Init(this=0x00007fff5bfb9dd8, aJSON=u"") + 72 at ChromeUtilsBinding.cpp:446 [opt]
    XUL`mozilla::dom::DOMStorageManager::Observe(this=0x0000000120604820, aTopic="test-flushed", aOriginAttributesPattern=<unavailable>, aOriginScope="") + 72 at DOMStorageManager.cpp:512 [opt]
    XUL`mozilla::dom::DOMStorageObserver::Observe(nsISupports*, char const*, char16_t const*) + 32 at DOMStorageObserver.cpp:120 [opt]
    XUL`mozilla::dom::DOMStorageObserver::Observe(this=<unavailable>, aSubject=<unavailable>, aTopic=<unavailable>, aData=<unavailable>) + 3896 at DOMStorageObserver.cpp:324 [opt]
    XUL`nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) + 79 at nsObserverList.cpp:112 [opt]
    XUL`nsObserverService::NotifyObservers(this=<unavailable>, aSubject=<unavailable>, aTopic=<unavailable>, aSomeData=<unavailable>) + 160 at nsObserverService.cpp:281 [opt]
    XUL`mozilla::dom::DOMStorageDBThread::NotifyFlushCompletion(this=0x00000001217b1780) + 69 at DOMStorageDBThread.cpp:729 [opt]
    XUL`mozilla::detail::RunnableMethodImpl<void (mozilla::dom::DOMStorageDBThread::*)(), false, false>::Run() [inlined] decltype(o=<unavailable>, m=<unavailable>).*fp0(Get<>(fp1).PassAsParameter())) mozilla::detail::RunnableMethodArguments<>::applyImpl<mozilla::dom::DOMStorageDBThread, void (mozilla::dom::DOMStorageDBThread::*)()>(mozilla::dom::DOMStorageDBThread*, void (mozilla::dom::DOMStorageDBThread::*)(), mozilla::Tuple<>&, mozilla::IndexSequence<>) + 23 at nsThreadUtils.h:791 [opt]
    XUL`mozilla::detail::RunnableMethodImpl<void (mozilla::dom::DOMStorageDBThread::*)(), false, false>::Run() [inlined] _ZN7mozilla6detail23RunnableMethodArgumentsIJEE5applyINS_3dom18DOMStorageDBThreadEMS5_FvvEEEDTcl9applyImplfp_fp0_dtdefpT10mArgumentscvNS_13IndexSequenceIJEEE_EEEPT_T0_(o=<unavailable>, m=<unavailable>) at nsThreadUtils.h:797 [opt]
    XUL`mozilla::detail::RunnableMethodImpl<void (mozilla::dom::DOMStorageDBThread::*)(), false, false>::Run(this=<unavailable>) + 16 at nsThreadUtils.h:826 [opt]
    XUL`nsThread::ProcessNextEvent(this=<unavailable>, aMayWait=<unavailable>, aResult=0x00007fff5bfba3c7) + 726 at nsThread.cpp:1213 [opt]
    XUL`NS_ProcessPendingEvents(aThread=<unavailable>, aTimeout=<unavailable>) + 95 at nsThreadUtils.cpp:323 [opt]
    XUL`nsBaseAppShell::NativeEventCallback(this=0x00000001089a0b30) + 103 at nsBaseAppShell.cpp:97 [opt]
    XUL`nsAppShell::ProcessGeckoEvents(aInfo=0x00000001089a0b30) + 296 at nsAppShell.mm:392 [opt]

The steps involved here seem to be:

1. DOMStorageDBThread::NotifyFlushCompletion sends “domstorage-test-flushed” observer notification
2. DOMStorageObserver::Notify forwards to observer sinks as “test-flushed”
3. One of the sinks is DOMStorageManager::Observe, which inits OriginAttributesPattern object by parsing the JSON form
4. OriginAttributesPatternDictionary::Init calls SimpleGlobalObject::Create
5. SimpleGlobalObject::Create creates the null principal compartment

# Symptoms

With my large main profile, this issue triggers the following effects:

* ~3000 domstorage-test-flushed observer notifications sent during Firefox startup for profile with ~250 tabs
* ~1000 null principal compartments alive in main process from the OriginAttributesPattern created in this code path at any given moment
* During normal operation, they seem to go uncollected for a long time
* Forcing a GC from about:memory does collect them, but more appear soon after this

# Questions

1. "domstorage-test-flushed" appears to only be meaningful for the test suite.  It is wrapped inside #ifdef DOM_STORAGE_TESTS, which is defined when ENABLE_TESTS is true[1].  Unfortunately, ENABLE_TESTS is true for nearly every Firefox build, including official builds for every release channel, so these notifications are sent in release builds.  Can we switch to having the test case that cares about this first enable a testing mode, so that this doesn't run at all in normal use?

2. Is it expected for the GC to leave many (seemingly useless) compartments alive like this for extended periods?  I am guessing overall GC performance lags because of the high volume of compartments flying around.

[1]: http://searchfox.org/mozilla-central/rev/f680e72cc6579f90b992b63ca14d923d2afea612/dom/storage/moz.build#33-34

Comment 1

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

It seems like this has been around since 2013 (bug 600307).  :mayhemer, since you worked on that bug, any thoughts on how to proceed with disabling this in regular use (see question 1 above)?

Comment 2

[Olli Pettay [:smaug][[e-mail]]]

SimpleGlobalObject is relatively new thing, and isn't that which is causing all the extra compartments ? I happened to learn about existence of SimpleGlobalObject last week, and am not familiar with it yet . See bug 1246153

Comment 3

[Honza Bambas (:mayhemer)]

(In reply to J. Ryan Stinnett [:jryans] (use ni?) from comment #1)
> It seems like this has been around since 2013 (bug 600307).  :mayhemer,
> since you worked on that bug, any thoughts on how to proceed with disabling
> this in regular use (see question 1 above)?

Oh, my beloved OriginAttributes JS sound again! :)

To have the simplest solution here, we can juts move the |"test-flushed"| block at the top of the method, before |OriginAttributesPattern pattern;|.  

And to make this even more optimal, we could also introduce some runtime switch (best in domstoragemanager) to enable/disable these notifications.  Note that there is a very important test based on them, which I really would like to keep enabled.

Comment 4

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

I'll add a pref to control the testing behavior.

Comment 5

[Boris Zbarsky [:bzbarsky]]

SimpleGlobalObject is _not_ supposed to be expensive.  We use it for dictionary stuff, as noted here, and in particular pretty much any webcrypto API call will trigger a SimpleGlobalObject creation.  The lifetime of this global is fairly precisely scoped in the dictionary case, as long as the dictionary doesn't contain any GCThings directly.  Is there a way to make this global go away quickly in those cases?

Comment 6

[Boris Zbarsky [:bzbarsky]]

The other option, of course, is to just have an extra long-lived per-thread global for doing dictionary stuff...

Comment 7

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

Attachment: Bug 1324176 - Control DOM storage testing paths with pref.

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

Comment 8

[Jon Coppeard (:jonco) (PTO until 10th March)]

(In reply to J. Ryan Stinnett [:jryans] (use ni?) from comment #0)
> 2. Is it expected for the GC to leave many (seemingly useless) compartments
> alive like this for extended periods?

No this is not expected.

(Disclaimer - I'm not familiar with this dictionary stuff)

SimpleGlobalObject::Create doesn't specify which zone to create the new global in so they will each get a fresh zone.  Our GC triggers are based on memory allocation so it may be that these zone just don't get selected for collection very often.

Maybe we could change this to allocate these globals in the system zone, which will definitely get collected.  Alternatively, having a single global object per thread for doing this sounds like a great idea.

Comment 9

[Honza Bambas (:mayhemer)]

Comment on attachment 8820076 [details]
Bug 1324176 - Control DOM storage testing paths with pref.

https://reviewboard.mozilla.org/r/99604/#review100172

Thanks!

when you are here, you can probably remove the "localStorageCommon.js" script inclusion from here:
https://dxr.mozilla.org/mozilla-central/rev/567894f026558e6dada617a3998f29aed06ac7d8/dom/tests/mochitest/localstorage/test_lowDeviceStorage.html#6

Comment 10

[Honza Bambas (:mayhemer)]

Comment on attachment 8820076 [details]
Bug 1324176 - Control DOM storage testing paths with pref.

https://reviewboard.mozilla.org/r/99604/#review100174

::: dom/tests/mochitest/localstorage/test_bug600307-DBOps.html:33
(Diff revision 1)
>  */
>  
>  function startTest()
>  {
> +  // Enable testing observer notifications
> +  SpecialPowers.pushPrefEnv({ "set": [["dom.storage.testing", true]] }, function() {

nit: could we have a function in the localStorageCommon.js doing this?  like:

localStorageEnableTestInternals(function() {
..
});

Comment 11

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

Comment on attachment 8820076 [details]
Bug 1324176 - Control DOM storage testing paths with pref.

https://reviewboard.mozilla.org/r/99604/#review100172

Updated to remove `localStorageCommon.js` from `test_lowDeviceStorage.html`.

Comment 12

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

Comment on attachment 8820076 [details]
Bug 1324176 - Control DOM storage testing paths with pref.

https://reviewboard.mozilla.org/r/99604/#review100174

> nit: could we have a function in the localStorageCommon.js doing this?  like:
> 
> localStorageEnableTestInternals(function() {
> ..
> });

Added `localStorageEnableTestingMode` to `localStorageCommon.js`.

Comment 13

[J. Ryan Stinnett [:jryans] (Use needinfo, replies may be slow)]

Comment on attachment 8820076 [details]
Bug 1324176 - Control DOM storage testing paths with pref.

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

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/da7210e8c51a
Control DOM storage testing paths with pref. r=mayhemer

Comment 15

[Boris Zbarsky [:bzbarsky]]

> Our GC triggers are based on memory allocation so it may be that these zone just don't get selected for collection very often.

Can we explicitly ask them to be collected once we know we're done with them?  That would be ideal in some ways.

> Maybe we could change this to allocate these globals in the system zone, which will definitely get collected.

Even in content processes?

> Alternatively, having a single global object per thread for doing this sounds like a great idea.

It's got some annoying downsides, which is why we didn't do it that way.  In particular:

1)  We really want to ensure that there is never any crosstalk between consumers.  This is easy right now: they're in separate globals that don't know about each other.  But using a single global requires quite some auditing to ensure this invariant.

2)  The global has to be stored somewhere (not totally trivial) and you can actually get more long-term bloat because it and its gc arenas stick around forever.

Comment 16

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/da7210e8c51a

Comment 17

[Sylvestre Ledru [:Sylvestre]]

I guess we want this to ride the trains with 53.

Comment 18

[Jon Coppeard (:jonco) (PTO until 10th March)]

(In reply to Boris Zbarsky [:bz] (still a bit busy) from comment #15)
> Can we explicitly ask them to be collected once we know we're done with
> them?  That would be ideal in some ways.

CycleCollectedJSContext::AddZoneWaitingForGC looks like it will queue the zone for collection the next time we GC.

Alternatively, you could perform an immediate GC of just that zone.  This should be quick since nothing will actually get marked.  But don't do this if there's an ongoing incremental GC though because it will abort that GC first which involves non-incrementally finishing at least some part of it.

Comment 19

[Boris Zbarsky [:bzbarsky]]

OK, I poked at this a bit.  Looks like AddZoneWaitingForGC() doesn't do much here; probably because we need the CC to run too.  And once it runs, it calls AddZoneWaitingForGC anyway.

But using the system zone does help clean things up a bit more quickly (<300ms after we finalize the first SimpleGlobalObject in a testcase where I allocated 5000 of them, as opposed to multiple seconds).  So we should at least do that.  Filed bug 1326301 on that.