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

Issue 637148 link

Starred by 3 users

Issue metadata

Status: Fixed
Owner:
Closed: Nov 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: All
Pri: 3
Type: Bug

Blocked on:
issue 647273



Sign in to add a comment

DurableStorage OriginTrial makes creating iframes 18% slower

Project Member Reported by esprehn@chromium.org, Aug 12 2016

Issue description

I loaded a blank page and then did:

document.body.innerHTML = "<iframe></iframe>".repeat(100);

Total %		Symbol Name
100	 	blink::HTMLFrameElementBase::openURL(bool)
99.9	 	 blink::DocumentLoader::finishedLoading(double)
96.4	 	  blink::DocumentLoader::commitData(char const*, unsigned long)
96.4	 	   blink::DocumentLoader::ensureWriter(WTF::AtomicString const&, blink::KURL const&)
96.4	 	    blink::DocumentLoader::createWriterFor(...)
96.4	 	     blink::FrameLoader::receivedFirstData()
96.3	 	      blink::FrameLoader::dispatchDidClearDocumentOfWindowObject()
96.3	 	       blink::ScriptController::initializeMainWorld()
96.3	 	        blink::WindowProxy::initializeIfNeeded()
96.3	 	         blink::WindowProxy::initialize()
60.3	 	          blink::WindowProxy::createContext()
60.3	 	           v8::NewContext(...)
18.1	 	          blink::OriginTrialContext::initializePendingFeatures()
18.1	 	           blink::installOriginTrials(blink::ScriptState*)
18.1	 	            blink::installOriginTrialsForModules(blink::ScriptState*)
17.3	 	             blink::V8NavigatorPartial::installDurableStorage(blink::ScriptState*, v8::Local<v8::Object>)
17.3	 	              blink::V8PerContextData::prototypeForType(blink::WrapperTypeInfo const*)
17.3	 	               blink::V8PerContextData::constructorForTypeSlowCase(blink::WrapperTypeInfo const*)
17.3	 	                v8::FunctionTemplate::GetFunction(v8::Local<v8::Context>)
0.8	 	             blink::V8WindowPartial::installDurableStorage(blink::ScriptState*, v8::Local<v8::Object>)
0.8	 	              blink::V8DOMConfiguration::installAttribute(...)
0.8	 	               blink::V8PerContextData::constructorForTypeSlowCase(blink::WrapperTypeInfo const*)
0.8	 	                v8::FunctionTemplate::GetFunction(v8::Local<v8::Context>)
17.7	 	          blink::WindowProxy::updateDocumentProperty()
17.7	 	           blink::Document::wrap(v8::Isolate*, v8::Local<v8::Object>)
17.7	 	            blink::V8DOMWrapper::createWrapper(v8::Isolate*, v8::Local<v8::Object>, blink::WrapperTypeInfo const*)
17.7	 	             blink::V8PerContextData::createWrapperFromCacheSlowCase(blink::WrapperTypeInfo const*)
17.7	 	              blink::V8PerContextData::constructorForTypeSlowCase(blink::WrapperTypeInfo const*)
17.7	 	               v8::FunctionTemplate::GetFunction(v8::Local<v8::Context>)
3.5	 	  blink::Document::finishedParsing()

This is also concerning for [SecureContext] which wants to do similarly dynamic things. I think the OriginTrial is forcing eager creation of the Navigator object, we should probably apply the trials lazily on first access.
 
Nice detective work! Yes, we should make the instantiation of the Navigator wrapper lazily.

Also peria@ might want to consider snapshotting the Navigator wrapper.


This is definitely concerning, especially if we start using this technique for features which should be present by default (feature policy).

I'm guessing that it's not instantiating the object itself, but it *is* trying to get the prototype in the current context -- in order to attach the storage attribute to it -- and that is forcing the creation of the interface object.

Attaching attributes lazily might be possible -- I'll take a look to see how that would work.

haraken -- Would snapshotting the Navigator interface mean that the interface and prototype would already be available by the time installOriginTrials is called? That would mean that we would avoid the slow constructorForTypeSlowCase call, which would eliminate almost all of this slowdown, I think.
> I'm guessing that it's not instantiating the object itself, but it *is* trying to get the prototype in the current context -- in order to attach the storage attribute to it -- and that is forcing the creation of the interface object.

Correct. For example, we need to instantiate JS functions for getters/setters of all DOM attributes, which is heavy.

> haraken -- Would snapshotting the Navigator interface mean that the interface and prototype would already be available by the time installOriginTrials is called? That would mean that we would avoid the slow constructorForTypeSlowCase call, which would eliminate almost all of this slowdown, I think.

Correct. The snapshotting is expected to eliminate the cost of constructorForTypeSlowCase.

Here's a possibility: What if we do the origin trial check *inside* of constructorForTypeSlowCase instead? Then we can attach the storage object to the Navigator prototype on the first time it is accessed, and afterwards, the correct interface+prototype for the context will be stored in the constructor map.

I'm not sure if that works with snapshotting, but it should avoid the startup cost right now, and we'll only run the code (the installDurableStorage/installAttribute code, which is fast) in cases where navigator is actually used.

I'll try to code up a POC, but WDYT?
Sounds like a plan.

Also I think it will work with snapshotting. To implement the snapshotting, we anyway need to implement a way to instantiate a wrapper that doesn't have any dynamic DOM attributes. It doesn't really matter where the dynamic DOM attributes are installed unless the place is scattered in the code base.


Owner: iclell...@chromium.org
Status: Started (was: Untriaged)
esprehn -- It's still rough, but could you try to profile https://codereview.chromium.org/2260113002/ and see if it resolves the original issue?

I've moved the origin trial checks into constructorForTypeSlowCase, for everything which doesn't require an instance object -- this is everything but globals and the testing `internals` object. That should eliminate the 17.3% time attributed to installDurableStorage on frame creation. (It will still happen eventually, of course, but only if `navigator` is actually accessed, when we would have paid that cost anyway.
Owner: esprehn@chromium.org
[Reassigning to esprehn; feel free to assign back to me after :) ]
Cc: igrigo...@chromium.org
So the cost here is only because we're triggering navigator creation earlier?  Perhaps we should repeat the analysis with a page that happens to poke navigator during the initial load (eg. navigator.userAgent is a very common API).  What's the additional overhead in that case to having an origin trial present?

If the real-world startup impact is non-trivial we should have seen some perf bot regressions in the CL that added this origin trial, did we?  Maybe worth a closer look at the data for that CL?  I can help point you at the right place to look.
It's about how much work is triggered synchronously inside the frame setup. ex. if you do:

appendChild(document.createElement("iframe")) there's no reason the navigator of that iframe needs to be touched immediately, and in most pages with about:blank iframes you wouldn't end up touching the navigator *inside* the frame anyway, since your script is actually running in the parent world.

Authors can break up the work of touching navigator if they need to, there's nothing they can do about the frame itself since that's one big sync operation.
Blockedon: 647273
Owner: iclell...@chromium.org
Status: Fixed (was: Started)
Closing this as fixed; the changes to the origin trials startup have made it so that OT initialization has a negligible effect on frame creation time.

I repeated the test on a page with and without an origin trial header, and I can see that the call to installOriginTrials which happens at the end of WindowProxy::initialize takes only 60us (6ms over 100 frame instantiations) when there are trials attached to the page, which accounts for 0.2% of the time under blink::HTMLFrameElementBase::openURL(bool) (and most of that time is spent in WTF::String, so there may be ways to make it faster still)


Trace:
Running Time		        Symbol Name
2646.8ms  100.0%	 	blink::HTMLFrameElementBase::openURL(bool)
2642.0ms   99.8%	 	 blink::HTMLFrameOwnerElement::loadOrRedirectSubframe(blink::KURL const&, WTF::AtomicString const&, bool)
2637.4ms   99.6%	 	  blink::FrameLoaderClientImpl::createFrame(blink::FrameLoadRequest const&, WTF::AtomicString const&, blink::HTMLFrameOwnerElement*)
2637.4ms   99.6%	 	   blink::WebLocalFrameImpl::createChildFrame(blink::FrameLoadRequest const&, WTF::AtomicString const&, blink::HTMLFrameOwnerElement*)
2245.9ms   84.8%	 	    blink::FrameLoader::load(blink::FrameLoadRequest const&, blink::FrameLoadType, blink::HistoryItem*, blink::HistoryLoadType)
2238.1ms   84.5%	 	     blink::FrameLoader::startLoad(blink::FrameLoadRequest&, blink::FrameLoadType, blink::NavigationPolicy)
2158.1ms   81.5%	 	      blink::DocumentLoader::startLoadingMainResource()
2158.1ms   81.5%	 	       blink::DocumentLoader::maybeLoadEmpty()
2153.0ms   81.3%	 	        blink::DocumentLoader::finishedLoading(double)
1685.6ms   63.6%	 	         blink::DocumentLoader::commitData(char const*, unsigned long)
1682.1ms   63.5%	 	          blink::DocumentLoader::ensureWriter(WTF::AtomicString const&, blink::KURL const&)
1678.1ms   63.4%	 	           blink::DocumentLoader::createWriterFor(blink::DocumentInit const&, WTF::AtomicString const&, WTF::AtomicString const&, bool, blink::ParserSynchronizationPolicy, blink::KURL const&)
1572.6ms   59.4%	 	            blink::FrameLoader::receivedFirstData()
1468.3ms   55.4%	 	             blink::FrameLoader::dispatchDidClearDocumentOfWindowObject()
1450.8ms   54.8%	 	              blink::ScriptController::initializeMainWorld()
1450.8ms   54.8%	 	               blink::ScriptController::windowProxy(blink::DOMWrapperWorld&)
1414.1ms   53.4%	 	                blink::WindowProxy::initializeIfNeeded()
1414.1ms   53.4%	 	                 blink::WindowProxy::initialize()
 676.4ms   25.5%	 	                  blink::WindowProxy::createContext()
 337.0ms   12.7%	 	                  blink::FrameLoaderClientImpl::didCreateScriptContext(v8::Local<v8::Context>, int, int)
 318.1ms   12.0%	 	                  blink::WindowProxy::updateDocument()
 315.2ms   11.9%	 	                   blink::WindowProxy::updateDocumentProperty()
 315.2ms   11.9%	 	                    blink::toV8(blink::Node*, v8::Local<v8::Object>, v8::Isolate*)
 313.1ms   11.8%	 	                     blink::Document::wrap(v8::Isolate*, v8::Local<v8::Object>)
 303.7ms   11.4%	 	                      blink::V8DOMWrapper::createWrapper(v8::Isolate*, v8::Local<v8::Object>, blink::WrapperTypeInfo const*)
 303.7ms   11.4%	 	                       blink::V8PerContextData::createWrapperFromCache(blink::WrapperTypeInfo const*)
 303.7ms   11.4%	 	                        blink::V8PerContextData::createWrapperFromCacheSlowCase(blink::WrapperTypeInfo const*)
 300.6ms   11.3%	 	                         blink::V8PerContextData::constructorForType(blink::WrapperTypeInfo const*)
 300.6ms   11.3%	 	                          blink::V8PerContextData::constructorForTypeSlowCase(blink::WrapperTypeInfo const*)
 282.8ms   10.6%	 	                           v8::FunctionTemplate::GetFunction(v8::Local<v8::Context>)
  17.7ms    0.6%	 	                           blink::V8PerContextData::constructorForType(blink::WrapperTypeInfo const*)
   0.1ms    0.0%	 	                           WTF::StringView::StringView(char const*)
   3.1ms    0.1%	 	                         blink::V8ObjectConstructor::newInstance(v8::Isolate*, v8::Local<v8::Function>)
   2.1ms    0.0%	 	                     blink::DOMDataStore::getWrapper(blink::Node*, v8::Isolate*)
   2.9ms    0.1%	 	                   blink::WindowProxy::updateSecurityOrigin(blink::SecurityOrigin*)
  74.3ms    2.8%	 	                  blink::MainThreadDebugger::contextCreated(blink::ScriptState*, blink::LocalFrame*, blink::SecurityOrigin*)
   6.1ms    0.2%	 	                  blink::OriginTrialContext::initializePendingFeatures()
   6.1ms    0.2%	 	                   blink::installOriginTrials(blink::ScriptState*)
   3.8ms    0.1%	 	                    blink::installOriginTrialsForModules(blink::ScriptState*)
   3.8ms    0.1%	 	                     WTF::String::~String()
   2.3ms    0.0%	 	                    WTF::String::String(char const*)
   2.2ms    0.0%	 	                  blink::WindowProxy::setupWindowPrototypeChain()
  36.8ms    1.3%	 	                blink::FrameLoader::dispatchDidClearWindowObjectInMainWorld()
  17.4ms    0.6%	 	              blink::FrameLoaderClientImpl::dispatchDidClearWindowObjectInMainWorld()
  82.0ms    3.0%	 	             blink::FrameLoaderClientImpl::dispatchDidCommitLoad(blink::HistoryItem*, blink::HistoryCommitType)
  16.0ms    0.6%	 	             blink::InspectorInstrumentation::didCommitLoad(blink::LocalFrame*, blink::DocumentLoader*)
   5.3ms    0.1%	 	             blink::FrameLoader::setHistoryItemStateForCommit(blink::FrameLoadType, blink::HistoryCommitType, blink::FrameLoader::HistoryNavigationType)
   1.1ms    0.0%	 	             blink::FrameLoaderClientImpl::isControlledByServiceWorker(blink::DocumentLoader&)
  56.9ms    2.1%	 	            blink::LocalDOMWindow::installNewDocument(WTF::String const&, blink::DocumentInit const&, bool)
  16.8ms    0.6%	 	            blink::FrameLoader::didBeginDocument()
  11.7ms    0.4%	 	            blink::FrameLoader::didInstallNewDocument(bool)
   9.5ms    0.3%	 	            blink::LocalDOMWindow::create(blink::LocalFrame&)
   7.9ms    0.2%	 	            blink::LocalFrame::setDOMWindow(blink::LocalDOMWindow*)
   2.6ms    0.0%	 	            blink::DocumentWriter::create(blink::Document*, blink::ParserSynchronizationPolicy, WTF::AtomicString const&, WTF::AtomicString const&)
   4.0ms    0.1%	 	           blink::FrameLoader::clear()
 390.9ms   14.7%	 	         blink::DocumentLoader::endWriting(blink::DocumentWriter*)
  74.9ms    2.8%	 	         blink::DocumentLoader::commitIfReady()
   1.6ms    0.0%	 	         blink::DocumentLoadTiming::setResponseEnd(double)
   2.0ms    0.0%	 	        blink::SubstituteData::isValid() const
   1.7ms    0.0%	 	        blink::ResourceRequest::url() const
   1.5ms    0.0%	 	        blink::ResourceResponse::ResourceResponse(blink::KURL const&, WTF::AtomicString const&, long long, WTF::AtomicString const&, WTF::String const&)
  29.2ms    1.1%	 	      blink::ProgressTracker::progressStarted()
  23.3ms    0.8%	 	      blink::FrameLoaderClientImpl::dispatchDidStartProvisionalLoad(double)
  18.4ms    0.6%	 	      blink::FrameLoaderClientImpl::createDocumentLoader(blink::LocalFrame*, blink::ResourceRequest const&, blink::SubstituteData const&)
   3.6ms    0.1%	 	      blink::FrameLoader::shouldContinueForNavigationPolicy(blink::ResourceRequest const&, blink::SubstituteData const&, blink::DocumentLoader*, blink::ContentSecurityPolicyDisposition, blink::NavigationType, blink::NavigationPolicy, bool, bool)
   1.9ms    0.0%	 	      blink::FrameLoader::defaultSubstituteDataForURL(blink::KURL const&)
   1.9ms    0.0%	 	      blink::SubstituteData::~SubstituteData()
   1.7ms    0.0%	 	      blink::FrameLoader::upgradeInsecureRequest(blink::ResourceRequest&, blink::Document*) const
   5.2ms    0.1%	 	     blink::FrameLoader::setReferrerForFrameRequest(blink::FrameLoadRequest&)
   2.6ms    0.0%	 	     blink::FrameLoadRequest::~FrameLoadRequest()
 263.1ms    9.9%	 	    blink::WebLocalFrameImpl::initializeCoreFrame(blink::FrameHost*, blink::FrameOwner*, WTF::AtomicString const&, WTF::AtomicString const&)
 115.9ms    4.3%	 	    non-virtual thunk to content::RenderFrameImpl::createChildFrame(blink::WebLocalFrame*, blink::WebTreeScopeType, blink::WebString const&, blink::WebString const&, blink::WebSandboxFlags, blink::WebFrameOwnerProperties const&)
   7.9ms    0.2%	 	    blink::FrameTree::calculateUniqueNameForNewChildFrame(WTF::AtomicString const&, WTF::AtomicString const&) const
   3.3ms    0.1%	 	    blink::FrameLoadRequest::FrameLoadRequest(blink::FrameLoadRequest const&)
   1.3ms    0.0%	 	    blink::FrameLoadRequest::~FrameLoadRequest()
   2.6ms    0.0%	 	  blink::FrameLoadRequest::FrameLoadRequest(blink::Document*, blink::ResourceRequest const&, WTF::AtomicString const&, blink::ContentSecurityPolicyDisposition)
   2.0ms    0.0%	 	  WTF::AtomicString::AtomicString(char const*)
   3.1ms    0.1%	 	 blink::blankURL()
   1.6ms    0.0%	 	 blink::protocolIsJavaScript(WTF::String const&)


Sign in to add a comment