New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 636655 link

Starred by 18 users

Issue metadata

Status: Fixed
Owner:
Closed: Mar 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: All
Pri: 2
Type: Bug


Sign in to add a comment

simple content scripts significantly slow down load times

Project Member Reported by ojan@chromium.org, Aug 11 2016

Issue description

This issue comes up frequently when working with web developers. It's especially bad because it means that appending an iframe to your page *always* causes you to miss at least one frame if you have content scripts that inject into iframes. It's even worse when you consider that ads consist of multiple nested frames.

I think this is high urgency, but since it's been like this for years, I don't think it makes sense to mark as a P1. :)

Test page that measures load time of 10 iframes: http://jsbin.com/qecanedura/edit?html,output

Here's the contents of the attached extension:

content_script.js:
chrome.storage.onChanged.addListener;
chrome.runtime.onMessage.addListener;

manifest.json:
{
   "name": "slow",
   "content_scripts": [ {
      "all_frames": true,
      "js": [ "content_script.js" ],
      "match_about_blank": true,
      "matches": [ "<all_urls>" ],
      "run_at": "document_start"
   } ],
   "manifest_version": 2,
   "permissions": [ "storage" ],
   "version": "1.22"
}

I tested the following three scenarios on a Macbook Pro laptop.

1. With no content scripts, the 10 iframes take ~10ms to load.
2. With an empty content script, they take ~60ms to load.
3. With the two line script listed above, they take ~110ms to load.

I haven't dug into it, but I suspect #2 is a side effect of creating the V8 context for the isolated world. I know work is going into making V8 contexts load faster already, but I wonder if there's low hanging fruit for the special case of isolated worlds as I expect we've paid less attention there.

For #3, I assume it's the cost of setting up the extension bindings. We should be able to do considerably better there. I suspect we should be able to eliminate the cost entirely, but I'm definitely not an expert here.
 
slow-extension.zip
1.6 KB Download
Cc: peria@chromium.org
I'm wondering if the only way to solve the performance issue is to speed up an iframe creation (as peria@ is working) or there's another workaround.

Would there be any option to delay instantiating a v8::Context for the content script (which means that we don't run the content script for the iframe synchronously)?

Comment 3 by peria@chromium.org, Aug 11 2016

> Would there be any option to delay instantiating a v8::Context for the content script (which means that we don't run the content script for the iframe synchronously)?

I think it can be done if we can commit crrev.com/1824573005, but it depends on the issue 611632.
The issue (611632) is blocked on refactoring of interceptors in V8.
I doubt that landing issue 611632 is enough to fix the performance issue of the content script.

The problem is that non-empty content scripts are running synchronously while the iframe is being created. Even if we delay instantiating the document wrapper, the content script anyway runs during the iframe creation and ends up instantiating the document wrapper then.

My question is if it's possible to delay executing the content script until the page becomes idle.

Comment 5 by peria@chromium.org, Aug 11 2016

Ah, yes, you're right.
I have no idea to delay it.
Re 2, it's probably a combination of the cost of creating the v8 context for the content script as well as the cost of setting up initial bindings for extensions.  Some background on extension bindings:

The process is pretty much all done in some fun custom JS.  Why?  Mostly because when it was written, the concept of doing this at a lower level wasn't feasible because of API availability and the chrome/webkit separation.  But now it's like that, and it's a lot of work (that we're looking into!) to change it.  What we do is set up lazy accessors for every API the extension has access to.  Even creating these lazy accessors though can require a some amount of work, though.  (On the upside, this should be significantly faster at times starting in M54 since I made the change to compile feature files.)  We have to do this because we have no way of knowing what the content script might access.

Once a content script accesses an API, we populate it with the actual methods, etc.  This is what's also taking a long time, because it means looping over the schema, creating functions, handlers, type checking, et al for each API method and event, and so forth.  This is the cost you're seeing in #3.  We're looking into ways to make this better.

One thought is to use blink-style bindings to generate extension APIs.  This is nice in principal, but has a few issues.  One is that extension APIs are much more conditional than any other blink API (including origin trials, since extension APIs can be enabled/disabled on the same origin based on script context).  Another is that it makes build rules go crazy, since it's mixing blink and extensions.  A third, and possibly the most insurmountable, is that this means we explode in binary size, since there are around 175 different extension APIs and blink bindings create separate C++ objects for each (in the current implementation, binary size is constant regardless of the number of APIs).  In my early exploration, I calculated that this would increase the size of the chrome binary by an entirely unacceptable amount.

I'm also looking into ways to come to a happy balance here, where we can reuse the same code for each API (good binary size) while still using general blink-style accessors and avoiding the JS instantiation for each API (good speed).  It's still early days.

No matter what we do, it'll be a significant pain because it means we have to convert ~100 JS files to C++.

Happy to chat more if anyone's interested.
Here's a profile of WatchWord:

8% is creating mojo bindings.
41% is under extensions::ModuleSystem::LazyFieldGetterInner creating extension bindings.
30% for the isolated world.
8% for the document property.
5% is compiling the script.
= 92%, the last 8% is a bunch of things including running the actual script.

So I think the bugs here are:
- Extension binding instantiation is very slow.
- Mojo bindings are adding a lot of overhead.
- Extensions don't appear to use the v8 compile cache, so they're recompiling the entire content script for every frame.
- Isolated worlds are expensive.

Total %     Symbol Name
100     content::RenderFrameImpl::runScriptsAtDocumentElementAvailable
99.9         extensions::Dispatcher::RunScriptsAtDocumentStart
99.9          extensions::ExtensionFrameHelper::RunScriptsAtDocumentStart
99.9           extensions::ScriptInjectionManager::StartInjectScripts
99.9            extensions::ScriptInjectionManager::InjectScripts
99.9             extensions::ScriptInjectionManager::TryToInject
99.9               extensions::ScriptInjection::Inject
99.9                extensions::ScriptInjection::InjectJs
99.9                 blink::WebLocalFrameImpl::requestExecuteScriptInIsolatedWorld
99.9                  blink::SuspendableScriptExecutor::executeAndDestroySelf
99.9                   blink::ScriptController::executeScriptInIsolatedWorld
61.8                    blink::ScriptController::executeScriptAndReturnValue
56.8                     blink::V8ScriptRunner::runCompiledScript
56.8                      v8::Script::Run
40.7                       extensions::ModuleSystem::LazyFieldGetterInner
22.4                        extensions::BindingGeneratingNativeHandler::NewInstance
10.7                         extensions::ModuleSystem::Require
10.7                          extensions::ModuleSystem::RequireForJsInner
10.7                           extensions::ModuleSystem::LoadModule
8.4                      extensions::::ExtensionImpl::Apply
2.8                       extensions::::ExtensionImpl::Apply
2.1                       extensions::ObjectBackedNativeHandler::Router
1.9                        extensions::ScriptContextSet::GetByV8Context const
18.2                        extensions::ModuleSystem::Require
18.2                         extensions::ModuleSystem::RequireForJsInner
18.1                          extensions::ModuleSystem::LoadModule
13.1                           extensions::ScriptContext::CallFunction const
13.1                            blink::V8ScriptRunner::callFunction
9.8                          extensions::::ExtensionImpl::Apply
2.8                          extensions::ObjectBackedNativeHandler::Router
2.7                           extensions::ModuleSystem::RequireForJs
4.9                        extensions::ScriptContext::RunScript
7.9                    blink::DOMWindowV8Internal::documentAttributeGetterCallback
2.5                    extensions::::ExtensionImpl::Apply
5                    blink::V8ScriptRunner::compileScript
38                  blink::WindowProxy::initializeIfNeeded()
38                   blink::WindowProxy::initialize()
29.9                      blink::WindowProxy::createContext()
29.9                       v8::NewContext
8.1                   content::RenderFrameImpl::didCreateScriptContext
8.1                    extensions::ExtensionFrameHelper::DidCreateScriptContext
8.1                     extensions::Dispatcher::DidCreateScriptContext
8.1                      extensions::ModuleSystem::ModuleSystem
8.1                       content::RenderFrameImpl::EnsureMojoBuiltinsAreAvailable

Thanks Elliott for the profile. This looks too bad :/

A couple of questions and comments:

- In general I like the idea of generating the extension bindings with the IDL compiler. It will help generate faster, more correct and maintainable bindings for extensions.

- Why doesn't the existing JS extension binding cause the binary size bloat? Is it because the JS bindings are downloaded lazily? Or is it because you can entirely drop the JS bindings on a mobile binary where extensions are disabled? (Maybe can we do the same thing for C++ bindings? i.e., don't compile the C++ extension bindings for a mobile binary.)

- Extension bindings and Mojo bindings are static things, so they can be snapshotted, right? (peria@ is now working on implementing DOM object snapshotting to speed up the frame instantiation.)

- In short term, would there be any option to delay running the content script until the page becomes idle (instead of synchronously running the content script during the frame creation)? Will it break the API semantics of the content script?


> In general I like the idea of generating the extension bindings with the IDL compiler. It will help generate faster, more correct and maintainable bindings for extensions.

I agree that in general, this is good, and there's an investigative bug at  issue 616765 .  However, there are a bunch of concerns.  The biggest one is the binary size.  There's also a number of layering concerns, questions of how to convert/duplicate/otherwise handle existing extension idl/json files (which are used for more than just js bindings), etc.  But the biggest blocker is definitely the fact that by some very rough calculations, this could increase Chrome's binary size by >10% (no joke).

- Why doesn't the existing JS extension binding cause the binary size bloat? Is it because the JS bindings are downloaded lazily? Or is it because you can entirely drop the JS bindings on a mobile binary where extensions are disabled? (Maybe can we do the same thing for C++ bindings? i.e., don't compile the C++ extension bindings for a mobile binary.)

Our binding code is done in very dumb JS.  It basically consists of:
for (let api of apis) {
  for (let function of apis.functions) {
    chrome[api.name][function.name] = function() {
      callNative(function, args);
    };
  }
}

This is, of course, a massive simplification (the real code is in extensions/renderer/resources/binding.js and related), but the idea is the same.  Since we just loop over the APIs, adding a new API doesn't add any binary size for the bindings themselves.

I have a suspicion that we could apply a similar approach and just use C++ rather than JS for the bindings, and it would result in static binary size benefits along with significant speed improvements, but I haven't had the time to investigate fully.

> Extension bindings and Mojo bindings are static things, so they can be snapshotted, right? (peria@ is now working on implementing DOM object snapshotting to speed up the frame instantiation.)

Static-ish.  The bindings code itself is static (as is I assume the mojo code), but the results are very different, since APIs are available on a per-context basis.  But I think that should be fine with snapshotting, correct?  The biggest problem I've heard with caching/snapshotting was that it was limited in its reusability (per-context?  per-process?).  If this isn't a concern anymore, than snapshotting or caching could be very beneficial.

> In short term, would there be any option to delay running the content script until the page becomes idle (instead of synchronously running the content script during the frame creation)? Will it break the API semantics of the content script?

Yes, this breaks API guarantees we make in extensions.  We allow content scripts to run before any other script is ran, which is critical to a number of extensions.
>  But the biggest blocker is definitely the fact that by some very rough calculations, this could increase Chrome's binary size by >10% (no joke).

How did you come up with that number? :)
@10 delta of the stub implementation of a single method of a single API.  Just the extra bindings generated added around 10k.  We have ~200 APIs -> 4% increase.  Most APIs have significantly more than one method, and add various different custom types, each of which has to have a v8 implementation with blink bindings.  Couple that with the added code to determine whether or not a feature is available to contexts and actually doing any work, and I think the 10% is reasonably fairly conservative.

Is there a reason that a more native implementation that's still generic enough to apply to every API is unattractive?

Comment 12 Deleted

Whoops, wrong bug.  Comment 12 ->  issue 637155 .
(It's sad that you deleted comment #12 :-)

Is there any short-term workaround to make the per-frame overhead cheaper?

I've heard that it's common that enterprise customers are installing >60 extensions. If that's the case, the extensions would be causing hundreds of ms of overhead on a frame instantiation...

> (It's sad that you deleted comment #12 :-)

Just moved it (verbatim) to https://bugs.chromium.org/p/chromium/issues/detail?id=637155#c5 - I got my "bindings are slow" bugs mixed up. :)

> Is there any short-term workaround to make the per-frame overhead cheaper?

Depends on how short-term we're talking.  I'm looking at the feasibility of reimplementing our bindings in C++, which I think should result in a significant speed-up (since the cost would ideally be at compile-time rather than binding creation time), but even that is a fair amount of work.  There might also be some low-hanging fruit to optimize the JS that generates the bindings, but how effective that is is debatable.  Any form of migrating bindings to an entirely different system is definitely not short-term, and would likely need some significant commitment from the bindings team, because I'm sure it's more work than the extensions team can handle on our own.

I can't comment on whether or not we could speed up other areas here, like creating the isolated world (which still accounted for 30% of the time) - anything there we can do?

And  issue 637155  should help with the 8% mojo cost in the majority of frames.

> I've heard that it's common that enterprise customers are installing >60 extensions. If that's the case, the extensions would be causing hundreds of ms of overhead on a frame instantiation...

That's terrifying for many reasons... :/
Cc: -rdevlin....@chromium.org asargent@chromium.org lazyboy@chromium.org
Owner: rdevlin....@chromium.org
Status: Assigned (was: Untriaged)
Summary: simple content scripts significantly slow down load times (was: simple content scripts significantly slow down iframe load times)
FYI, I'm making this the official "Content scripts are too dang slow" bug, unless anyone objects.  I'll start spawning some child bugs and duping other "content scripts are slow" bugs into this one.
Blockedon: 638735
Re #15:

> I'm looking at the feasibility of reimplementing our bindings in C++, which I think should result in a significant speed-up (since the cost would ideally be at compile-time rather than binding creation time), but even that is a fair amount of work.

I think this is worth exploring. Let's brainstorm :)

> I can't comment on whether or not we could speed up other areas here, like creating the isolated world (which still accounted for 30% of the time) - anything there we can do?

peria@'s snapshotting will help a lot to make the cost cheaper.

As far as I look at UMAs, it's taking 60 ms to inject content scripts around the 80 percent tile. The number looks really bad :/

https://uma.googleplex.com/histograms?endDate=08-16-2016&dayCount=1&histograms=Extensions.InjectScriptTime&fixupData=true&otherVersions=true&showMax=true&filters=isofficial%2Ceq%2CTrue&implicitFilters=isofficial

Comment 19 by ojan@chromium.org, Aug 18 2016

That uma is a great thing to track. Even better would be if we split it between the top-level page and subframes to understand the impact.

The top-level page has a big impact on page load, the subframes have an impact on jank on the page.
@18 Oh, don't worry, it's much worse than that.  The description for that metric is quite wrong - I'll update it.  That's actually the time taken to inject scripts from a single extension, not from all extensions.  I've added a few more graphs to your url.

https://uma.googleplex.com/histograms?endDate=08-16-2016&dayCount=1&histograms=Extensions.InjectEnd_Time%2CExtensions.InjectIdle_Time%2CExtensions.InjectScriptTime%2CExtensions.InjectStart_Time&fixupData=true&otherVersions=true&showMax=true&filters=isofficial%2Ceq%2CTrue&implicitFilters=isofficial

Comment 21 by ojan@chromium.org, Aug 18 2016

@20, that's really interesting. Do we yield to the event loop between script injections? If not, this might be some low hanging fruit for improving the impact of extensions on page interactivity (i.e. a user action like clicking a link can happen between script injections).

This matters much more for sub frames and scripts injected at idle time or document end than it does for scripts injected at document start for the top-level page. Maybe the ideal thing is to yield to the event loop between script injections in all cases except document start scripts on the top-level page.
We defer to blink for script injection, but my understanding is we only yield in the case of, e.g., blocking js.  With document idle, it's hard to say if we yield already.  All these injections happen as a result of the blink notifications like DidCreateDocumentElement, DidFinishDocumentLoad, DidFinishLoad, etc.  If we handle interactivity between e.g. DidFinishDocumentLoad and DidFinishLoad (I'd hope we do), then we should handle it between scripts, though not during a single script.
> then we should handle it between scripts, though not during a single script.

I guess this should have been "between run time like document end and idle", since we do still synchronously inject all scripts for a given time.
Blockedon: 638758
As far as I understand the discussion so far, content scripts need to be injected synchronously while the frame is being instantiated. This is required to ensure the API semantics of extensions (it's not allowed to defer the injection to idle time). It means that content script injection is causing a very big jank on the main thread.

Am I understanding correctly?

(Some background that might be known but is necessary)
Content scripts can specify a "run location" (which is really more of an injection time).  This can be document_start, document_end, or document_idle.  These are documented at https://developer.chrome.com/extensions/content_scripts; documentation inline here for ease:

---
In the case of "document_start", the files are injected after any files from css, but before any other DOM is constructed or any other script is run. 

In the case of "document_end", the files are injected immediately after the DOM is complete, but before subresources like images and frames have loaded. 

In the case of "document_idle", the browser chooses a time to inject scripts between "document_end" and immediately after the window.onload event fires. The exact moment of injection depends on how complex the document is and how long it is taking to load, and is optimized for page load speed. 
---

So, in the case of document_start, we have a very firm contract with the extensions - your script will run before the DOM is fully constructed and before anything else.  In code, this equates to "runScriptsAtDocumentElementAvailable()".

In the case of document_end, we might have a bit of flexibility, but not a whole lot (equates to runScriptsAtDocumentReady()).

With document_idle, we theoretically have a good amount of leeway - having specified that we optimize it for page load time.  However, I'd feel better if we didn't abuse this trust, because I want to encourage developers to use this whenever possible, and if we start equating this with "whenever we feel like it", I think we'll see (even more) scripts executing at document_start/document_end even if they didn't strictly need to.

Now, all of this is pretty bad, given how slow this execution can be (especially injecting at document start - which is sadly common).  The upside is that from Elliot's breakdown of watchword, we know that actually running the script is pretty cheap, so even if we're stuck with executing synchronously at document_start, there's still a ton of room for improvement to make this less sad.
Blockedon: 639539
Re #20: I want to make sure that I'm interpreting the UMA results correctly.

- Extensions.InjectEnd_Time: This is time duration taken to inject all scripts that have document_end to a given frame.

- Extensions.InjectIdle_Time: This is the time taken to inject all scripts that have document_idle to a given frame.

- Extensions.InjectStart_Time: This is the time taken to inject all scripts that have document_start to a given frame.

- Extensions.InjectScriptTime: This is the time taken to inject all scripts of a single extension to a given frame. It mixes results for scripts with document_start, document_end and document_idle.

Am I understanding correctly?

Elliott: It looks like that the indentation of the perf result you posted in #7 is broken and a bit hard to understand what component is taking how much time. Would it be possible to re-post the perf result with a correct indentation?

(Sorry for asking many questions :-)

rdevlin: Would you help me understand what script injection is already yielded and what's not?

- document_start and document_end are executed as a part of an HTML parser. The HTML parser may split the parsing tasks into chunks (if the scheduler has some urgent tasks). As a result, document_start and document_end can be scheduled in distinct tasks. Either way, it's a responsibility of the HTML parser to split document_start and document_end, right?

- document_idle is already scheduled in a separate task from the task where document_start and document_end are scheduled, right?

- Do we already have a mechanism to split scripts that are injected at the document_start/document_end/document_idle timing into multiple chunks?

- We probably want to have UMAs that measure non-yieldable time caused by content scripts.

@28 Histogram descriptions are mostly correct.  Extensions.InjectIdleTime *might* not be all scripts of a given extension depending on how the author formats the manifest, but it "probably" is.  In other words - that's a really bad histogram.  It has too many variable bits to be able to get much useful information.  The others are a little more useful (though they too can fluctuate a lot based on number/type of extensions installed).

@30 My knowledge of HTML parsing is rudimentary at best, so the best I can do is explain our implementation. :/  With start/end, we listen for the runScriptsAtDocumentElement[Start|End], and then use WebFrame::requestExecuteScriptAndReturnResult(), thus letting blink handle most of the innards.  My understanding is that this can be suspended in the case of blocking code, breakpoints, etc, but won't yield the event loop otherwise (which can be important for extension scripts, since they need to run [to completion] before any other scripts if they're injected at document_start).

> Do we already have a mechanism to split scripts that are injected at the document_start/document_end/document_idle timing into multiple chunks?

Hypothetically, this could be done by WebFrame::requestExecuteScriptAndReturnResult(), which is called once per "batch" of scripts ("batches" are rather vague, but are always from one extension for one run location - often all the scripts for that extension/run location pair).  Of course, we'd have to make sure that splitting the tasks doesn't break guarantees we make to the extension.

> We probably want to have UMAs that measure non-yieldable time caused by content scripts.

This might be what the histograms above measure, depending on my understanding of non-yieldable. :)  The histograms *don't* account for any scripts that block and finish asynchronously, since this is relatively rare, far more variable, and harder to implement an accurate timer for.  At a really high level, the histograms kind of work like this:

Timer timer;
for (extension : extensions) {
  scripts = GetScriptsForExtensionAndRunLocation(extension, run_location);
  web_frame->requestExecuteScriptAndReturnValue(scripts);
}
UMA_HISTOGRAM_TIMES("Extensions.Inject[Start|End|Idle]_Time", timer.Elapsed());
Thanks for the pointers, Devlin!

I looked at the code and confirmed that the following things are happening:

- All scripts injected at document_start (or document_end) are injected in the same event loop.

- The HTML parser may schedule document_start and document_end in different event loops (it's up to the HTML parser).

- The UMA (https://uma.googleplex.com/histograms?endDate=08-16-2016&dayCount=1&histograms=Extensions.InjectEnd_Time%2CExtensions.InjectIdle_Time%2CExtensions.InjectScriptTime%2CExtensions.InjectStart_Time&fixupData=true&otherVersions=true&showMax=true&filters=isofficial%2Ceq%2CTrue&implicitFilters=isofficial) indicates that it's common that the injection takes >100 ms. This is really problematic.

- It's important to reduce the injection overhead per content script but is also important to split the script injections into multiple tasks. Given that the HTML parser is already splitting a parsing logic into multiple tasks, it will be semantically doable to split the script injections into multiple tasks.


Do we know whether that 100ms is many extensions, or just one big extension like an adblocker?
> important to split the script injections into multiple tasks. Given that the HTML parser is already splitting a parsing logic into multiple tasks, it will be semantically doable to split the script injections into multiple tasks.

My blink knowledge is still pretty rudimentary - what's the advantage of this, and can we still make guarantees about injection time?  What's the event loop doing if we have to e.g. make sure document_start scripts run before any DOM or any other scripts?

> Do we know whether that 100ms is many extensions, or just one big extension like an adblocker?

There's probably some way to find this out if you're a dremel/uma ninja, but unfortunately I don't know it - the histogram is aggregated across all users.
Blockedon: 640247

Comment 36 by ojan@chromium.org, Aug 23 2016

Water-cooler brainstormed w/ esprehn a way to make running the different content scripts in different tasks work while maintaining enough of the current contracts that very little (if any) content would break.

document_idle: I think we can safely run each injection in it's own task. The only thing that would break here is one extension depending on running it's content scripts immediately after another extension.

document_end: I think it's a bit more risky, but also still probably pretty safe. Folks depending on this to run before images and iframes have loaded are depending on a race condition I believe.

document_start in the top-level page: Probably nothing we can do here. 

document_start in subframes: We can maintain enough of the current contract that it's probably safe to change if we block parsing and rendering in the subframe until all the content scripts have run. We have easy ways to do both of those. That way, we minimize the impact on responsiveness that inserting a frame has on the top-level page.

There would be non-zero risk here, but I suspect these would all be pretty safe and maintain current contracts.
That sounds fairly reasonable overall.  I'd like to start with just document_idle first, because I think the document_end risk is a little high to do off the bat.  The document_idle would let us see how much of a win this is, and whether or not it's worth pursuing further.  Additionally, I'd like to measure how much this ends up delaying content scripts at document_idle - it's not meant to be a "we'll inject this at some point in the distant future", and if we see them not being injected for long periods of time, it will be a bad user experience and disincentivize developers from using document_idle more (which we want to be encouraging). 
Cc: nduca@chromium.org rsch...@chromium.org
Labels: Performance
Ojan's proposal sounds very reasonable.

Re #37: Splitting document_idle would be a good start point, but note that the gain would be very limited because document_idle is consuming <14 ms in 80% of the cases. It's still important to work on document_end and document_start in subframes.

Maybe shall we insert more UMAs to understand a real world better?

- How many content scripts are injected during document_start(main frame), document_start(sub frame), document_end, and document_idle, respectively
- How much time is consumed to inject all content scripts during document_start(main frame), document_start(sub frame), document_end, and document_idle, respectively
- How much time is consumed to inject one content scripts during document_start(main frame), document_start(sub frame), document_end, and document_idle, respectively

These metrics will give us insights about how much we can gain by splitting document_start/end/idle into multiple tasks.

Blockedon: 641006
@39 Correct me if I'm wrong, but I think we already have metrics for number of content scripts injected and amount of time to inject all content scripts for document_end and document_idle (and document_start, but not split by main-sub frame), right?  Adding the others would probably be useful - I'll see if I can do that.
@41: Thanks, I found the metrics :) Also please ignore my comment about document_idle. My analysis was wrong.

UMA results:

https://uma.googleplex.com/histograms?endDate=08-16-2016&dayCount=1&histograms=Extensions.InjectEnd_ScriptCount%2CExtensions.InjectEnd_Time%2CExtensions.InjectIdle_ScriptCount%2CExtensions.InjectIdle_Time%2CExtensions.InjectScriptTime%2CExtensions.InjectStart_ScriptCount%2CExtensions.InjectStart_Time&fixupData=true&otherVersions=true&showMax=true&filters=isofficial%2Ceq%2CTrue&implicitFilters=isofficial

Summary:

- <13 content scripts are injected at document_start (99% tile). It takes <190 ms to inject those content scripts (95% tile).

- <8 content scripts are injected at document_end (99% tile). It takes <60 ms to inject those content scripts (95% tile).

- <5 content scripts are injected at document_idle (99% tile). It takes <270 ms to inject those content scripts (95% tile).

Also I wrote a document to summarize the discussions in this bug:

https://docs.google.com/document/d/1IfBBZ7sRgNOX_hWQZhXJ2nPelmjoaYIjbqFXEbmYvXc/edit#

Blockedon: 642380
Blockedon: 653596
Project Member

Comment 46 by bugdroid1@chromium.org, Oct 13 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/9152fe906781b3e9fe03b98820cb9d3c8cbb7802

commit 9152fe906781b3e9fe03b98820cb9d3c8cbb7802
Author: sammc <sammc@chromium.org>
Date: Thu Oct 13 22:34:16 2016

Only inject mojo builtins to contexts with the mojoPrivate API feature.

The mojo JS bindings are only used by the mimeHandlerPrivate and
mojoPrivate APIs.

BUG= 636655 

Review-Url: https://codereview.chromium.org/2412783002
Cr-Commit-Position: refs/heads/master@{#425196}

[modify] https://crrev.com/9152fe906781b3e9fe03b98820cb9d3c8cbb7802/extensions/renderer/module_system.cc

Cc: ksakamoto@chromium.org kouhei@chromium.org
Hi,

I made a prototype CL that splits script injections into multiple tasks:
https://codereview.chromium.org/2633253002/

This changes document_end and document_idle content scripts to run asynchronously. The window.onload event is blocked until all document_end scripts are injected. Document_start scripts still run synchronously; to make them run asyncronously, the HTML parser has to be blocked somehow.

This splits scripts injections from different extensions into different tasks, but if single extension had multiple document_end or document_idle scripts they are still injected within one task.


The attached videos demonstrate UI responsiveness when 30 extensions installed where each extension injects one document_idle script of 100ms busy loop.

In async.ogv (patch applied), the page is responsive to text selection while injecting scripts. In sync.ogv (patch not applied), text selection takes effect after all the script injections finished.

This patch works sometimes, but sometimes the page is still not responsive to user input while injecting scripts... Scheduling problem?


Implementation notes:
- This CL adds a option parameter to requestExecuteScriptInIsolatedWorld to allow asynchronous execution.
- ScriptInjection / ScriptInjectionManager treat these posted scripts as blocked injections (ScriptInjection::Inject() returns INJECTION_BLOCKED).
- This change makes Extensions.Inject{End,Idle}_Time UMA useless, as they will report the time took to post tasks. We have to add new UMA that measures actual execution times.
- There are some extension tests that assume all document_idle scripts are injected when chrome.tabs.onUpdated(status == 'complete') is dispatched. This no longer holds, so I had to change these tests to use document_end instead.
- ExtensionApiTest.ContentScriptAboutBlankIframes also had to be changed since the behavior of document_end script injection for <iframe src="javascript:...">.

sync.ogv
3.2 MB View Download
async.ogv
5.2 MB View Download

Comment 48 Deleted

Hmm, it seems Ubuntu's stock Videos app cannot play async.ogv.
Please drag-and-drop it to Chrome to play it.
Owner: ksakamoto@chromium.org
Wow! Great videos.
What are the remaining work items blocking landing the CL?

New UMA has to be added, and the change should be gated using a finch flag.
Project Member

Comment 52 by bugdroid1@chromium.org, Mar 17 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/cbf167aaccb8c6f17c305dffa76b6523776222bf

commit cbf167aaccb8c6f17c305dffa76b6523776222bf
Author: ksakamoto <ksakamoto@chromium.org>
Date: Fri Mar 17 06:45:48 2017

Split content script injections into multiple tasks

Currently, content scripts for all extensions are injected in single
task, causing a big jank on main thread. This patch changes
document_end and document_idle content scripts to run in separate tasks
asynchronously. The window.onload event is blocked until all
document_end scripts are injected.

This new behavior is protected by a feature switch, disabled by default.

To enable asynchronous execution, this CL adds a option parameter to
WebLocalFrame::requestExecuteScriptInIsolatedWorld(). Inside Blink,
it uses SuspendableScriptExecutor's ability to delay execution. So
async script executions are posted as timer tasks.

To test the new behavior, browser tests in content_script_apitest.cc
are parameterized so they run with and without the flag enabled.
Also, some extensions for tests are switched from document_idle to
document_end, since after this patch there's no reliable way to make
sure that all document_idle scripts have finished.

BUG= 636655 

Review-Url: https://codereview.chromium.org/2633253002
Cr-Commit-Position: refs/heads/master@{#457702}

[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/browser/chrome_content_browser_client.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/browser/extensions/content_script_apitest.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/renderer/chrome_content_renderer_client.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/renderer/chrome_content_renderer_client.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/renderer/extensions/chrome_extensions_renderer_client.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/renderer/extensions/chrome_extensions_renderer_client.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/test/data/extensions/api_test/content_scripts/about_blank_iframes/test.js
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/chrome/test/data/extensions/platform_apps/web_view/content_script_whitelisted/main.js
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/content/public/renderer/content_renderer_client.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/content/renderer/render_frame_impl.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/content/renderer/render_frame_impl.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/common/feature_switch.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/common/feature_switch.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/common/switches.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/common/switches.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/renderer/dispatcher.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/renderer/dispatcher.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/renderer/extension_frame_helper.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/renderer/extension_frame_helper.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/renderer/script_injection.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/renderer/script_injection.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/extensions/renderer/script_injection_manager.cc
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/core/frame/LocalFrameClient.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/core/loader/EmptyClients.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/core/loader/FrameLoader.cpp
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/web/LocalFrameClientImpl.cpp
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/web/LocalFrameClientImpl.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/web/SuspendableScriptExecutor.cpp
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/web/SuspendableScriptExecutor.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/web/WebLocalFrameImpl.cpp
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/Source/web/WebLocalFrameImpl.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/public/web/WebFrameClient.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/public/web/WebLocalFrame.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/third_party/WebKit/public/web/WebScriptExecutionCallback.h
[modify] https://crrev.com/cbf167aaccb8c6f17c305dffa76b6523776222bf/tools/metrics/histograms/histograms.xml

Project Member

Comment 53 by bugdroid1@chromium.org, Mar 21 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/3b3e4fe434fa1165715fe60b49b4b642879cca90

commit 3b3e4fe434fa1165715fe60b49b4b642879cca90
Author: ksakamoto <ksakamoto@chromium.org>
Date: Tue Mar 21 02:57:32 2017

Deprecate Extensions.InjectScriptTime histogram

This histogram isn't useful when content scripts are injected
asynchronously, as this measures the time taken to just post a task.

BUG= 636655 

Review-Url: https://codereview.chromium.org/2757833002
Cr-Commit-Position: refs/heads/master@{#458288}

[modify] https://crrev.com/3b3e4fe434fa1165715fe60b49b4b642879cca90/extensions/renderer/script_injection.cc
[modify] https://crrev.com/3b3e4fe434fa1165715fe60b49b4b642879cca90/tools/metrics/histograms/histograms.xml

Project Member

Comment 54 by bugdroid1@chromium.org, Mar 24 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/049f833eba3d4dedd636728c504f5edcb44d91e0

commit 049f833eba3d4dedd636728c504f5edcb44d91e0
Author: ksakamoto <ksakamoto@chromium.org>
Date: Fri Mar 24 06:39:07 2017

Add breakdown histograms for injected script execution time

Currently we have the following metrics for content script injections:

- Extensions.Inject{Start,End,Idle}_Time: Time to inject all extensions'
  scripts for one run_location. Recorded only if injected synchronously.
- Extensions.InjectedScriptExecutionTime: Time to inject one extension's
  scripts, not broken down by run_location.

This patch adds breakdown histograms for InjectedScriptExecutionTime by
locations. Also, add notes to Inject{Start,End,Idle}_Time descriptions
that these are reported only for synchronous script injections.

BUG= 636655 

Review-Url: https://codereview.chromium.org/2766603002
Cr-Commit-Position: refs/heads/master@{#459375}

[modify] https://crrev.com/049f833eba3d4dedd636728c504f5edcb44d91e0/extensions/renderer/script_injection.cc
[modify] https://crrev.com/049f833eba3d4dedd636728c504f5edcb44d91e0/tools/metrics/histograms/histograms.xml

Blockedon: 705400
The finch trial for this might break chrome's PDF viewer, see  bug 697574 .
Labels: -Performance Performance-Loading
Project Member

Comment 58 by bugdroid1@chromium.org, Jul 31 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/7d386bf120192ae5aaeea88209f9267edc4be6f8

commit 7d386bf120192ae5aaeea88209f9267edc4be6f8
Author: Kunihiko Sakamoto <ksakamoto@chromium.org>
Date: Mon Jul 31 03:19:53 2017

Add UMA to track the time yielded between content script runs

This will be used to understand the effect of YieldBetweenContentScriptRuns
experiment on page load time.

Bug:  636655 
Change-Id: I7978daa7361c73ba5b835dbc21402b8cb7d73ae3
Reviewed-on: https://chromium-review.googlesource.com/571246
Reviewed-by: Ilya Sherman <isherman@chromium.org>
Reviewed-by: Devlin <rdevlin.cronin@chromium.org>
Commit-Queue: Kunihiko Sakamoto <ksakamoto@chromium.org>
Cr-Commit-Position: refs/heads/master@{#490701}
[modify] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/extensions/renderer/BUILD.gn
[add] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/extensions/renderer/async_scripts_run_info.cc
[add] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/extensions/renderer/async_scripts_run_info.h
[modify] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/extensions/renderer/script_injection.cc
[modify] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/extensions/renderer/script_injection.h
[modify] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/extensions/renderer/script_injection_manager.cc
[modify] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/extensions/renderer/script_injection_manager.h
[modify] https://crrev.com/7d386bf120192ae5aaeea88209f9267edc4be6f8/tools/metrics/histograms/histograms.xml

Project Member

Comment 59 by bugdroid1@chromium.org, Aug 29 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/cf8f3b588dafb6887aae51e18146e65afb9b98a7

commit cf8f3b588dafb6887aae51e18146e65afb9b98a7
Author: Kunihiko Sakamoto <ksakamoto@chromium.org>
Date: Tue Aug 29 02:40:21 2017

Add UMA that logs long content script injection task time

Currently, we use separate histograms to track injection time for
synchronously injected scripts and for asynchronously injected scripts.
This makes it hard to see the impact of YieldBetweenContentScriptRuns
experiment on Finch dashboard, and causes false alerts (e.g. because
metrics for sync injections are not recorded in the experiment group).

So, this patch adds UMA histograms that log injection task time both for
sync and async injections. Since we are interested in long tasks that
cause user-noticeable janks, this only logs tasks longer than 50 ms.

Bug:  636655 
Change-Id: Id0534d3063b9c1aef9b07b4aab9f388dad66e6b1
Reviewed-on: https://chromium-review.googlesource.com/624824
Reviewed-by: Ilya Sherman <isherman@chromium.org>
Reviewed-by: Devlin <rdevlin.cronin@chromium.org>
Commit-Queue: Kunihiko Sakamoto <ksakamoto@chromium.org>
Cr-Commit-Position: refs/heads/master@{#497993}
[modify] https://crrev.com/cf8f3b588dafb6887aae51e18146e65afb9b98a7/extensions/renderer/async_scripts_run_info.cc
[modify] https://crrev.com/cf8f3b588dafb6887aae51e18146e65afb9b98a7/extensions/renderer/async_scripts_run_info.h
[modify] https://crrev.com/cf8f3b588dafb6887aae51e18146e65afb9b98a7/extensions/renderer/script_injection.cc
[modify] https://crrev.com/cf8f3b588dafb6887aae51e18146e65afb9b98a7/extensions/renderer/scripts_run_info.cc
[modify] https://crrev.com/cf8f3b588dafb6887aae51e18146e65afb9b98a7/extensions/renderer/scripts_run_info.h
[modify] https://crrev.com/cf8f3b588dafb6887aae51e18146e65afb9b98a7/tools/metrics/histograms/histograms.xml

Cc: -rsch...@chromium.org
Status: Fixed (was: Assigned)
Since M63, content scripts are injected as separate tasks.

Sign in to add a comment