1572538 - Running ExtensionProcessScript.jsm during page load takes significant amount time

Status: RESOLVED WORKSFORME

(WebExtensions :: General, defect, P3)

Description

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

instagram on G5 through geckoview nightly from taskcluster
https://perfht.ml/2MYc9Wz

Comment 1

[Kris Maglione [:kmag]]

I think the biggest part of the problem here is that these modules aren't in the script preloader, which means they have to be compiled from source whenever they're loaded, since we have no other form of startup cache in content processes.

Ted and I have talked about populating the child preloader cache with scripts that aren't needed at startup so that we can still use their entries for bytecode sharing, but it would also help with problems like this.

Comment 2

[Julien Wajsberg [:julienw]]

We should take another profile, see if this is still a problem now. This bug is about loading a page inside a new content process.

Comment 3

[Marc Leclair [not active]]

I think I still see the same thing as of today. It looks like PreloadContentScript takes 130ms on the G5+ which is a notch above the g5

Comment 4

[Julien Wajsberg [:julienw]]

From the profile, it looks like we spend quite some time in _log (this is a lot less than the import obviously, but still quite some time) => https://share.firefox.dev/3ef9Lrj.

(but maybe you enabled logs specifically here?)

Comment 5

[Julien Wajsberg [:julienw]]

Hey Marc,
it looks like that your link in comment 3 links to the old profile! Have you shared the wrong link?
I should have seen that earlier, sorry about that!

Comment 6

[Frank Doty [:fdoty]]

Can a new profile be collected to determine if this is still a significant issue?

Comment 7

[Michael Comella (:mcomella) [NI reported issues only: ex-Mozilla]]

We improved start up script caching in bug 1632682. In comment 5, I specifically reference ExtensionProcessScript.jsm. When I worked on the bug in Feb 2022, it sounds like I didn't observe ExtensionProcessScript to be as slow as when this bug was originally filed. Also, my changes didn't do much to improve ExtensionProcessScript. Here's a snippet of that comment:

and see that each script takes less time to import (though some still take surprisingly long, e.g. ExtensionProcessScript.jsm goes from 26.2ms to 25.3ms).

I think it'd still be worth capturing a new profile to see if this is still an issue.

Comment 8

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

Triggered profile creation on https://treeherder.mozilla.org/jobs?repo=autoland&revision=c38ede3a4e99d2dd3612b4df2cf78232b3f549e9&group_state=expanded&selectedTaskRun=EvnLy-JzRhWLlR0VwjU6uQ.0

Comment 9

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

hmm, the profiles looks all different. We're loading something totally different these days?
See for example https://share.firefox.dev/3IPTM0H

But anyhow, ExtensionProcessScript.jsm or such doesn't show up. I'll file a new but about instagram record.

filed https://bugzilla.mozilla.org/show_bug.cgi?id=1779879

Comment 10

[Kris Maglione [:kmag]]

(In reply to Michael Comella (:mcomella) [needinfo or I won't see it] from comment #7)

We improved start up script caching in bug 1632682. In comment 5, I specifically reference ExtensionProcessScript.jsm. When I worked on the bug in Feb 2022, it sounds like I didn't observe ExtensionProcessScript to be as slow as when this bug was originally filed. Also, my changes didn't do much to improve ExtensionProcessScript. Here's a snippet of that comment:

I don't think those changes should have affected ExtensionProcessScript at all. They didn't change when it would run, and it's loaded as a message manager process script, which have been loaded after the script preloader was initialized as long as there has been a preloader in the content process.

(In reply to Marc Leclair [not active] from comment #3)

I think I still see the same thing as of today. It looks like PreloadContentScript takes 130ms on the G5+ which is a notch above the g5

The problem with the preloader here is actually that ExtensionContent.jsm is loaded too late to be available in a bytecode cache, for reasons related to security. We would ideally like to fix that.

That said, only about 18ms of the time spent running that function is in reading/compiling ExtensionContent.jsm, and another 19ms reading/compiling ExtensionChild.jsm. The rest is in running their initialization code. But it would be nice if we weren't wasting that 37ms.