Last Comment Bug 1308332 - [meta] The add-on SDK's module system is a performance disaster
: [meta] The add-on SDK's module system is a performance disaster
Status: NEW
[e10s-multi:M2]
: meta, perf
Product: Add-on SDK
Classification: Client Software
Component: General (show other bugs)
: unspecified
: All All
-- normal with 9 votes (vote)
: ---
Assigned To: Nobody; OK to take it and work on it
:
:
Mentors:
Depends on: 1314861 1315331 1309350 1309351 1313198 1313408
Blocks: e10s-addons e10s-multi triaged-tracking 1305368 1308656
  Show dependency treegraph
 
Reported: 2016-10-06 14:47 PDT by Markus Stange [:mstange]
Modified: 2017-02-14 19:43 PST (History)
41 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
50+


Attachments
startup without addons (119.43 KB, text/plain)
2016-10-06 14:48 PDT, Markus Stange [:mstange]
no flags Details
startup with Test Pilot + Tab Center + Activity Stream (237.32 KB, text/plain)
2016-10-06 14:48 PDT, Markus Stange [:mstange]
no flags Details

Description User image Markus Stange [:mstange] 2016-10-06 14:47:40 PDT
While looking into startup performance in bug 1308326, I found out that add-on SDK addons are spending a surprising amount of time (4+ seconds!) in require(), before doing any actual work.

There seem to be multiple problems here:

(1) JS files are re-evaluated every time they are require()d.

If you have a require tree like this:
a.js
 - b.js
    - c.js
 - c.js

Then a simple call to require('a') will evaluate c.js twice.

(2) readURI is called a lot and/or very slow.

readURI is called as part of require. In this profile, readURI on its own takes up at least 1.5 seconds of startup (probably more, because the first 8 seconds of startup are missing because the profile buffer was too small):
https://cleopatra.io/#report=07b15e5c88a431b4fa5e41982caeb4c92003cae1&filter=%5B%7B%22type%22%3A%22FocusedFrameSampleFilter%22,%22name%22%3A%22readURI()%20%40%20loader.js%3A171%22,%22focusedSymbol%22%3A45%7D%5D

(3) There are so many modules.

With per-module overhead being as high as it is, having so many small modules hurts us.


I have written a tool to create a nice tree of our includes, and dumped timings for both a fresh profile and for a profile that has the addons Test Pilot, Activity Stream and Tab Center installed.

The tool is here: https://github.com/mstange/module-profiling

Results from my machine, on a fresh profile:
Without addons, the total amount of time we spend in Cu.import and require is 804.97ms.
With the three addons, it's 3844.84ms.
Comment 1 User image Markus Stange [:mstange] 2016-10-06 14:48:11 PDT
Created attachment 8798611 [details]
startup without addons
Comment 2 User image Markus Stange [:mstange] 2016-10-06 14:48:36 PDT
Created attachment 8798612 [details]
startup with Test Pilot + Tab Center + Activity Stream
Comment 3 User image Markus Stange [:mstange] 2016-10-06 14:52:39 PDT
Comment on attachment 8798612 [details]
startup with Test Pilot + Tab Center + Activity Stream

Two notable pieces of information from this file:
 - Each call to require('sdk/tabs') takes, on average, 176ms.
 - The initial require of resource://testpilot-addon/index.js takes 924.25ms.

This is on a fairly beefy Macbook Pro.
Comment 4 User image Alexandre Poirot [:ochameau] 2016-10-06 15:22:50 PDT
I faced the same issues while trying to optimize the devtools for Firefox OS, on cheap phones with limited memory and slow CPUs.
We addressed that in devtools by avoiding any dependency to the SDK which uses way too many modules
and loading modules lazily. In many cases we were loading modules that we never really used.
Also I introduced a new parameter to the SDK Loader called "sharedGlobal". It isn't necessary compatible with SDK modules (I haven't really tried to verify). But it allows to create just one Sandbox and saves **tons** of memory and also some CPU cycles.

One thing is surprising in your findings. We should not evaluate a module more than once. At least for a given addon. But I imagine that each addon is going to load its own instances (tree of modules).
One easy optimization could be to share the same loader between all these addons so that you really have just one instance for each module.

Otherwise, I've heard :yoric talking about improving Cu.import to support modules, that may become an efficient module system...
Comment 5 User image Markus Stange [:mstange] 2016-10-06 15:43:19 PDT
(In reply to Markus Stange [:mstange] from comment #0)
> (1) JS files are re-evaluated every time they are require()d.
> 
> If you have a require tree like this:
> a.js
>  - b.js
>     - c.js
>  - c.js
> 
> Then a simple call to require('a') will evaluate c.js twice.

This seems to be false. I think I was confused by "core.js", but there are lots of different core.js files in different directories.

(In reply to Alexandre Poirot [:ochameau] from comment #4)
> We should not evaluate a module
> more than once. At least for a given addon. But I imagine that each addon is
> going to load its own instances (tree of modules).

You're right, thanks for catching that.
Comment 6 User image Alexandre Poirot [:ochameau] 2016-10-07 02:45:24 PDT
Oh!

It looks like the loader uses readURI at extreme. I'm not sure devtools get into this codepath, it seems to be related to some node compatiblity code.
It doesn't use readURI only for fetching a given URI content, but also just to check if a URI resolves to something :/

http://searchfox.org/mozilla-central/source/addon-sdk/source/lib/toolkit/loader.js#503
http://searchfox.org/mozilla-central/source/addon-sdk/source/lib/toolkit/loader.js#525
http://searchfox.org/mozilla-central/source/addon-sdk/source/lib/toolkit/loader.js#531

Ideally, all modules will just get loaded using loadSubScript and I think devtools gets into this more sane practice and codepaths:
  http://searchfox.org/mozilla-central/source/addon-sdk/source/lib/toolkit/loader.js#279
Comment 7 User image :Ehsan Akhgari 2016-10-07 08:23:39 PDT
Do I understand correctly that readURI also reads the entire contents of the file *synchronously* on the main thread every time it's called? :(
Comment 8 User image :Ehsan Akhgari 2016-10-07 08:24:20 PDT
Also, given these performance issues, is it practical to ban the usage of the add-on SDK inside m-c and the system add-ons we ship to all users by default?
Comment 9 User image Chuck Harmston [:chuck] 2016-10-07 08:29:30 PDT
@Ehsan: the Test Pilot add-on itself also uses the SDK.

We've noticed some startup performance issues as well, though: https://github.com/mozilla/testpilot/issues/1370
Comment 10 User image :Ehsan Akhgari 2016-10-07 08:33:12 PDT
(In reply to Chuck Harmston [:chuck] from comment #9)
> @Ehsan: the Test Pilot add-on itself also uses the SDK.

Can we fix that?  :-)

> We've noticed some startup performance issues as well, though:
> https://github.com/mozilla/testpilot/issues/1370

Yeah.  Unfortunately it's very hard for any extension to be using the add-on SDK and have a fast startup due to this bug.  But even if it's too hard to migrate the Test Pilot add-on off of the add-on SDK, perhaps we can try using sharedGlobal as mentioned in comment 4 to see if it helps?
Comment 11 User image Chuck Harmston [:chuck] 2016-10-07 08:36:20 PDT
> Can we fix that?  :-)

We've talked about moving to a WebExtension, but there are a few APIs we need that don't exist yet. Off the top of my head:

- Sending telemetry pings
- Add-on management (i.e. AddonManager, although we were recently whitelisted to use the mozAddonManager and have plans [1] to use it more globally)

[1] https://github.com/mozilla/testpilot/issues/1344
Comment 12 User image Wil Clouser [:clouserw] 2016-10-07 08:57:13 PDT
Test Pilot as a webextension is https://bugzilla.mozilla.org/show_bug.cgi?id=1280233
Comment 13 User image Kris Maglione [:kmag] 2016-10-07 10:01:53 PDT
(In reply to Alexandre Poirot [:ochameau] from comment #6)
> Oh!
> 
> It looks like the loader uses readURI at extreme. I'm not sure devtools get
> into this codepath, it seems to be related to some node compatiblity code.
> It doesn't use readURI only for fetching a given URI content, but also just
> to check if a URI resolves to something :/

Ugh.

(In reply to Alexandre Poirot [:ochameau] from comment #4)
> Also I introduced a new parameter to the SDK Loader called "sharedGlobal".
> It isn't necessary compatible with SDK modules (I haven't really tried to
> verify). But it allows to create just one Sandbox and saves **tons** of
> memory and also some CPU cycles.
>
> One thing is surprising in your findings. We should not evaluate a module
> more than once. At least for a given addon. But I imagine that each addon is
> going to load its own instances (tree of modules).
> One easy optimization could be to share the same loader between all these
> addons so that you really have just one instance for each module.

Unfortunately, the built-in SDK modules are written with the assumption that
each add-on gets its own instances of all modules, so that's not really doable
without a nearly complete rewrite.

We should be able to use a shared global at least for all built-in modules
pretty safely, though. And we can definitely make most of their internal
imports lazy.

There might be add-on compatibility problems if their own modules don't get
individual globals, but we could test that with a slow rollout...

There might be some other optimizations we can get away with for internal
modules, too. The most obvious possibility I can think of is to compile all of
the SDK module into a single script (similar to Browserify), with each module
stored in a closure. That would get rid of most of the per-module overhead,
and also possibly allow us to keep the built-in modules for all add-ons in a
single compartment.
Comment 14 User image Zibi Braniecki [:gandalf][:zibi] 2016-10-07 10:27:40 PDT
Not sure how related it is but while working on L20n we tested many ways to load a resource - NetUtil, OS.File and XHR - both sync and async.

XHR with use system principal is *by far* the fastest, with NetUtil being almost 2x slower and OS.File being many times slower. If I remember correctly SDK uses NetUtil?
Comment 15 User image Markus Stange [:mstange] 2016-10-07 10:55:57 PDT
So, in the order of low risk to high risk, I think these are the steps that have been identified to fix this:

 - Speed up readURI:
    - make sure the node compatibility code is not run in Firefox (and maybe not even ship that code in Firefox)
    - don't read directories (all those files are packaged in omni.ja, right? we should already have a list of available files)
    - whatever remaining work readURI needs to do, make sure it only does it once per file, for example by caching the results keyed by the string URI
 - Find faster ways of reading the files themselves
 - investigate sharing the global between the includes of one addon
 - investigate sharing the loader between addons

(In reply to Kris Maglione [:kmag] from comment #13)
> There might be some other optimizations we can get away with for internal
> modules, too. The most obvious possibility I can think of is to compile all of
> the SDK module into a single script (similar to Browserify), with each module
> stored in a closure. That would get rid of most of the per-module overhead,
> and also possibly allow us to keep the built-in modules for all add-ons in a
> single compartment.

This seems like a very worthwhile pursuit, independent from (and somewhat orthogonal to) the speedups above.
Comment 16 User image Kris Maglione [:kmag] 2016-10-07 12:05:53 PDT
(In reply to Markus Stange [:mstange] from comment #15)
>  - Speed up readURI:

I think this is less a matter of speeding up readURI as a matter of not using
it, except in the couple of cases where it's used to load JSON files.

>     - make sure the node compatibility code is not run in Firefox (and maybe
> not even ship that code in Firefox)

It is, unfortunately, necessary for Jetpack add-ons. But I think its
performance can be improved considerably.

>     - don't read directories (all those files are packaged in omni.ja,
> right? we should already have a list of available files)

Only for built-in modules. But, yes, we already have a list in-memory for
omni.ja and add-ons loaded from XPIs.

>     - whatever remaining work readURI needs to do, make sure it only does it
> once per file, for example by caching the results keyed by the string URI

readURI doesn't need to be used at all to load modules, with the exception of
JSON files.

>  - Find faster ways of reading the files themselves

The files themselves are loaded via loadSubScript, which means that they
should actually be loaded from the startup cache the vast majority of the
time.

>  - investigate sharing the loader between addons

This is a non-starter.

> (In reply to Kris Maglione [:kmag] from comment #13)
> > There might be some other optimizations we can get away with for internal
> > modules, too. The most obvious possibility I can think of is to compile all of
> > the SDK module into a single script (similar to Browserify), with each module
> > stored in a closure. That would get rid of most of the per-module overhead,
> > and also possibly allow us to keep the built-in modules for all add-ons in a
> > single compartment.
> 
> This seems like a very worthwhile pursuit, independent from (and somewhat
> orthogonal to) the speedups above.

I'm not sure it is. It seems like a significant chunk of the startup overhead
is from the SDK individually loading dozens of tiny modules. Removing that
overhead won't help with modules provided by add-ons themselves, but it should
help a lot with the built-in overhead.
Comment 17 User image Markus Stange [:mstange] 2016-10-07 12:18:12 PDT
Sounds good, thanks.

(In reply to Kris Maglione [:kmag] from comment #16)
> Removing that
> overhead won't help with modules provided by add-ons themselves,

This is the reason I think it's somewhat orthogonal - we'll need to fix perf for both cases.
Comment 18 User image Kris Maglione [:kmag] 2016-10-07 12:32:55 PDT
(In reply to Markus Stange [:mstange] from comment #17)
> Sounds good, thanks.
> 
> (In reply to Kris Maglione [:kmag] from comment #16)
> > Removing that
> > overhead won't help with modules provided by add-ons themselves,
> 
> This is the reason I think it's somewhat orthogonal - we'll need to fix perf
> for both cases.

I think that the built-in modules are a big enough chunk of the problem to warrant special treatment. Most SDK add-ons are fairly simple, with a small number of modules of their own. But even the simplest ones pull in dozens of built-in modules.

I'd be willing to bet that just fixing the issues with built-in modules would make this only a minor issue for the vast majority of add-ons (by number of add-ons, anyway; perhaps not by usage). And since the built-in modules affect literally all SDK add-ons, and we can make more extreme changes to them without breaking add-ons in the wild, I think it's worth treating them specially.
Comment 19 User image Markus Stange [:mstange] 2016-10-07 12:46:58 PDT
(In reply to Kris Maglione [:kmag] from comment #18)
> I'd be willing to bet that just fixing the issues with built-in modules
> would make this only a minor issue for the vast majority of add-ons (by
> number of add-ons, anyway; perhaps not by usage).

That's probably true. But if we can fix the "minor issue" as well, then we should do so.

> And since the built-in
> modules affect literally all SDK add-ons, and we can make more extreme
> changes to them without breaking add-ons in the wild, I think it's worth
> treating them specially.

Absolutely! I'm not disagreeing.
Comment 20 User image Kris Maglione [:kmag] 2016-10-07 13:04:07 PDT
For reference, here's the list of 139 built-in modules that I get from about:memory for a single SDK add-on:

https://gist.github.com/278ccfc3021203cdd539f40f37985696

Oh, and somehow all of these seem to be loaded twice, once with ./ and once without:

 36,864 B (00.01%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/core/heritage.js
 21,120 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/core/namespace.js
 24,848 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/core/promise.js
 17,344 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/net/url.js
 26,480 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/platform/xpcom.js
 33,112 B (00.01%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/preferences/service.js
 27,192 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/system/events.js
 23,944 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/system/unload.js
 32,712 B (00.01%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/timers.js
 17,624 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/uri/resource.js
 18,344 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/util/array.js
 16,752 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/util/object.js
 16,616 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./sdk/util/uuid.js
 22,888 B (00.00%) ++ compartment([System Principal], resource://gre/modules/commonjs/./toolkit/loader.js

(In reply to Markus Stange [:mstange] from comment #19)
> (In reply to Kris Maglione [:kmag] from comment #18)
> > I'd be willing to bet that just fixing the issues with built-in modules
> > would make this only a minor issue for the vast majority of add-ons (by
> > number of add-ons, anyway; perhaps not by usage).
>
> That's probably true. But if we can fix the "minor issue" as well, then we
> should do so.

Sure. What I'm mainly trying to say is that I think we should tackle the built-in modules first, rather than treating it as a separate, orthogonal issue, since I suspect it will fix the biggest part of the problem.
Comment 21 User image Alexandre Poirot [:ochameau] 2016-10-10 03:32:06 PDT
(In reply to :Ehsan Akhgari from comment #8)
> Also, given these performance issues, is it practical to ban the usage of
> the add-on SDK inside m-c and the system add-ons we ship to all users by
> default?

It sounds like a hard requirement coming a bit late now that all the addons are written.
But I do agree that Test pilot and system addons should look seriously into WebExtension and use it as much as possible even if that means having hybrid addon with a bootsrap.js doing some chrome things.

> (In reply to Alexandre Poirot [:ochameau] from comment #4)
> Unfortunately, the built-in SDK modules are written with the assumption that
> each add-on gets its own instances of all modules, so that's not really
> doable
> without a nearly complete rewrite.

You are thinking about all SDK addons, but here I'm suggesting tweaks for just some addons.
We do used sharedGlobals in Devtools without any issue.
Same for node resolution. I don't think we use that in devtools either and are able to have a fully working loader working with a couple of sdk modules.

And I agree with Markus, there is so many ways to improve the current situation that we should not limit ourself to agree and do just one thing. Patches!
Markus, if you do have patches against loader.js, do not hesitate to r? me. I used to be reviewing that file ages ago.
Comment 22 User image Gabor Krizsanits [:krizsa :gabor] 2016-10-10 05:07:51 PDT
*** Bug 1308867 has been marked as a duplicate of this bug. ***
Comment 23 User image Gabor Krizsanits [:krizsa :gabor] 2016-10-10 05:13:44 PDT
Hey Markus, are you actively working on this? It seems like we're struggling with the same issue. This is quite critical for e10s-multi (running firefox with multiple content processes), because there with each tab opening that spawns a new process we're hitting this issue. So if you need any help we can try to split up the tasks here to make this loader code suck less.
Comment 24 User image Markus Stange [:mstange] 2016-10-10 06:42:59 PDT
No, I am not working on this, and don't intend to work on it. Sorry for not being clear about that.
Comment 25 User image andrei 2016-10-12 07:38:18 PDT
I think this bug might have the same cause
https://bugzilla.mozilla.org/show_bug.cgi?id=1304393
Comment 26 User image Jeff Griffiths (:canuckistani) (:⚡︎) 2016-10-14 12:52:39 PDT
My $0.02: yes we should stop using the SDK for internal add-ons but we can't do this quickly. From all the comments here it sounds like there is a lot of low-hanging fruit to fix, let's re-assess after Kris has knocked off a few of those and see how bad it really is without the pathologically slow aspects of the loader involved.
Comment 27 User image andrei 2016-10-15 08:41:04 PDT
How about giving addon devs or users a per-addon setting that enables them later. Most addons these days don't require restart so if the users or the addon devs can make the addons start disabled and be enabled after Firefox starts not during startup it will seem like Firefox loads faster. I can have ublock origin become enabled 1s after firefox, keyword search 2s after and disable ctrl-q addon start 3 seconds after ff starts.
Comment 28 User image Kris Maglione [:kmag] 2016-10-17 09:21:52 PDT
(In reply to andrei from comment #27)
> How about giving addon devs or users a per-addon setting that enables them
> later. Most addons these days don't require restart so if the users or the
> addon devs can make the addons start disabled and be enabled after Firefox
> starts not during startup it will seem like Firefox loads faster. I can have
> ublock origin become enabled 1s after firefox, keyword search 2s after and
> disable ctrl-q addon start 3 seconds after ff starts.

This isn't really an option for a lot of reasons, and it doesn't help with the content process startup issues. But add-on developers can and should avoid loading code that isn't needed immediately until it is.
Comment 29 User image Kris Maglione [:kmag] 2016-10-18 09:34:11 PDT
So, just for some context, since some people have questioned the wording "is a performance disaster":

The Linux Jetpack test suite on infra usually takes about 30min for opt, 63min for debug. With the changes from bug 1309350 and bug 1309351, that's down to 15min for opt and 37min for debug on try. Which means that about 50% of the time spent in those test runs was wasted in overhead from the module loading code alone.

It's hard to say exactly how that translates to real world performance, but it's difficult to imagine that not having a major impact on startup time (both main process and child process).
Comment 30 User image Andy McKay [:andym] 2016-10-24 11:35:04 PDT
With the two depending bugs fixed, is there anything else to do here? Wondering Markus if you had chance to retest with Nightly to see if this improved things for you?
Comment 31 User image Kris Maglione [:kmag] 2016-10-24 11:44:54 PDT
I'm still investigating merging certain groups of modules into combined scripts. It looks like there are at least 70 modules that get loaded for every SDK add-on, and so far it's looking like loading them in one go gives a significant speed-up even over the previous set of changes. I'm still trying fine tuning and trying to decide whether it's worth the complexity, though.
Comment 32 User image Kris Maglione [:kmag] 2016-10-24 11:46:36 PDT
And, I'm not sure if this is strictly related, but we should also investigate lazily loading modules in SDK internal code.
Comment 33 User image Markus Stange [:mstange] 2016-10-25 12:03:20 PDT
(In reply to Andy McKay [:andym] from comment #30)
> Wondering Markus if you had chance to retest with Nightly to see if this
> improved things for you?

I've just re-run my initial tests with current mozilla-central, and it's already much better!

In a profile without addons, total time in require() + Cu.import during startup has gone down by 35%, from 805ms to 524ms.
In a profile with Test Pilot, Activity Stream and Tab Center, the total time spent in require() and Cu.import during startup has gone down by 65%, from 3844ms to 1320ms.

But this still means that having those three addons in your profile adds about a second to startup time just for loading their JS code (plus the time for actually running that code). I have high hopes for the approach mentioned in comment 31 to make a dent in this.
Comment 34 User image Andy McKay [:andym] 2016-10-25 12:26:29 PDT
(In reply to Markus Stange [:mstange] from comment #33)
> (In reply to Andy McKay [:andym] from comment #30)
> > Wondering Markus if you had chance to retest with Nightly to see if this
> > improved things for you?
> 
> I've just re-run my initial tests with current mozilla-central, and it's
> already much better!
> 
> In a profile without addons, total time in require() + Cu.import during
> startup has gone down by 35%, from 805ms to 524ms.
> In a profile with Test Pilot, Activity Stream and Tab Center, the total time
> spent in require() and Cu.import during startup has gone down by 65%, from
> 3844ms to 1320ms.

That's great news, thanks for testing.

> But this still means that having those three addons in your profile adds
> about a second to startup time just for loading their JS code (plus the time
> for actually running that code). I have high hopes for the approach
> mentioned in comment 31 to make a dent in this.

As Kris said, any further changes should probably evaluated for complexity, expected benefit and the expected lifespan of the SDK.
Comment 35 User image andrei 2016-10-26 13:40:10 PDT
Firefox starts in 3 seconds with my default profile. It used to start in like 4 or 5, even 6 sometimes. I know this is not an accurate benchmark but for a couple of days my profile has been starting constantly in 3 second with the same 8 addons I keep around for some time. This happens on 2 different machines with different OSes. This is a visible improvement! I obviously use Nightly :)
Comment 36 User image Markus Stange [:mstange] 2016-10-26 14:12:22 PDT
(In reply to Andy McKay [:andym] from comment #34)
> As Kris said, any further changes should probably evaluated for complexity,
> expected benefit and the expected lifespan of the SDK.

Just a note, the ratio of "person hours invested" vs "startup time improvement payoff" from this work was probably the best I've seen during all my time at Mozilla. If the rest of the work will be similarly effective, there's little reason not to do it.
Comment 37 User image Andy McKay [:andym] 2016-10-26 14:50:30 PDT
(In reply to Markus Stange [:mstange] from comment #36)
> (In reply to Andy McKay [:andym] from comment #34)
> Just a note, the ratio of "person hours invested" vs "startup time
> improvement payoff" from this work was probably the best I've seen during
> all my time at Mozilla. If the rest of the work will be similarly effective,
> there's little reason not to do it.

On this bug so far, there's no argument from me on that point. It's pretty nice to see this sort of win.
Comment 38 User image Alexandre Poirot [:ochameau] 2016-10-26 14:58:11 PDT
(In reply to Markus Stange [:mstange] from comment #33)
>
> In a profile without addons, total time in require() + Cu.import during
> startup has gone down by 35%, from 805ms to 524ms.
> In a profile with Test Pilot, Activity Stream and Tab Center, the total time
> spent in require() and Cu.import during startup has gone down by 65%, from
> 3844ms to 1320ms.

During your first profiling you saw readURI coming first. Did you saw another hot spot that seems to be slow? If not, may be you can share raw profile data so that we can look at other potential tweaks.
Comment 39 User image Kestrel 2016-10-31 04:50:03 PDT
I've noticed a dramatic improvement in startup and shutdown time since the fixes landed on aurora.

Configuration: Two windows with 15 tabs each and 22 addons.

Startup: 25 seconds -> 14 seconds (44% reduction)
Shutdown: 30 seconds -> 5 seconds (83% reduction) 

Shutdown used to take so long it was triggering a minidump.
Comment 40 User image The 8472 2016-11-03 08:32:29 PDT
Is it possible that these changes keep modules alive longer than they would have been previously and thus increase memory footprint and GC overhead?
Comment 41 User image The 8472 2016-11-03 09:10:01 PDT
To add some data, this is from a child process about 1 week ago:


├───83.42 MB (15.42%) -- js-non-window
│   ├──51.91 MB (09.60%) -- zones
│   │  ├──37.21 MB (06.88%) -- zone(0x1e64d7a6000)
│   │  │  ├──30.82 MB (05.70%) -- (223 tiny)
│   │  │  │  ├───4.92 MB (00.91%) ++ compartment([System Principal], Addon-SDK (from: resource://gre/modules/commonjs/toolkit/loader.js:414))

this is from nightly 02-11-2016:


├────696.55 MB (55.14%) -- js-non-window
│    ├──667.98 MB (52.88%) -- zones
│    │  ├──661.08 MB (52.33%) -- zone(0x1f2b6b86000)
│    │  │  ├──286.03 MB (22.64%) ++ compartment([System Principal], Addon-SDK (from: resource://gre/modules/commonjs/toolkit/loader.js:414))
│    │  │  ├───90.99 MB (07.20%) ++ compartment([System Principal], resource://gre/modules/commonjs/toolkit/loader.js)
│    │  │  ├───80.85 MB (06.40%) ++ shapes
│    │  │  ├───74.55 MB (05.90%) ++ scopes
│    │  │  ├───59.72 MB (04.73%) ++ (206 tiny)
│    │  │  ├───33.34 MB (02.64%) ── type-pool
│    │  │  ├───21.39 MB (01.69%) ++ object-groups
│    │  │  └───14.21 MB (01.12%) ++ compartment([System Principal], [anonymous sandbox] (from: resource://gre/modules/commonjs/toolkit/loader.js -> resource://devtools/shared/builtin-modules.js:185))

I have included the ancestor categories to show that this it's not just allocations being moved into the compartment, which is expected, but the overall footprint of the system zone increasing significantly. "tiny" also covers other addons in my case, so the SDK is really eating the lion's share here.
Comment 42 User image The 8472 2016-11-03 09:49:16 PDT
I'm also regularly seeing long CC pauses in content, which I think did not happen before

CC(T+54785.3)[content] max pause: 3420ms, total time: 3838ms, slices: 38, suspected: 171, visited: 19669 RCed and 4615878 GCed, collected: 167 RCed and 912 GCed (912|0|0 waiting for GC)
ForgetSkippable 8 times before CC, min: 1 ms, max: 6 ms, avg: 1 ms, total: 15 ms, max sync: 0 ms, removed: 663
Comment 43 User image Kris Maglione [:kmag] 2016-11-03 09:54:53 PDT
(In reply to The 8472 from comment #40)
> Is it possible that these changes keep modules alive longer than they would
> have been previously and thus increase memory footprint and GC overhead?

Not really. It's possible they may have caused a leak in some other way,
though.

(In reply to The 8472 from comment #41)
> To add some data, this is from a child process about 1 week ago:

None of these changes landed that recently. What build is it from?

> I have included the ancestor categories to show that this it's not just
> allocations being moved into the compartment, which is expected, but the
> overall footprint of the system zone increasing significantly. "tiny" also
> covers other addons in my case, so the SDK is really eating the lion's share
> here.

It's hard to make much from this. What SDK add-ons do you have installed? How
long were the profiles running in each case? How many tabs did you have open?
Comment 44 User image The 8472 2016-11-03 10:17:06 PDT
> What build is it from?

I don't know since I usually keep a FF instance open for several days. The report itself was captured on 29.10.

> What SDK add-ons do you have installed?

I think "ipfs firefox addon" and "new tab override" are the only sdk-based ones that I have. And AIUI the devetools themselves also use the SDK.

> How long were the profiles running in each case? How many tabs did you have open?

Several days, about the same amount of tabs, around 1.5k. Although we're talking about the child process. So the number of active tabs per child process probably is more important, which is about a dozen.
Comment 45 User image Andrew McCreight [:mccr8] 2016-11-03 11:02:54 PDT
(In reply to The 8472 from comment #40)
> Is it possible that these changes keep modules alive longer than they would
> have been previously and thus increase memory footprint and GC overhead?

Could you please file a separate bug for this issue? You can make it block this one if you like.
Comment 46 User image Ritu Kothari (:ritu) 2016-11-10 13:54:22 PST
Release Note Request (optional, but appreciated)
[Why is this notable]:
[Affects Firefox for Android]: 
[Suggested wording]: Performance improvements for SDK Extensions or Extensions using the module loader
[Links (documentation, blog post, etc)]:
Comment 47 User image Ritu Kothari (:ritu) 2016-11-10 13:55:14 PST
Added to Fx50 release notes.

Note You need to log in before you can comment on or make changes to this bug.