1317304 - Content process startup is slow

Status: RESOLVED DUPLICATE of bug 1336380

(Core :: DOM: Content Processes, defect)

Description

[Gabor Krizsanits (INACTIVE)]

I know that profiling debug build is usually pointless but since this is a problem in debug version as well (see bug 1305368) I started it there. On windows 10 with a fast machine using the visual studio profiler plus some good old printf-ing, here are some results:

It takes several seconds to start up a process, most of this time is spent on loading/executing various scripts:

Some of the hot functions:
js::RunScript 73%
js::CallJSNative 69%
mozJSComponentLoader:Import 37%
js::frontend::CompileGlobalScript 24%
RecvLoadRemoteScript 24%
RecvLoadProcessScript 17%

I could not find any non JS related hot code. The most time consuming JS files were:

TelemetryStartup 1047ms (via an app startup observer notification)
converter-observer.js 1062ms
tab-content.js 547ms
content.js 328s

And another 5-6 above 100ms. All the scripts and their related modules loaded comes in the next comment.

Comment 1

[Gabor Krizsanits (INACTIVE)]

---Import: resource://gre/modules/Services.jsm
---Import: resource://gre/modules/AppConstants.jsm
---Import: resource://gre/modules/XPCOMUtils.jsm
---Import: resource://gre/modules/TelemetryController.jsm
---Import: resource://gre/modules/Log.jsm
---Import: resource://gre/modules/debug.js
---Import: resource://gre/modules/osfile.jsm
---Import: resource://gre/modules/osfile/osfile_async_front.jsm
---Import: resource://gre/modules/osfile/osfile_shared_allthreads.jsm
---Import: resource://gre/modules/PromiseWorker.jsm
---Import: resource://gre/modules/ctypes.jsm
---Import: resource://gre/modules/Timer.jsm
---Import: resource://gre/modules/osfile/osfile_win_allthreads.jsm
---Import: resource://gre/modules/osfile/ospath.jsm
---Import: resource://gre/modules/osfile/ospath_win.jsm
---Import: resource://gre/modules/Promise.jsm
---Subscript: resource://gre/modules/Promise-backend.js
---Import: resource://gre/modules/Task.jsm
---Import: resource://gre/modules/TelemetryStopwatch.jsm
---Import: resource://gre/modules/AsyncShutdown.jsm
---Import: resource://gre/modules/osfile/osfile_native.jsm
---Import: resource://gre/modules/PromiseUtils.jsm
---Import: resource://gre/modules/DeferredTask.jsm
---Import: resource://gre/modules/Preferences.jsm
---Import: resource://gre/modules/TelemetryUtils.jsm
---Import: resource://gre/modules/TelemetrySession.jsm
---Import: resource://gre/modules/TelemetrySend.jsm
--- process script: chrome://global/content/process-content.js
---Import: resource://gre/modules/RemotePageManager.jsm
--- process script: chrome://pocket/content/pocket-content-process.js?0.5792476070489035
---Import: chrome://pocket/content/AboutPocket.jsm
---Import: resource://gre/modules/AppsServiceChild.jsm
---Import: resource://gre/modules/AppsUtils.jsm
--- remote script: chrome://global/content/browser-content.js
--- remote script: resource://gre/modules/addons/Content.js
--- remote script: chrome://satchel/content/formSubmitListener.js
---Import: resource://gre/modules/PrivateBrowsingUtils.jsm
--- remote script: chrome://global/content/browser-child.js
---Import: resource://gre/modules/BrowserUtils.jsm
---Import: resource://gre/modules/RemoteAddonsChild.jsm
---Import: resource://gre/modules/Prefetcher.jsm
--- remote script: chrome://global/content/select-child.js
--- remote script: chrome://browser/content/tab-content.js
---Import: resource://gre/modules/ExtensionContent.jsm
---Import: resource://gre/modules/ExtensionChild.jsm
---Import: resource://gre/modules/ExtensionUtils.jsm
---Import: resource://gre/modules/Schemas.jsm
---Import: resource://gre/modules/NetUtil.jsm
---Import: resource://gre/modules/MessageChannel.jsm
--- remote script: chrome://browser/content/content.js
---Import: resource:///modules/ContentWebRTC.jsm
---Import: resource:///modules/ContentObservers.jsm
---Import: resource://gre/modules/InlineSpellChecker.jsm
---Import: resource://gre/modules/InlineSpellCheckerContent.jsm
---Import: resource:///modules/FormSubmitObserver.jsm
---Import: resource:///modules/ContentLinkHandler.jsm
---Import: resource:///modules/PluginContent.jsm
--- remote script: chrome://browser/content/content-UITour.js
--- remote script: chrome://global/content/manifestMessages.js
---Import: resource://gre/modules/ManifestObtainer.jsm
---Import: resource://gre/modules/PromiseMessage.jsm
---Import: resource://gre/modules/ManifestProcessor.jsm
---Import: resource://gre/modules/Console.jsm
---Import: resource://gre/modules/ValueExtractor.jsm
---Import: resource://gre/modules/ImageObjectProcessor.jsm
---Import: resource://gre/modules/ManifestFinder.jsm
--- remote script: chrome://browser/content/content-sessionStore.js
---Import: resource:///modules/sessionstore/FrameTree.jsm
---Import: resource:///modules/sessionstore/ContentRestore.jsm
---Import: resource:///modules/sessionstore/SessionHistory.jsm
---Import: resource:///modules/E10SUtils.jsm
---Import: resource://gre/modules/LoginManagerContent.jsm
---Import: resource://gre/modules/InsecurePasswordUtils.jsm
---Import: resource://gre/modules/LoginHelper.jsm
--- process script: resource://devtools/client/jsonview/converter-observer.js
---Import: resource://devtools/shared/Loader.jsm
---Import: resource://gre/modules/commonjs/toolkit/loader.js
---Import: resource://gre/modules/osfile/ospath_unix.jsm
---Import: resource://devtools/shared/loader-plugin-raw.jsm
---Subscript: resource://devtools/shared/builtin-modules.js
---Import: resource://gre/modules/jsdebugger.jsm
---Subscript: resource://devtools/client/jsonview/converter-sniffer.js
---Subscript: resource://gre/modules/commonjs/sdk/platform/xpcom.js
---Subscript: resource://gre/modules/commonjs/sdk/util/object.js
---Subscript: resource://gre/modules/commonjs/sdk/util/array.js
---Subscript: resource://gre/modules/commonjs/sdk/core/heritage.js
---Subscript: resource://gre/modules/commonjs/sdk/util/uuid.js
---Subscript: resource://devtools/client/jsonview/converter-child.js
---Subscript: resource://gre/modules/commonjs/sdk/dom/events.js
---Import: resource://gre/modules/ShimWaiver.jsm
---Subscript: resource://gre/modules/commonjs/sdk/clipboard.js
---Subscript: resource://gre/modules/commonjs/sdk/url.js
---Subscript: resource://gre/modules/commonjs/sdk/base64.js
---Subscript: resource://gre/modules/commonjs/sdk/deprecated/api-utils.js
---Subscript: resource://gre/modules/commonjs/sdk/lang/type.js
--- process script: resource://pdf.js/pdfjschildbootstrap.js
---Import: resource://pdf.js/PdfJs.jsm
---Import: resource://pdf.js/PdfjsContentUtils.jsm
---Import: resource://pdf.js/PdfStreamConverter.jsm
--- process script: resource://gre/modules/PerformanceWatcher-content.js
---Import: resource://gre/modules/PerformanceWatcher.jsm
---Import: resource://gre/modules/PerformanceStats.jsm
---Import: resource://gre/modules/ObjectUtils.jsm
--- process script: resource://gre/modules/PerformanceStats-content.js
---Subscript: resource://devtools/shared/webconsole/network-helper.js
---Subscript: resource://devtools/shared/DevToolsUtils.js
---Subscript: resource://devtools/shared/defer.js
---Subscript: resource://devtools/shared/flags.js
---Subscript: resource://devtools/shared/platform/chrome/stack.js
---Subscript: resource://devtools/shared/ThreadSafeDevToolsUtils.js
---Import: resource://gre/modules/ReaderMode.jsm
---Import: resource://gre/modules/sessionstore/Utils.jsm
---Import: resource:///modules/sessionstore/PageStyle.jsm
---Import: resource:///modules/sessionstore/SessionStorage.jsm
---Import: resource://gre/modules/ScrollPosition.jsm

Comment 2

[Gabor Krizsanits (INACTIVE)]

Jan, I will try to delay some of these scripts, but realistically we will need something like bug 876173 for this as well. Are you working on something related these days?

Comment 3

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

Another thing we can do to improve start-up time is to reduce the number of synchronous messages we send to the parent on startup (bug 1303096).

Comment 4

[Gabor Krizsanits (INACTIVE)]

(In reply to Mike Conley (:mconley) from comment #3)
> Another thing we can do to improve start-up time is to reduce the number of
> synchronous messages we send to the parent on startup (bug 1303096).

It's hard to tell how much time we spend on those sync messages, according to the profiling I made they are not so much, but I'm not sure how much I can trust visual studio profiler, so it is entirely possible that I'm wrong. Do you have any numbers maybe? I wonder if for the talos Tabpaint test we could start the profiler somehow earlier to record the process script activity as well, that would help a lot with getting the right data.

From what I learned so far: lazy init does not help much, there are a few exceptions but nothing major.
Cutting out some stuff might help (SDK loader and some some stuff from Web Extensions). In general a pattern of slim class for startup init that only contains what we really need at startup and loads the rest later lazily would be a great pattern.

Order of scripts is terrible. browser-child.js should come sooner because before that we don't start loading anything, but for example all the process scripts comes sooner, like pdf.js and pocket, etc.

What I'm really curious about if the JS engine is warming up at the beginning and if so how big of an issue that is. I also wonder if we could save some state for these static chrome scripts and reuse it.

Another if we could do some optimized compilation for all the process/frame scripts on the parent side once and then run them faster on the child side. This could potentially be a huge win, have no idea though as I don't know anything about our JS engine.

Comment 5

[Jan de Mooij [:jandem]]

(In reply to Gabor Krizsanits [:krizsa :gabor] from comment #2)
> Jan, I will try to delay some of these scripts, but realistically we will
> need something like bug 876173 for this as well. Are you working on
> something related these days?

Brian is working on bug 1315757 but I think that will help memory usage more than it will help performance.

Using the startup cache in content processes (bug 626814) might help a bit?

Comment 6

[Gabor Krizsanits (INACTIVE)]

(In reply to Jan de Mooij [:jandem] from comment #5)
> (In reply to Gabor Krizsanits [:krizsa :gabor] from comment #2)
> Using the startup cache in content processes (bug 626814) might help a bit?

I experimented a bit with startup cache but could not see any major improvement, but maybe I did something wrong. It's mostly the interpreting/executing part that is slow for some reason. I wonder if building those atom tables is also time consuming though, I've seen some hashmap activity with the profiler... so it _might_ actually help if we don't have to build those atom tables in each processes.

I wonder if we could just compile all the frame/process scripts into byte codes, and create a shared storage for jsm's and do the same thing with those too. All these chrome scripts are static JS code we have full control over and will only change in the product when we update the browser, I wish there were a way to optimize them offline more.

Comment 7

[Jan de Mooij [:jandem]]

(In reply to Gabor Krizsanits [:krizsa :gabor] from comment #6)
> I wonder if we could just compile all the frame/process scripts into byte
> codes, and create a shared storage for jsm's and do the same thing with
> those too. All these chrome scripts are static JS code we have full control
> over and will only change in the product when we update the browser, I wish
> there were a way to optimize them offline more.

Well that's what the startup cache is for. It uses a mechanism called XDR to serialize the bytecode and omni.ja even contains pre-compiled (at build time) XDR files.

Comment 8

[Gabor Krizsanits (INACTIVE)]

Attachment: release build, with startup-cache, exclusive semples

(In reply to Jan de Mooij [:jandem] from comment #7)
> (In reply to Gabor Krizsanits [:krizsa :gabor] from comment #6)
> > I wonder if we could just compile all the frame/process scripts into byte
> > codes, and create a shared storage for jsm's and do the same thing with
> > those too. All these chrome scripts are static JS code we have full control
> > over and will only change in the product when we update the browser, I wish
> > there were a way to optimize them offline more.
> 
> Well that's what the startup cache is for. It uses a mechanism called XDR to
> serialize the bytecode and omni.ja even contains pre-compiled (at build
> time) XDR files.

I did a second attempt to use startup cache and it's not doing much. I mean I see
a 10% improvement in module loading in release mode which is not bad, but not
game changing either. The funny thing is all the unzipping we still have to do
on these XDR optimized scripts we read from the cache (which is funny since the
cache file is compressed as well so isn't this double zipping? and I would not
expect bytcode to have to unzip JS function/script strings lazily...)

Anyway I attach the result of the profiler for the release build. There the script
execution is less problematic to start with, thought this inflate/deflate work is interesting,
and ARGBSetRow_X86 (BufferTexture.cpp's InitBuffer) works quite a lot too but that's probably optimized code already, we won't be able to do much with the dll loading part either. The long tail of small initialization stuff mainly from the JS engine seems like a hard thing to improve :(

For the debug build startup cache does not do much either, the main problem there is the amazingly thorough assertion and other debug only work the JS engine does while executing scripts in debug mode. I can probably cut out some of the JS work, but realistically we will have to reuse processes for debug try-runs for a while...

Comment 9

[Gabor Krizsanits (INACTIVE)]

Attachment: release build, with startup-cache, inclusive samples

Comment 10

[Gabor Krizsanits (INACTIVE)]

Attachment: release build, with startup-cache, inclusive samples

Bah... visual studio does not export the ordering :( I had to sort the xml by script, here is the inclusive one, exclusive will come soon.

Comment 11

[Gabor Krizsanits (INACTIVE)]

I'll start a new meta bug for tracking the related work in the future and close this one. This bug ended up as an investigation bug instead of a meta bug.