Closed Bug 819000 Opened 12 years ago Closed 11 years ago

Preload more things inside the prelaunch process

Categories

(Firefox OS Graveyard :: General, defect)

Product:
Firefox OS Graveyard
Component:
General
Platform:
x86_64
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(blocking-b2g:tef+, firefox19 wontfix, firefox20 wontfix, firefox21 fixed, b2g18+ fixed, b2g18-v1.0.0 fixed, b2g18-v1.0.1 fixed)

Status:
RESOLVED FIXED
Milestone:
B2G C4 (2jan on)
Project Flags:
blocking-b2g tef+
Tracking Flags:
Tracking Status
firefox19 --- wontfix
firefox20 --- wontfix
firefox21 --- fixed
b2g18 + fixed
b2g18-v1.0.0 --- fixed
b2g18-v1.0.1 --- fixed

People

(Reporter: vingtetun, Assigned: justin.lebar+bug)

References

Details

(Keywords: perf, Whiteboard: [fast:300ms][FFOS_perf] QARegressExclude)

Attachments

(7 files, 6 obsolete files)

Missing preload.js file
3.90 KB, application/javascript
Details
Patch, v2
6.15 KB, patch
cjones
: review+
akeybl
: approval-mozilla-b2g18+
Details | Diff | Splinter Review
Preload about:blank
958 bytes, patch
cjones
: review+
cjones
: approval-mozilla-b2g18+
Details | Diff | Splinter Review
Bail out of PresShell::Paint if not active
864 bytes, patch
roc
: review+
Details | Diff | Splinter Review
Make sure preloaded docshells are reset to active, v1.1
2.89 KB, patch
justin.lebar+bug
: review+
Details | Diff | Splinter Review
Rollup for landing on b2g18
4.93 KB, patch
cjones
: review+
Details | Diff | Splinter Review
Preload more things - again.
49.22 KB, patch
Details | Diff | Splinter Review
Attached patch dirty wip (obsolete) — — Splinter Review 
It seems like we can preload more things. I would like to see how does it sounds?

(The patch is really really ugly but I mostly want to know if the approach make sense or not. Delegating some parts of what is done in BrowserElementChild._init to a preload.js file that is loaded when the process is created).

On a build with this patch applied and the 'Show time to load' option in the developer settings of Gaia the calculator takes:
 - 913, 946, 923, 1078, 944


(hmm the times seems too good in this build, I wonder if I have done something wrong with CSP)

And without the patch it takes:
 - 1243, 1233, 1277, 1249, 1268

The time seems to vary depending on the app.

The 'Show time to load' function takes into account the mozbrowserfirstpaint option.
Comment on attachment 689305 [details] [diff] [review]
dirty wip

Sorry for this really dirty patch. I just want to know about the approach.
Attachment #689305 - Flags: feedback?(justin.lebar+bug)
Attachment #689305 - Flags: feedback?(jones.chris.g)
Comment on attachment 689305 [details] [diff] [review]
dirty wip

This approach makes sense (it's been on my list for a while), but based on my previous measurements loading and compiling the preload.js file itself will probably be a 50ms hit.  If it's possible to sneak this code into a file that's already being run I'd prefer that.
Attachment #689305 - Flags: feedback?(jones.chris.g) → feedback+
Comment on attachment 689305 [details] [diff] [review]
dirty wip

Looks reasonable to me!
Attachment #689305 - Flags: feedback?(justin.lebar+bug) → feedback+
Blocks: slim-fast
Whiteboard: [fast:300ms]
Attached patch dirty wip0.2 (obsolete) — — Splinter Review 
This one breaks scrolling into in-process frame. But it starts to be usable.
Attached patch dirty wip0.3 (obsolete) — — Splinter Review 
Last dirty wip. Real patch coming soon.
Attachment #689305 - Attachment is obsolete: true
Attachment #690784 - Attachment is obsolete: true
I just re-profiled (now with the FM radio app, with headphones unplugged), and it still takes ~1200ms to open.

I'll try to resurrect this patch.
Assignee: nobody → justin.lebar+bug
Vivien, what is the purpose of these changes?  Were they just for your testing, or do they do something useful?

diff --git a/dom/apps/src/Webapps.jsm b/dom/apps/src/Webapps.jsm
index e37d7ae..c2ac243 100644
--- a/dom/apps/src/Webapps.jsm
+++ b/dom/apps/src/Webapps.jsm
@@ -64,7 +64,7 @@ this.DOMApplicationRegistry = {
   appsFile: null,
   webapps: { },
   children: [ ],
-  allAppsLaunchable: false,
+  allAppsLaunchable: true,
   downloads: { },
 
   init: function() {
@@ -1871,6 +1871,7 @@ this.DOMApplicationRegistry = {
   _isLaunchable: function(aOrigin) {
     if (this.allAppsLaunchable)
       return true;
+    return true;
 
 #ifdef XP_WIN
     let uninstallKey = Cc["@mozilla.org/windows-registry-key;1"]
diff --git a/b2g/chrome/content/shell.js b/b2g/chrome/content/shell.js
@@ -262,17 +261,16 @@ var shell = {
     window.addEventListener('keyup', this, true);
     window.addEventListener('MozApplicationManifest', this);
     window.addEventListener('mozfullscreenchange', this);
     window.addEventListener('sizemodechange', this);
     this.contentBrowser.addEventListener('mozbrowserloadstart', this, true);
 
     CustomEventManager.init();
     WebappsHelper.init();
-    AccessFu.attach(window);
     UserAgentOverrides.init();
 
     // XXX could factor out into a settings->pref map.  Not worth it yet.
     SettingsListener.observe("debug.fps.enabled", false, function(value) {
       Services.prefs.setBoolPref("layers.acceleration.draw-fps", value);
     });
     SettingsListener.observe("debug.paint-flashing.enabled", false, function(value) {
       Services.prefs.setBoolPref("nglayout.debug.paint_flashing", value);
Sorry, I meant to ask in comment 8: Why is this change safe?  Is it just that we don't need AccessFu in B2G?
> +  content/scrolling.js                  (content/scrolling.js)

Did you forget to attach this file, or should I just delete this?
Flags: needinfo?(21)
(In reply to Justin Lebar [:jlebar] from comment #6)
> I just re-profiled (now with the FM radio app, with headphones unplugged),
> and it still takes ~1200ms to open.
> 
> I'll try to resurrect this patch.

Sorry for having let this bug in this state. I tried to add too many preloaded things, got stuck and the bug moved out of my radar. I will try to find the latest version of the patch I have and may even work on it again except if you insist to do it?
Flags: needinfo?(21)
That's the only important part of the patch (and the missing file you were looking at). All the rest is distraction :)

Thanks for looking into this.
I worked on this on the plane.

I found that just doing

  docShell.loadURI("about:blank")

shaved off ~500ms from app startup.  Loading the JSMs shaved off another ~100ms.  I didn't try preloading the services, as in the attached preload.js (I was rewriting it from scratch without an internet connection).

Unfortunately there appears to be a race condition with the docShell.loadURI call.  If I call loadURI right at the end of my frame script, apps load as a blank white page.  But if I stick some dump()s after the loadURI call, apps load fine.

I can work around this by moving the loadURI call before the loading of the JSMs, but that scares me.  So I think I need to take a closer look at this.  Hopefully it's something simple...
Hmmm.

I verified that the about:blank loads happen before the loads that are apparently being clobbered.  I also tried adding a call to nsIWebNavigation::Stop(STOP_ALL) which happens after the about:blank load and before the app loads.  This didn't change anything.

bz, do you have any idea of what might be going on here (wrt the race described in comment 13)?  It would be awesome to have this for b2g v1, but I don't want to land something risky at this point.
Flags: needinfo?(bzbarsky)
> bz, do you have any idea of what might be going on here (wrt the race described in
> comment 13)?

Does it help to do a stop() _before_ your about:blank load?  You might have two about:blank loads racing there...

Past that, I think I need more context.  :(  Can you catch me on irc?
Flags: needinfo?(bzbarsky)
(In reply to Justin Lebar [:jlebar] from comment #13)
> I worked on this on the plane.
> 
> I found that just doing
> 
>   docShell.loadURI("about:blank")
> 
> shaved off ~500ms from app startup.  Loading the JSMs shaved off another
> ~100ms.  I didn't try preloading the services, as in the attached preload.js
> (I was rewriting it from scratch without an internet connection).

Most of the service started by the script are based on investigating which services are loaded by loading the template application so the list should be fine - even if it can probably be nail down if the docShell.loadURI("about:blank") call is used.

> 
> Unfortunately there appears to be a race condition with the docShell.loadURI
> call.  If I call loadURI right at the end of my frame script, apps load as a
> blank white page.  But if I stick some dump()s after the loadURI call, apps
> load fine.

This is something I discovered too and I was thinking about a rendering issue. If this is the same thing I saw the 'white' app is working and you can interact with it even if the screen stays white. You can see that the app is rendering in the Cards View (which use BrowserElementParent.getScreenshot() to render the window).
> You can see that the app is rendering in the Cards View (which use 
> BrowserElementParent.getScreenshot() to render the window).

Ah, yes, that works.  So this doesn't look like a dom/docshell issue.

I'll see how much of a win we get by preloading the XPCOM services.
We caught up over IRC, but ftr: preloading about:blank is pretty scary because IPC isn't connected for the preload tabchild.  If we try to paint about:blank and push a frame to the compositor, I'm not really sure what would happen (probably bad things).  We need to not do that.

Random thought: are we trying to load about:blank before the app entry point?
This is a ~300ms startup win on my Otoro.

Testing methodology:

0. Enable the show-app-load-time setting.
1. Restart the phone.
2. Repeat 4 times:
   a. Open the FM app.
   b. Record time displayed.
   c. Use the card view to close the FM app.
   d. Wait a few seconds.
3. Repeat 4 times:
   a. Open the clock app.
   b. Record time displayed.
   c. Use the card view to close the clock app.
   d. Wait a few seconds.

Taking the average of the three fastest startup times and rounding to the
nearest 25ms, I have:

 Unpatched:
   FM:    1700ms
   Clock: 2400ms

 Patched:
   FM:    1300ms
   Clock: 2125ms

There's obviously some noise here; I didn't do a lot of trials.  But this patch
is clearly a significant win.

Would be nice if we could get this for B2G v1.
Attachment #692313 - Attachment is obsolete: true
Attachment #701970 - Flags: review?(jones.chris.g)
How does this win compare to loading about:blank?
Comment on attachment 701970 [details] [diff] [review]
Preload JSMs + XPCOM services, v1

This doesn't belong in the b2g product.  Can we put it in dom/browser-element?

> +    tab->RecvLoadRemoteScript(NS_LITERAL_STRING("chrome://browser/content/preload.js"));

What happens when this file doesn't exist?
Attachment #701970 - Flags: review?(jones.chris.g)
(In reply to Chris Jones [:cjones] [:warhammer] from comment #20)
> How does this win compare to loading about:blank?

about:blank was ~500ms, and the JSMs alone were ~100ms.  But I'm having difficulty getting the right busywaits in the code to make the about:blank loading work at all again.
> Can we put it in dom/browser-element?

It's not really related to mozbrowser, so long as we still have <iframe remote>.  How about dom/ipc?

> What happens when this file doesn't exist?

I'll verify this, but it looks like nsFrameScriptExecutor silently fails if the URL doesn't exist.
Attached patch Patch, v2 — — Splinter Review 
I'm going to try to take the day off tomorrow, so feel free to land this if it
gets r+.  (That's not directed to anyone in particular.)

Moved preload.js to dom/ipc.  No changes to preload.js itself.
Attachment #702112 - Flags: review?(jones.chris.g)
Attachment #701970 - Attachment is obsolete: true
Comment on attachment 702112 [details] [diff] [review]
Patch, v2

Measuring with a stopwatch from tap-icon to first real paint, I don't quite replicate the results above.  I saw a 50-100ms win on dialer startup, 150-200ms on settings, and wasn't able to measure email (variance was too high with this patch applied), but there might have been a 100ms win.

But we need all the help we can get here.
Attachment #702112 - Flags: review?(jones.chris.g) → review+
What is the "app startup" counter measuring?  Is it time to first load, or something?  If so, that's still a reasonable thing to measure, since a page may not be responsive until onload.
Comment on attachment 702112 [details] [diff] [review]
Patch, v2

[Approval Request Comment]
Bug caused by (feature/regressing bug #): n/a
User impact if declined: Slower app startup
Testing completed: Landed on m-c
Risk to taking this patch (and alternatives if risky): Relatively safe patch.  It's hard for me to imagine what this could screw up.
String or UUID changes made by this patch: none
Attachment #702112 - Flags: approval-mozilla-b2g18?
Backed out for assertions:
https://tbpl.mozilla.org/?tree=Mozilla-Inbound&rev=4082c7521142

eg:
{
Assertion failure: _mOwningThread.GetThread() == PR_GetCurrentThread() (ConsoleListener not thread-safe), at ../../../dom/ipc/ContentChild.cpp:189
1208 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/test_browserElement_inproc_OpenMixedProcess.html | Test timed out.
1209 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/test_browserElement_inproc_OpenMixedProcess.html | This test left crash dumps behind, but we weren't expecting it to!
Assertion failure: _mOwningThread.GetThread() == PR_GetCurrentThread() (ConsoleListener not thread-safe), at ../../../dom/ipc/ContentChild.cpp:189
1468 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/test_browserElement_oop_Alert.html | Test timed out.
1469 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/test_browserElement_oop_Alert.html | This test left crash dumps behind, but we weren't expecting it to!
Assertion failure: _mOwningThread.GetThread() == PR_GetCurrentThread() (ConsoleListener not thread-safe), at ../../../dom/ipc/ContentChild.cpp:189
1474 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/test_browserElement_oop_AlertInFrame.html | Test timed out.
1475 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/test_browserElement_oop_AlertInFrame.html | This test left crash dumps behind, but we weren't expecting it to!
Assertion failure: _mOwningThread.GetThread() == PR_GetCurrentThread() (ConsoleListener not thread-safe), at ../../../dom/ipc/ContentChild.cpp:189
1480 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/browser-element/mochitest/test_browserElement_oop_AppFramePermission.html | Test timed out.
...
...
}

https://hg.mozilla.org/integration/mozilla-inbound/rev/66c50eff016e
Well, that's certainly not what I expected...
(In reply to Justin Lebar [:jlebar] from comment #31)
> Well, that's certainly not what I expected...

This seems to be an unrelated bug, which is that the proxy auto controller, which apparently has its own thread (?), touches the console service on the PAC thread.

I don't know yet why my patch here is triggering this bug, but it looks pretty bad regardless.

> #0  mozilla::dom::ConsoleListener::AddRef (this=0x1603e90) at ../../../src/dom/ipc/ContentChild.cpp:186
> #1  0x00002aaf276deaa7 in ns_if_addref<nsISupports*> (expr=0x1603e90)
>     at ../../../dist/include/nsISupportsUtils.h:59
> #2  0x00002aaf29abf00e in nsCOMArray_base::InsertObjectAt (this=0x2aaf6c020cf8, aObject=0x1603e90, 
>     aIndex=0) at ../../../src/xpcom/glue/nsCOMArray.cpp:116
> #3  0x00002aaf27690697 in nsCOMArray_base::AppendObject (this=0x2aaf6c020cf8, aObject=0x1603e90)
>     at ../../dist/include/nsCOMArray.h:54
> #4  0x00002aaf29b68d98 in nsCOMArray<nsIConsoleListener>::AppendObject (this=0x2aaf6c020cf8, 
>     aObject=0x1603e90) at ../../dist/include/nsCOMArray.h:245
> #5  0x00002aaf29b68d5f in (anonymous namespace)::LogMessageRunnable::AddListener (this=0x2aaf6c020cd0, 
>     listener=0x1603e90) at ../../../src/xpcom/base/nsConsoleService.cpp:105
> #6  0x00002aaf29b67b99 in (anonymous namespace)::CollectCurrentListeners (aKey=0x1603e90, 
>     aValue=0x1603e90, closure=0x2aaf6c020cd0) at ../../../src/xpcom/base/nsConsoleService.cpp:136
> #7  0x00002aaf29b6898a in nsBaseHashtable<nsISupportsHashKey, nsCOMPtr<nsIConsoleListener>, nsIConsoleListener*>::s_EnumReadStub (table=0x16af190, hdr=0x163fd68, number=0, arg=0x2aaf65bff4a8)
>     at ../../dist/include/nsBaseHashtable.h:400
> #8  0x00002aaf29aca9aa in PL_DHashTableEnumerate (table=0x16af190, 
>     etor=0x2aaf29b68920 <nsBaseHashtable<nsISupportsHashKey, nsCOMPtr<nsIConsoleListener>, nsIConsoleListener*>::s_EnumReadStub(PLDHashTable*, PLDHashEntryHdr*, unsigned int, void*)>, arg=0x2aaf65bff4a8)
>     at ../../../src/xpcom/glue/pldhash.cpp:717
> #9  0x00002aaf29b67b61 in nsBaseHashtable<nsISupportsHashKey, nsCOMPtr<nsIConsoleListener>, nsIConsoleListener*>::EnumerateRead (this=0x16af190, 
>     enumFunc=0x2aaf29b67b70 <(anonymous namespace)::CollectCurrentListeners(nsISupports*, nsIConsoleListener*, void*)>, userArg=0x2aaf6c020cd0) at ../../dist/include/nsBaseHashtable.h:188
> #10 0x00002aaf29b679d8 in nsConsoleService::LogMessageWithMode (this=0x16af160, message=0x2aaf6c01e1c0, 
>     outputMode=nsConsoleService::OutputToLog) at ../../../src/xpcom/base/nsConsoleService.cpp:217
> #11 0x00002aaf29b677f2 in nsConsoleService::LogMessage (this=0x16af160, message=0x2aaf6c01e1c0)
>     at ../../../src/xpcom/base/nsConsoleService.cpp:146
> #12 0x00002aaf29b67c42 in nsConsoleService::LogStringMessage (this=0x16af160, message=0x2aaf6c05ddf8)
>     at ../../../src/xpcom/base/nsConsoleService.cpp:238
> #13 0x00002aaf277606ae in mozilla::net::PACLogToConsole (aMessage=...)
>     at ../../../../src/netwerk/base/src/ProxyAutoConfig.cpp:299
> #14 0x00002aaf2776044b in mozilla::net::ProxyAutoConfig::SetupJS (this=0x1a42288)
>     at ../../../../src/netwerk/base/src/ProxyAutoConfig.cpp:604
> #15 0x00002aaf2776009d in mozilla::net::ProxyAutoConfig::Init (this=0x1a42288, aPACURI=..., aPACScript=...)
>     at ../../../../src/netwerk/base/src/ProxyAutoConfig.cpp:565
> #16 0x00002aaf27723b36 in ExecutePACThreadAction::Run (this=0x1ad6a70)
>     at ../../../../src/netwerk/base/src/nsPACMan.cpp:190
Is this just a case of needing to use 

NS_IMPL_THREADSAFE_ISUPPORTS2(ConsoleListener, nsIConsoleListener)

instead of:

NS_IMPL_ISUPPORTS1(ConsoleListener, nsIConsoleListener)
Err - minus the typo s/SUPPORTS2/SUPPORTS1/
Depends on: 831428
> Is this just a case of needing to use 
> 
> NS_IMPL_THREADSAFE_ISUPPORTS2(ConsoleListener, nsIConsoleListener)

I originally thought the console service was not threadsafe, but upon closer examination, I think you're right, and I filed bug 831428.
This patch brings a really nice perf win for all apps:


                  | pre-patch     | post-patch    |  diff
------------------|---------------|---------------|---------
system+homescreen |  13745 (944)  |  14445 (1181) | +699
template          |  1204 (11)    |  1060 (11)    | -143
settings          |  2796 (165)   |  2528 (97)    | -268
sms               |  2058 (31)    |  1895 (33)    | -163
calendar          |  2973 (390)   |  2758 (319)   | -215
browser           |  1107 (81)    |  1031 (23)    | -76

The perf cost in system+homescreen is not statically significant with such a huge variance. I expect that there is some cost for a boot, but I'd need more testing to give the reliable number.

What's nice is that I observe a win for each and every app I tested, even in-process. event Template app.

In my tests the patch also reduces variance and gives more steady numbers which is another win (out of 40 tests I got only one outlier with the patch and 5 without it).

Seems worth taking.
> What's nice is that I observe a win for each and every app I tested, even in-process. 

This patch does not affect in-process apps, so I think that's probably noise.
The fact that this patch seems to be a much bigger win for the show-app-load-time "firstpaint" timer than for more accurate measurements of "real" first paint seems worth following up on.  Maybe content processes are getting hung up on something early in startup?
the diff for browser is probably coming from too small sample (5 cold runs), but the variance makes it insignificant anyway. Within the noise zone.

The out of process apps listed here indicate 140-260ms win that seems reproducible on other apps as well.
majority if not of the perf boost from this patch is coming in before the child process starts loading document, so the win should be similar >100ms for every process.
I can land this if we get approval here and bug 831428.
blocking-b2g: --- → tef?
> blocking-b2g: --- → tef?

FWIW, although I'd love to take this bug on b2g18, I don't think performance improvements of this sort block release, for any meaningful definition of "block".
I don't really care to argue over what "blocking" means.  The point is that app start times are crap right now, and goodness like this is what we need to turn the v1.0 release into a viable product.
Understood.  Mostly, I wish approval requests were triaged every day so we didn't end up nominating things like this twice.
Ping overholt or lmandel to speed things along.
I shouldn't need to, is my point.  Interrupting them is a waste of everyone's time and concentration.  (But so is things moving so slowly that we nominate bugs twice in the hopes that will get them looked at more quickly.)

OTOH it looks like there aren't many outstanding approval requests.  So I guess not everyone is hitting this problem.

https://wiki.mozilla.org/B2G/Triage#Searches_used_during_triage
We're going to approve this for v1.0.0 given partner desire, perf improvement, and risk profile. Please land on tip of mozilla-b2g18.

At the first sign of regression caused by this, we'll need to backout.
blocking-b2g: tef? → -
tracking-b2g18: --- → +
Attachment #702112 - Flags: approval-mozilla-b2g18? → approval-mozilla-b2g18+
Bug 831428 needs approval too, otherwise this cannot land.
Since the patch is not closed yet I use it to attach this small followup.  It seems to work for me but this is late here and I can be dreaming already...
Attachment #705602 - Flags: review?(jones.chris.g)
Some quick stopwatch timings

== feedback ==
 before: 1.37, 1.37, 1.35
  after: 1.06, 1.09, 1.03

== dialer ==
 before: 2.09, 2.00, 2.00
  after: 1.69, 1.68, 1.69

== settings ==
 before: 2.97, 3.19, 3.16
  after: 2.78, 3.35(?), 2.72

== email ==
 before: 4.94, 5.00, 5.19
  after: 5.06, 4.75, 4.79

For the less noisy apps, looks like a 300-350ms win! :D
Comment on attachment 705602 [details] [diff] [review]
Preload about:blank

Before I r+, let me make sure an inactivated docshell guarantees either
 - prevent painting entirely
 - or if we do attempt to paint, the world won't 'asplode

Would also be interesting to see if the other junk we're preloading is made unnecessary by the about:blank load.
           || master      || noanim      ||    %
===========||=============||=============||=========
Homescreen ||  3478 (28)  ||  1874 (36)  ||  -1604
Template   ||  1027 (30)  ||   713 (22)  ||  -314
Settings   ||  2685 (265) ||  2143 (52)  ||  -541
SMS        ||  1877 (27)  ||  1591 (17)  ||  -286
Calendar*  ||  2626 (103) ||  2044 (21)  ||  -581
Email      ||  5511 (290) ||  5254 (34)  ||  -256
Contacts   ||  3247 (144) ||  2850 (51)  ||  -397

I love the numbers, but what also is amazing here is how much lower the variance becomes. The lower the variance the more reliable measurements we get.

Also, please not that those numbers are for my builds that use heavier perf measuring including logging and perf.js lib in every measured app, which means that on average the timings per app for production will be ~200ms lower than those.
Comment on attachment 705602 [details] [diff] [review]
Preload about:blank

r=me on the code.

I poked through PresShell and ViewManager, and here's what I see

 - when !PresShell.mIsActive, we ignore invalidations
 - however, when !PresShell.mIsActive, we can still reach ViewManager::Refresh I believe.  Refresh() doesn't check if the PresShell is active, but, it does bail if the damageRegion is empty.  Maybe that's the case when we ignore invalidations.
 - PresShell::Paint doesn't check docshell active-ness

So if we can reach PresShell::Paint with the inactive docshell here, we'll be in for bad times.

roc/tn can that ever happen, to your knowledge?  (This is an || review request.)
Attachment #705602 - Flags: review?(tnikkel)
Attachment #705602 - Flags: review?(roc)
Attachment #705602 - Flags: review?(jones.chris.g)
Attachment #705602 - Flags: feedback+
I'm not confident. Why not just add an mIsActive check to PresShell::Paint?
Is that going to prevent requestAnimationFrame() callbacks from running?
(In reply to Justin Lebar [:jlebar] from comment #50)
> https://hg.mozilla.org/releases/mozilla-b2g18/rev/a83603927132

You meant to land this on inbound too, right?  Maybe I'm missing something?
(In reply to Robert O'Callahan (:roc) (Mozilla Corporation) from comment #56)
> I'm not confident. Why not just add an mIsActive check to PresShell::Paint?

Alright, let's see what blows up ...

https://tbpl.mozilla.org/?tree=Try&rev=292539a04732
(In reply to Chris Jones [:cjones] [:warhammer] from comment #59)
> (In reply to Justin Lebar [:jlebar] from comment #50)
> > https://hg.mozilla.org/releases/mozilla-b2g18/rev/a83603927132
> 
> You meant to land this on inbound too, right?  Maybe I'm missing something?

We don't have a patch for the dependency (bug 831428) that's suitable for m-c quite yet.  bsmedberg is still waiting on one review there.

We could land the version of bug 831428 which we landed on b2g18 and then back it out later, if you need it on m-c before the version bsmedberg is working on is ready.
(In reply to Chris Jones [:cjones] [:warhammer] from comment #57)
> Is that going to prevent requestAnimationFrame() callbacks from running?

I'm not sure exactly what the reason is for setting active to false, but that will throttle the refresh driver, and hence requestAnimationFrame callbacks too. I'm not sure if that is important to you.
Attachment #705602 - Flags: review?(tnikkel)
Attachment #705602 - Flags: review?(roc)
Attachment #705602 - Flags: review+
Attachment #705602 - Flags: feedback+
Comment on attachment 705602 [details] [diff] [review]
Preload about:blank

Relatively safe patch that brings sorely needed big startup win.  Extensive testing internally and downstream.
Attachment #705602 - Flags: approval-mozilla-b2g18+
(In reply to Timothy Nikkel (:tn) from comment #63)
> (In reply to Chris Jones [:cjones] [:warhammer] from comment #57)
> > Is that going to prevent requestAnimationFrame() callbacks from running?
> 
> I'm not sure exactly what the reason is for setting active to false, but
> that will throttle the refresh driver, and hence requestAnimationFrame
> callbacks too. I'm not sure if that is important to you.

We want a solution that doesn't allow the window to paint, but doesn't break running throttled callbacks.
Preloading about:blank is messing with the browser-element tests.  It looks like we're missing navigation events and getting too many in other cases.
Attachment #706088 - Flags: review?(justin.lebar+bug)
Comment on attachment 706088 [details] [diff] [review]
Only PreloadSlowThings() when prelaunch is enabled

That's a bit scary, since it means we have no test coverage...  But sure.
Attachment #706088 - Flags: review?(justin.lebar+bug) → review+
We cover that code in b2g runs.  But apparently we're not running the browser-element tests on b2g, which is indeed rather scary.
> But apparently we're not running the browser-element tests on b2g, which is indeed rather scary.

Last time I checked, the number of mochitests we run on b2g on tinderbox was quite approximately zero.  (It was something like four directories, with a bunch of omissions.)  But I'm not sure where that manifest file lives.
So what's going on here is, this patch changes the mozbrowser API contract.  Previously, sort of by accident, the child docshell started out active.  With this patch, it sometimes starts active and sometimes inactive.  This was causing two tests that rely on an active docshell (to process reflow and RAF callbacks) to fail.

Existing "production strength" mozbrowser clients always initialize visibility of created frames, so this isn't an issue in gaia.  However, the mochitest harness seems not to be doing this, although I wasn't able to track down that code.

Unfortunately, a great solution to this problem doesn't present itself to me.  The simplest might be to retain the old behavior by always resetting the docshell to active when we take over the first TabChild "for real".  We could do this in BrowserElementChild.js.  This can't race with API clients.

jlebar, what do you think?
Flags: needinfo?(justin.lebar+bug)
Implements proposed plan above.  Various try things are going on in parallel, let's hope this r? catches you tonight and those complete.
Attachment #706088 - Attachment is obsolete: true
Attachment #706249 - Flags: review?(justin.lebar+bug)
(Sneaking in a 1s startup win for email while I'm at it.)
Attachment #706249 - Attachment is obsolete: true
Attachment #706249 - Flags: review?(justin.lebar+bug)
Attachment #706252 - Flags: review?(justin.lebar+bug)
> jlebar, what do you think?

That sounds perfect to me.
Flags: needinfo?(justin.lebar+bug)
Comment on attachment 706252 [details] [diff] [review]
Make sure preloaded docshells are reset to active, v1.1

> +pref("dom.ipc.processPrelaunch.delayMs", 5000);

Oh, interesting: This is the e-mail startup win?

I'm totally fine with this change (it's not like 1000ms was arrived at scientifically), but I'd like us to at some point investigate why this change has an effect.  Possible explanations include:

* Perhaps we are not setting the preallocated process to background priority early enough.

* Perhaps setting a process to background priority doesn't prevent it from stealing significant amounts of CPU.

* Perhaps the e-mail app goes "idle" earlier than expected for some reason.

Understanding this would affect our decisions elsewhere.
Attachment #706252 - Flags: review?(justin.lebar+bug) → review+
(In reply to Justin Lebar [:jlebar] from comment #78)
> Comment on attachment 706252 [details] [diff] [review]
> Make sure preloaded docshells are reset to active, v1.1
> 
> > +pref("dom.ipc.processPrelaunch.delayMs", 5000);
> 
> Oh, interesting: This is the e-mail startup win?

Yep.

> I'm totally fine with this change (it's not like 1000ms was arrived at
> scientifically), but I'd like us to at some point investigate why this
> change has an effect.  Possible explanations include:
> 
> * Perhaps we are not setting the preallocated process to background priority
> early enough.

Part of it.  The process will fork()/exec()/dynamic link/init XPCOM at the same priority as the b2g process.  When I measured previously, that time was around 700ms total.

> * Perhaps the e-mail app goes "idle" earlier than expected for some reason.

Also part of it; that's why this change makes any difference at all.  I don't understand why email is sitting idle during load though.  That's bad but an orthogonal problem to fix.
> Part of it.  The process will fork()/exec()/dynamic link/init XPCOM at the same priority as the b2g 
> process.  When I measured previously, that time was around 700ms total.

Okay; that we can totally fix, since at the time that we fork() the process we know what priority we want it to have.
b2g tests have been pending for hours on try :( :(, but if

https://tbpl.mozilla.org/?tree=Try&rev=ec3df1942184

goes green, we should land this (somewhere for release) asap.
Attachment #706335 - Flags: review+
https://hg.mozilla.org/releases/mozilla-b2g18/rev/893e68b73efd

There's no preload.js on mozilla-central, so I'm not entirely certain what to do there.
> There's no preload.js on mozilla-central, so I'm not entirely certain what to do there.

See comment 61; we're waiting on a dependency for m-c.  I'll go ping in that bug.
Whiteboard: [fast:300ms] → [fast:300ms], [perf_tsk]
Whiteboard: [fast:300ms], [perf_tsk] → [fast:300ms], [FFOS_perf]
Whiteboard: [fast:300ms], [FFOS_perf] → [fast:300ms][FFOS_perf]
Comment on attachment 706335 [details] [diff] [review]
Rollup for landing on b2g18

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

With this latest patch I can confirm the win that we saw earlier in all apps, but I also noticed that if I launch/kill/launch the app rather quickly the ttlview numbers are really low (in 400-500ms zone for Settings for example) despite it being a cold boot.

I don't think it's a bug in the code, but it possibly means that mozbrowserloadend fires too early in such cases (the ttlview is definitely visible before the app is really loaded). Should I file a followup bug?

::: b2g/app/b2g.js
@@ -576,5 @@
>  // Enable pre-launching content processes for improved startup time
>  // (hiding latency).
>  pref("dom.ipc.processPrelaunch.enabled", true);
>  // Wait this long before pre-launching a new subprocess.
> -pref("dom.ipc.processPrelaunch.delayMs", 1000);

This change brings a lot of variance to most apps. It does indeed give a nice win on email app, but for Homescreen, Dialer, Template, Settings, SMS and Contacts I see a 500-1000ms slowdown every 2-3rd run.
> This change brings a lot of variance to most apps.

Perhaps you're not waiting long enough between launching the apps.
(In reply to Justin Lebar [:jlebar] from comment #85)
> > This change brings a lot of variance to most apps.
> 
> Perhaps you're not waiting long enough between launching the apps.

I'm waiting at least 5s after killing it before I tap again.

But even if that's the reason, that's a normal behavior for the user, he can launch an app right after closing another and that brings a really high regression that I cannot reproduce without this change.
I tend to think that rapidly cycling through cold-launched apps is not a common use case based on personal experience, but note that the prelaunch delay is eminently tunable.  As we cut down the app-level slowness we can take the training wheels off a bit more again.

Also, as noted above, we're most likely running some of the prelaunch startup work at a much higher priority than it should.
(In reply to Chris Jones [:cjones] [:warhammer] from comment #87)
> I tend to think that rapidly cycling through cold-launched apps is not a
> common use case based on personal experience, but note that the prelaunch
> delay is eminently tunable.  As we cut down the app-level slowness we can
> take the training wheels off a bit more again.

Yeah, I know, but:
 - cycling through different apps is. So going through Dialer->SMS->Browser->Settings etc. is
 - This makes it really hard to measure performance impact of changes, because of the variance (for example I just got 2600ms on Template app)
 - The only notable win I was able to observe is the email app.

It just makes the ttlview unreliable once again and greatly reduces the only simple tool app authors have to measure their startup performance changes.
blocking-b2g: - → tef?
cjones, does the benefit here outweigh the potential regression risk?
Flags: needinfo?(jones.chris.g)
(In reply to Andrew Overholt [:overholt] from comment #89)
> cjones, does the benefit here outweigh the potential regression risk?

I'd like to mention that without this patch it will be very unlikely that we'll meet the requirements set by some of our partners (I cannot go into more detail on this publicly). Without knowing how big the associate risk is I can say that we need it quite badly.
We don't have a viable commercial product without these patches.
Flags: needinfo?(jones.chris.g)
(In reply to Chris Jones [:cjones] [:warhammer] from comment #91)
> We don't have a viable commercial product without these patches.

:)
blocking-b2g: tef? → tef+
I have played a bit more with preloading and this patch is the result of my investigation. I don't think I can preload more things actually and the other things that affects the load time of the template app seems out of the preloading path.

This patch loads more services related to some specifics apps:
 - +  /* Applications Specific Helper */
Cc["@mozilla.org/alarmsManager;1"].getService(Ci["nsIDOMMozAlarmsManager"]);
Cc["@mozilla.org/contactManager;1"].getService(Ci["nsIDOMContactManager"]);  Cc["@mozilla.org/settingsManager;1"].getService(Ci["nsIDOMSettingsManager"]);
Cc["@mozilla.org/system-message-manager;1"].getService(Ci["nsIDOMNavigatorSystemMessages"]);

Is there any secuirty issues of preloading those here?

The patch preloads the ContentSecurityPolicy loaded by privileged/certified apps:
Cc["@mozilla.org/contentsecuritypolicy;1"].createInstance(Ci["nsIContentSecurityPolicy"]);


The patch loads one more additional service for app that use the console API:
 - Cc["@mozilla.org/console-api;1"].createInstance(Ci["nsISupports"]);


Also the patch do less call to messageManager.loadFrameScript (that are done once TabChild is connected to the parent) and more mozIJSSubscriptLoader.loadFrameScript when possible.

And the last thing beeing that a big part of the BrowserElementChild logic has  been moved to be preloaded if needed.


The things that seems to stays between the click on the homescreen and the mozbrowserloadend of the template app seems out of the scope of this bug:
 - Time to sent the message from the user click on the homescreen to the system app in order to open the app: ~20ms (mostly related to webapps.jsm)
 - Time to append to the dom an <iframe mozbrowser mozapp>: ~40ms (half of the time is when calling: new BrowserElementParent() in BrowserElementParent.js.)
 - Random time in Gaia spent doing 'something': ~40ms
 - Time between the loadstart/loadend of the template app: ~130ms (It seems like the JS web progress listeners on the BrowserElementChild side are a non neglige able part of the time here).

My measurements are made with the animation disabled when opening an application since there is still a regression on it which is out of the scope of this work again.

I have also some local patches applied to my Gaia tree that I need to upstream (which is why there is 'only' 40ms spent in Gaia.
Attachment #707607 - Flags: review?(justin.lebar+bug)
Attachment #707607 - Flags: review?(jones.chris.g)
> This patch loads more services related to some specifics apps:

This means that every app will pay the memory cost of these services.  Before we did something like this, I'd want to at least measure it.

> The patch preloads the ContentSecurityPolicy loaded by privileged/certified apps:

ibid.

> The patch loads one more additional service for app that use the console API:

ibid.
Comment on attachment 707607 [details] [diff] [review]
Preload more things - again.

Let's move the discussion in a different bug to not pollute too much this one. Sorry for the spam.

Bug 835809.
Attachment #707607 - Flags: review?(justin.lebar+bug)
Attachment #707607 - Flags: review?(jones.chris.g)
Anyone know if this made it to 1_0_0?
$ git log --pretty=oneline origin/b2g18_v1_0 --grep 819000
> 23d977c38ae619c072ddfbaae01f1358a2095bad Rollup of bug 819000: Preload about:blank. r=cjones,jlebar a=cjones
> 2207f0e0d5e7d1690acdb7139fddfc213bdf1ef5 Back out bug 819000
> 219381bfe4379d60b27054609df47fed5403fd97 Bug 819000: Preload about:blank. r=cjones a=cjones
> 02474190223e5735581dc398c125676089d1e58d Bug 819000: Only PreloadSlowThings() when prelaunch is enabled. r=jlebar
> aa01008d64de7849ecf3a59cd967729d3c7714cd Bug 819000: Bail out of PresShell::Paint if not active. r=roc
> 47f58147a229789121af5c2beb2f53fee45ac910 Back out bug 819000. a=bustage
> 4a76c874ec4efd91aad1adae88e7a2a41d65bb3a Back out bug 819000
> 529fe2f87bb7ee5fb62c29f6b3bdbf5b8f4479eb Bug 819000: Preload about:blank. r=cjones a=cjones
> 40ba82924111dc44f7f94ff97c651dac0812e4e1 Bug 819000: Bail out of PresShell::Paint if not active. r=roc
> 94e7b9c3bdf38701b5146d85ee227ad7096d33bf Bug 819000 - Preload some JSMs and XPCOM services into the preallocated process to speed up app startup. r=cjones, a=akeybl
When do we "RESOLVED/FIXED" this?
Keywords: perf
(In reply to Milan Sreckovic [:milan] from comment #100)
> When do we "RESOLVED/FIXED" this?

Bugs get RESOLVED/FIXED when they land on m-c.

Speaking of which, we've landed the dependency, so this can land now.
https://hg.mozilla.org/mozilla-central/rev/14e3c735b373
https://hg.mozilla.org/mozilla-central/rev/d1a412685273
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Target Milestone: --- → B2G C4 (2jan on)
sorry for reviving an already resolved bug, but just hit this preallocated process timeout with a very slow up (over 5000ms startup time).

Would it be possible to instead of setting it to 5s just check if there's an app launching and delay creation of the new preallocated process until it's finished?
Can you please provide steps to verify this fix - as we will blackbox test from the UI?
Nothing to verify here.
Whiteboard: [fast:300ms][FFOS_perf] → [fast:300ms][FFOS_perf] QARegressExclude
No Test case creation is needed in moztrap for this issue.
Flags: in-moztrap-
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: