Very slow chrome to content DOM access

NEW
Unassigned

Status

()

Core
XPConnect
7 years ago
7 days ago

People

(Reporter: bz, Unassigned)

Tracking

(Depends on: 3 bugs, Blocks: 3 bugs)

Trunk
x86
Mac OS X
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [qf:p1])

Attachments

(1 attachment)

The steps are in bug 613487.

Profile says:

  4% in js_Interpret
  4% GC
 89% under js::proxy_GetProperty

The property get time is about half XrayWrapper::getPropertyDescriptor and half JSCrossCompartmentWrapper::call.

Under getPropertyDescriptor we have:

 4% entering cross-compatment calls
 4% resolveOwnProperty on the wrapper
 9% JS_WrapValue
 8% JS_DefinePropertyById
 3% auto-entering compartments
 3% XPCCallContext ctors
 3% XPCNativeMember::resolve
 2% leaving cross-compartment calls

and some minor stuff.

Under call we have:

 4% self time in XPCWrappedNative::CallMethod
 2% XPCCallContext ctors
 8% NativeData2JS
 4% calling actual DOM methods (previousSibling, nextSibling, etc)
 4% nsScriptSecurityManager::CanAccess (from CallMethod).  Can we remove this
    yet?
 1% XPCCallContext::CanCallNow.
 1% ~CallMethodHelper.
 1% NS_IsMainThread_P
 1% various xptInterfaceEntry stuff.
So summary:

1)  Under call() this is all xpconnect suck.  No fast-path for wrapping, looks
    like, and probably useless security checks, plus general silliness.  Any way
    we could call quickstubs from the proxy code somehow?  ;)
2)  Under getPropertyDescriptor, about 10% of the total runtime is managing our
    compartment.  
3)  JS_WrapValue is mostly JSCompatment::wrap self time and JSWrapper::New.
4)  JS_DefinePropertyById is ending up in newShape, changeProperty,
    lookupProperty, putProperty, etc.
Blocks: 536910
Created attachment 8848224 [details]
Zip of testcase that can be used, since the other one is gone
(Reporter)

Updated

5 months ago
Depends on: 1348095
(Reporter)

Updated

5 months ago
Depends on: 1348099

Updated

5 months ago
Duplicate of this bug: 1334263
Blocks: 1337841
Whiteboard: [qf]
Whiteboard: [qf] → [qf:p1]
Blocks: 1258946

Updated

3 months ago
Depends on: 1363956

Updated

3 months ago
Assignee: nobody → janus926

Updated

3 months ago
Depends on: 1363959

Updated

3 months ago
Depends on: 1363963

Comment 4

2 months ago
UncheckedUnwrap is now the top symbol on the reversed callstack after bug 1363963 landed, https://perfht.ml/2rrY3S3.
I suspect that bug 1355109 would help here more than anything else.

Comment 6

2 months ago
If so, do I still need to work on bug 1348099? The numbers in bug 1348099 comment 27 and 29 look worthy though.
Depends on: 1355109
The patch in bug 1355109 should help with getters, but so far not with method calls or indexed access on lists.  So improving those cases would still be a good idea; I expect the patches in bug 1348099 do help with method calls.

Updated

2 months ago
Depends on: 1377815

Comment 8

a month ago
Replace the empty if [1] by MOZ_ASSERT_IF doesn't get better numbers for the micro benchmark (bug 1348095 comment 3).

[1] http://searchfox.org/mozilla-central/rev/f1472e5b57fea8d4a7bbdd81c44e46958fe3c1ce/js/src/proxy/Wrapper.cpp#344-345

Comment 9

28 days ago
From VTune, I see:

(a) accessing object scope in XrayResolveOwnProperty() [1] and getExpandoObject() [2] is expensive
(b) the if clause for ExposeObjectToActiveJS() [3] is the reason why Wrapper::wrappedObject() stays on the top of profile

Now we have two calls to getExpandoObject() and two calls to getTargetObject() in a single Proxy::get(), one pair in hasOwn() [4][5] and one pair in GetProtoType() [6]. I am thinking something like CreateProtoWalkingContext() and pass the context to hasOwn() and GetProtoType(), so we can call getExpandoObject() and getTargetObject() just once. It'd also be good if we improve (a) and (b).

[1] http://searchfox.org/mozilla-central/rev/3a3af33f513071ea829debdfbc628caebcdf6996/dom/bindings/BindingUtils.cpp#1721
[2] http://searchfox.org/mozilla-central/rev/3a3af33f513071ea829debdfbc628caebcdf6996/js/xpconnect/wrappers/XrayWrapper.cpp#1153
[3] http://searchfox.org/mozilla-central/rev/3a3af33f513071ea829debdfbc628caebcdf6996/js/src/proxy/Wrapper.cpp#346-347
[4] http://searchfox.org/mozilla-central/rev/3a3af33f513071ea829debdfbc628caebcdf6996/js/xpconnect/wrappers/XrayWrapper.cpp#2100
[5] http://searchfox.org/mozilla-central/rev/3a3af33f513071ea829debdfbc628caebcdf6996/js/xpconnect/wrappers/XrayWrapper.cpp#1513
[6] http://searchfox.org/mozilla-central/rev/3a3af33f513071ea829debdfbc628caebcdf6996/js/xpconnect/wrappers/XrayWrapper.cpp#2412,2414
Running the test case is a lot better as of bug 1355109 landed. Reducing the number of times calling getExpandoObject() and getTargetObject() that I mentioned in comment 9 will help, but probably doesn't block this bug? Are there anything else that you think we should do?
Flags: needinfo?(bzbarsky)
So I just tried re-profiling both the testcase from bug 1348095 comment 3 and the testcase from bug 613487.

On the latter, we're no longer a long pole: Xray time is less than 1/3 the time spent in xpath evaluation, for example....

On the former, a profile is at https://perfht.ml/2w0yrv2 but note that it's not running in a sandbox and hence does not benefit from bug 1355109 afaict.

The main thing that would help here would probably be extending the caching to more cases, but that may depend on the compartments work jorendorff is doing.

The other thing that would be useful here are "real life" testcases instead of microbenchmarks (e.g. actual extension content scripts where this is a problem).
Flags: needinfo?(bzbarsky)
I thought sandboxes were the only cases that we expected bug 1355109 to help.
> I thought sandboxes were the only cases that we expected bug 1355109 to help.

For now, yes, until we merge chrome compartments and rework Xray expandos.

Updated

22 days ago
Depends on: 1384790
(In reply to Boris Zbarsky [:bz] (vacation Aug 14-27) from comment #11)
> The other thing that would be useful here are "real life" testcases instead
> of microbenchmarks (e.g. actual extension content scripts where this is a
> problem).

Bug 1369274 might be what you are looking for.
Depends on: 1369274
Yep, thank you!  And thank you for the profiles in there!
Depends on: 1388538

Updated

7 days ago
Assignee: janus926 → nobody
You need to log in before you can comment on or make changes to this bug.