Improve ContactManager to make the conversion of contacts faster (200+ms).

RESOLVED FIXED in Firefox 38

Status

defect
RESOLVED FIXED
5 years ago
4 years ago

People

(Reporter: sinker, Assigned: bent.mozilla)

Tracking

unspecified
2.2 S4 (23jan)
x86_64
Linux
Dependency tree / graph

Firefox Tracking Flags

(blocking-b2g:2.2+, firefox36 wontfix, firefox37 wontfix, firefox38 fixed, b2g-v2.2 fixed, b2g-master fixed)

Details

(URL)

Attachments

(4 attachments, 1 obsolete attachment)

(Reporter)

Description

5 years ago
ContactManager spend quite a lot of time to wrap/convert Contacts.

The possible solutions that I know are
 - a faster way to convert data.
 - be multi-threading to wrap/convert Contact objects.

Maybe, there is a better solution.  Let's discuss here.
Should the component be Core::DOM:Contacts ?
Depends on: 1019081
ContactManager._convertContact() news mozContact which is a JS implemented WebIDL.
No longer blocks: B2G-Multicore
(Reporter)

Updated

4 years ago
Blocks: 1082262

Comment 3

4 years ago
No wrappedJSObject is used nor __exposedProps__ is needed now. The class in question is redefined in WebIDL. Anyway, bug 783057 has nothing to do with this bug.
See Also: 783057

Comment 4

4 years ago
The time spent here (1020ms) is much higher than Thinker's estimation (200+ms).

With reference-workload-light (200 contacts), it takes ~4.6 sec / 3866 1-ms samples to stabilize on Flame. There are 936 samples (~1.02 sec) in the callees of _convertContacts and 772 samples (~0.85 sec) of this:

> let newContact = new this._window.mozContact(contact.properties);

Namely, it takes ~4.25ms to new a mozContact.
We should consider making it a feature blocker if this improves launch time.
feature-b2g: --- → 2.2?
(Reporter)

Comment 6

4 years ago
assign to Ting-Yuan for temporary since he is studying.  Assign to others if he think there is better candidate for this bug.
Assignee: nobody → thuang

Comment 7

4 years ago
It seems that argument passing to the constructor of mozContact takes most of the time. By returning Contact (which implements mozContact) rather than mozContact, the _convertContact() and launch time become much faster. The improvement roughly match what described in comment 4, which is ~0.85 sec.

Before:
http://people.mozilla.org/~bgirard/cleopatra/#report=842f0c00e65b531ff1ebc281a17c6522012d034a
After:
http://people.mozilla.org/~bgirard/cleopatra/#report=8716fa7833c8ba11e19e4966ca66817fde8eb761

I'm still trying to catch up the knowledge here and not sure if doing so is OK or not. Gregor, may I know your opinion?
Flags: needinfo?(anygregor)
I just want to note that this definitely could make the SMS app startup faster as well.
Performance improvement is one of 2.2 features.
feature-b2g: 2.2? → 2.2+

Updated

4 years ago
Status: NEW → ASSIGNED
Gregor asked me to look into this. I don't think the patch can land as is, unfortunately, because even though all of the properties will exist properly on the Contact object (instead of a mozContact object), it won't have the correct prototype and things like |contact instanceof window.mozContact| will return false.

Ting-Yuan, would you mind testing that?

It seems like the easiest way to fix this would be to have getters for all of the properties listed in the mozContact webidl interface and to simply store their values on a sub-object hanging off of the webidl object.

I have a sketch of a patch that bent and I cooked up that I'll attach here. I haven't run it at all, so it might not work at all; however, I think it's the right approach at least.
Flags: needinfo?(anygregor)
Posted patch sketchSplinter Review
Hopefully, this is useful.
Attachment #8544307 - Flags: feedback?(thuang)

Comment 12

4 years ago
http://people.mozilla.org/~bgirard/cleopatra/#report=417802cc8c33d4a1c922b4350daae66688a23aa7

It's roughly 613ms faster than the unmodified codes in terms of convertContacts: the number of samples filtered by convertContacts are 956 and 399 respectively.

The improvement to the overall running time is 5080 - 4765 = 315ms, measured by the first and last call-stack pikes.

I'm still catching up the knowledge here so I can't comment on the result. Perhaps this should be a need-info rather than a feedback :)

Updated

4 years ago
Attachment #8544307 - Flags: feedback?(thuang)
Ting-Yuan, do you see an improvement with the SMS launch time as well?

Comment 14

4 years ago
w/o mrbkap's patch
http://people.mozilla.org/~bgirard/cleopatra/#report=197474f417f2508c63c56da5e1ebb34fbf3db354

w/ mrbkap's patch
http://people.mozilla.org/~bgirard/cleopatra/#report=75ade316f94877c1c2cef4c9da254d646e0afdf6

There are 178/59 samples of convertContacts and the sample size is roughly 1.17ms. The improvement is 140ms.

The overall running time is 4465ms/4172ms and the improvement is larger than 140ms, but the outlines/shapes of the stack-depths looked a little bit different. In the contacts case they looked quite similar; The patch just made the histogram more compact. Maybe we should first define a deterministic way to measure the start-up times.

Updated

4 years ago
Target Milestone: --- → 2.2 S6 (20feb)
Hi Ting-Yuan,

I don't have time to drive this patch into the tree myself. I requested feedback from you basically as a needinfo :)

The idea behind the patch is that in the current code, we're iterating, in chrome code, over an object that's already been cloned into content. Unfortunately, due to the way our wrappers work, each iteration is very expensive because we have to continually switch security contexts between chrome and content. I think this is what you found when you wrote your first patch.

Unfortunately, the way that we create the DOM object is important, so we can't avoid the round-trip in order to create that object. My patch fixes this by doing as much of the work as possible in C++ (which doesn't have the same performance bottlenecks). I don't know enough about this bug to know if the 613ms is enough, but I guess it's a start. I'm happy to answer any questions you have about this patch or anything else here.
Flags: needinfo?(thuang)
Posted patch Better idea (obsolete) — Splinter Review
How about this? This should remove all the X-Ray wrappers and cloning.
Attachment #8549042 - Flags: feedback?(thuang)

Updated

4 years ago
blocking-b2g: --- → 2.2?
feature-b2g: 2.2+ → ---

Updated

4 years ago
blocking-b2g: 2.2? → 2.2+
(In reply to ben turner [:bent] (use the needinfo? flag!) from comment #16)
> Created attachment 8549042 [details] [diff] [review]
> Better idea
> 
> How about this? This should remove all the X-Ray wrappers and cloning.

Before:
https://people.mozilla.org/~bgirard/cleopatra/#report=9895482ee79f718ff9d3b26fd0a1ed2a03abba89&selection=0,1,871,63,63,875,154,876
After:
https://people.mozilla.org/~bgirard/cleopatra/#report=6c324bafe551534036817cc3c0b0f965e6605366&selection=0,1,818,24,24,823,132,824


This patch reduced the total time of _convertContacts() from 1087ms to 348ms which is a 700ms+ win! However the total time seems only reduced 200ms+. Maybe the time is distributed to later property access through Xray?
Flags: needinfo?(thuang)
The "after" profile there doesn't really show a whole lot of time spent in contacts now... It looks ore like we're triggering a bunch of layout flushes from some mutationHandler() function?
I profiled again.

Timing before patch

https://people.mozilla.org/~bgirard/cleopatra/#report=4b1a1c34d1bcd6081faa92e598654228fdc144c2&selection=0,1,829,48,48,832,141,833

I/Communications: Content JS LOG: Performance Entry: mark|navigationLoaded|532.1532129999999|0|1421730699919 
I/Communications: Content JS LOG: Performance Entry: mark|navigationInteractive|568.716619|0|1421730699955 
I/Communications: Content JS LOG: Performance Entry: mark|visuallyLoaded|737.555319|0|1421730700123 
I/Communications: Content JS LOG: Performance Entry: mark|contentInteractive|1221.3032210000001|0|1421730700607 
I/Communications: Content JS LOG: Performance Entry: mark|fullyLoaded|6787.150922999999|0|1421730706173 

After patch

https://people.mozilla.org/~bgirard/cleopatra/#report=fb16142e0a015e9fd3c5851eb16b4fbf2e67afc1&selection=0,1,847,55,55,851,143,852

I/Communications( 1074): Content JS LOG: Performance Entry: mark|navigationLoaded|542.2859759999999|0|1421731546806 
I/Communications( 1074): Content JS LOG: Performance Entry: mark|navigationInteractive|578.574699|0|1421731546842 
I/Communications( 1074): Content JS LOG: Performance Entry: mark|visuallyLoaded|737.4027159999999|0|1421731547000 
I/Communications( 1074): Content JS LOG: Performance Entry: mark|contentInteractive|1098.611324|0|1421731547362 
I/Communications( 1074): Content JS LOG: Performance Entry: mark|fullyLoaded|4661.193346|0|1421731550924 

The time to visuallyLoaded is about the same. The contentInteractive is 123ms faster. fullyLoaded is 2126ms faster.

However I noticed there is a JS error after patch.

W/Communications( 1174): renderPhoto@app://communications.gaiamobile.org/contacts/js/views/list.js:1040:5
W/Communications( 1174): onscreen@app://communications.gaiamobile.org/contacts/js/views/list.js:116:5
W/Communications( 1174): safeOnscreenCallback@app://communications.gaiamobile.org/shared/js/tag_visibility_monitor.js:527:7
W/Communications( 1174): notifyInRange@app://communications.gaiamobile.org/shared/js/tag_visibility_monitor.js:521:7
W/Communications( 1174): notifyOnscreenInRange@app://communications.gaiamobile.org/shared/js/tag_visibility_monitor.js:512:5
W/Communications( 1174): callCallbacks@app://communications.gaiamobile.org/shared/js/tag_visibility_monitor.js:428:7
W/Communications( 1174): updateVisibility@app://communications.gaiamobile.org/shared/js/tag_visibility_monitor.js:172:7
W/Communications( 1174): init@app://communications.gaiamobile.org/shared/js/tag_visibility_monitor.js:133:5
W/Communications( 1174): monitorTagVisibility@app://communications.gaiamobile.org/shared/js/tag_visibility_monitor.js:578:3
W/Communications( 1174): n
W/Communications( 1174): Content JS WARN: monitorTagVisiblity: Exception in onscreenCallback: Error: Permission denied to access property 'valueOf' setImageURL@app://communications.gaiamobile.org/contacts/js/views/list.js:1008:9

I think it's because the Contact returned from DOMRequest is type |any| so it's properly wrapped. The cross-compartment wrapper on Contact.photo[0] does not allow us to call methods from content.
Flags: needinfo?(bent.mozilla)
10          mov     r7, ip
(gdb) b Proxy.cpp:47
Breakpoint 1 at 0xb5f2daf8: file ../../../gecko/js/src/proxy/Proxy.cpp, line 47.
(gdb) c
Continuing.
[New Thread 5715.5731]

Breakpoint 1, js::AutoEnterPolicy::reportErrorIfExceptionIsNotPending (this=this@entry=0xbeda7220, cx=cx@entry=0xb6a31b70, id=...) at ../../../gecko/js/src/proxy/Proxy.cpp:48
48                                     prop);
(gdb) bt
#0  js::AutoEnterPolicy::reportErrorIfExceptionIsNotPending (this=this@entry=0xbeda7220, cx=cx@entry=0xb6a31b70, id=...) at ../../../gecko/js/src/proxy/Proxy.cpp:48
#1  0xb5f2e514 in AutoEnterPolicy (act=1, id=..., wrapper=..., handler=0xb66124d0 <xpc::FilteringWrapper<js::SecurityWrapper<js::CrossCompartmentWrapper>, xpc::Opaque>::singleton>, cx=0xb6a31b70, 
    this=0xbeda7220, mayThrow=<optimized out>) at ../../../gecko/js/src/jsproxy.h:599
#2  js::Proxy::get (cx=0xb6a31b70, proxy=..., receiver=..., id=..., vp=...) at ../../../gecko/js/src/proxy/Proxy.cpp:288
#3  0xb5d7350e in JSObject::getGeneric (cx=<optimized out>, obj=..., receiver=..., id=..., vp=...) at ../../../gecko/js/src/vm/NativeObject.h:1358
#4  0xb5f8fbf0 in GetPropertyOperation (vp=..., lval=..., pc=<optimized out>, script=..., fp=<optimized out>, cx=<optimized out>) at ../../../gecko/js/src/vm/Interpreter.cpp:251
#5  Interpret (cx=0xb6a31b70, state=...) at ../../../gecko/js/src/vm/Interpreter.cpp:2372
#6  0xb5f9588c in js::RunScript (cx=cx@entry=0xb6a31b70, state=...) at ../../../gecko/js/src/vm/Interpreter.cpp:448
#7  0xb5f95ac2 in js::Invoke (cx=cx@entry=0xb6a31b70, args=..., construct=construct@entry=js::NO_CONSTRUCT) at ../../../gecko/js/src/vm/Interpreter.cpp:517
#8  0xb5f96118 in js::Invoke (cx=cx@entry=0xb6a31b70, thisv=..., fval=..., argc=argc@entry=1, argv=0xbeda7d38, rval=rval@entry=...) at ../../../gecko/js/src/vm/Interpreter.cpp:554
#9  0xb5e4cdba in js::jit::DoCallFallback (cx=0xb6a31b70, frame=0xbeda7d80, stub_=<optimized out>, argc=1, vp=0xbeda7d28, res=...) at ../../../gecko/js/src/jit/BaselineIC.cpp:9496
#10 0xb37b58a4 in ?? ()
#11 0xb37b58a4 in ?? ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) p handler
$12 = (const xpc::FilteringWrapper<js::SecurityWrapper<js::CrossCompartmentWrapper>, xpc::Opaque> *) 0xb66124d0 <xpc::FilteringWrapper<js::SecurityWrapper<js::CrossCompartmentWrapper>, xpc::Opaque>::singleton>
This patch works but I don't know why photo[] needs clone.

https://people.mozilla.org/~bgirard/cleopatra/#report=3e5dbdd9ce76e15bcb4a8d7dfa16cbc2abf6b37d&selection=0,1,792,33,33,795,121,796

I/Communications: Content JS LOG: Performance Entry: mark|navigationLoaded|575.5531820000001|0|1421744120297 
I/Communications: Content JS LOG: Performance Entry: mark|navigationInteractive|611.689304|0|1421744120332 
I/Communications: Content JS LOG: Performance Entry: mark|visuallyLoaded|788.280177|0|1421744120509 
I/Communications: Content JS LOG: Performance Entry: mark|contentInteractive|1053.502214|0|1421744120774 
I/Communications: Content JS LOG: Performance Entry: mark|fullyLoaded|4890.920189|0|1421744124612
Unfortunately I think we need to ask bholley here...
Flags: needinfo?(bent.mozilla) → needinfo?(bobbyholley)
(In reply to ben turner [:bent] (use the needinfo? flag!) from comment #22)
> Unfortunately I think we need to ask bholley here...

We're going to look at this in-person when I'm in SF tomorrow.
Flags: needinfo?(bobbyholley)
Hi Kan-Ru, your approach works too, but bholley and I think that this might be more correct. Basically the way you were doing this before uses an advanced function that shouldn't be necessary in this case (though it is still fine and supported). Please give this patch a try and see how it performs?
Attachment #8549042 - Attachment is obsolete: true
Attachment #8549042 - Flags: feedback?(thuang)
Attachment #8552558 - Flags: feedback?(kchen)
(In reply to ben turner [:bent] (use the needinfo? flag!) from comment #24)
> Created attachment 8552558 [details] [diff] [review]
> Better idea 3!
> 
> Hi Kan-Ru, your approach works too, but bholley and I think that this might
> be more correct. Basically the way you were doing this before uses an
> advanced function that shouldn't be necessary in this case (though it is
> still fine and supported). Please give this patch a try and see how it
> performs?

Yes, this should work. I was hoping the advanced function would save some createInstance time after reading https://developer.mozilla.org/en-US/docs/Mozilla/WebIDL_bindings#Using_the_WebIDL_constructor

So do you think only clone photo is fine?
Hm, have we seen createInstance showing up in profiles? But yeah, that's fine too. And I think the "photo" property is the only thing you have to worry about (we only need special cloning for DOM objects, not normal binding object types, dictionaries, or JS object types).
I see. Since Blob is already a DOM object so it wont be WebIDL wrapped again so we have to clone it. I'll try the patch today.
with new patch

https://people.mozilla.org/~bgirard/cleopatra/#report=3e5dbdd9ce76e15bcb4a8d7dfa16cbc2abf6b37d&selection=0,1,792,33,33,795,121,796

I/Communications( 1184): Content JS LOG: Performance Entry: mark|navigationLoaded|549.5803460000001|0|1421895623363 
I/Communications( 1184): Content JS LOG: Performance Entry: mark|navigationInteractive|586.4489550000001|0|1421895623399 
I/Communications( 1184): Content JS LOG: Performance Entry: mark|visuallyLoaded|744.1171989999999|0|1421895623557 
I/Communications( 1184): Content JS LOG: Performance Entry: mark|contentInteractive|1047.184496|0|1421895623860 
I/Communications( 1184): Content JS LOG: Performance Entry: mark|fullyLoaded|4617.305052|0|1421895627430 

Looks good.
Comment on attachment 8552558 [details] [diff] [review]
Better idea 3!

Review of attachment 8552558 [details] [diff] [review]:
-----------------------------------------------------------------

bholley could you r+ this patch?
Attachment #8552558 - Flags: review?(bobbyholley)
Attachment #8552558 - Flags: feedback?(kchen)
Attachment #8552558 - Flags: feedback+
Comment on attachment 8552558 [details] [diff] [review]
Better idea 3!

Review of attachment 8552558 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good. Did you verify that the performance characteristics are the same as with the _create approach (i.e. the createInstance overhead is negligible)? I agree with your logic for that, but it depends whether it's a problem in practice.
Attachment #8552558 - Flags: review?(bobbyholley) → review+
(In reply to Bobby Holley (Busy with media, don't ask for DOM/JS/XPConnect things) from comment #30)
> Comment on attachment 8552558 [details] [diff] [review]
> Better idea 3!
> 
> Review of attachment 8552558 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Looks good. Did you verify that the performance characteristics are the same
> as with the _create approach (i.e. the createInstance overhead is
> negligible)? I agree with your logic for that, but it depends whether it's a
> problem in practice.

Yes, the overhead is totally negligible. Thanks for the review!
Assignee: thuang → bent.mozilla
https://hg.mozilla.org/mozilla-central/rev/aa2ab2b3f01b
Status: ASSIGNED → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → FIXED
Please request b2g37 approval on this when you get a chance.
Flags: needinfo?(bent.mozilla)
Target Milestone: 2.2 S6 (20feb) → 2.2 S4 (23jan)
Attachment #8552558 - Flags: approval-mozilla-b2g37?
bent can you please fill in the approval request comment form to mainly know risk here ?

"[Approval Request Comment]
[Bug caused by] (feature/regressing bug #):
[User impact] if declined:
[Testing completed]:
[Risk to taking this patch] (and alternatives if risky):
[String changes made]:"
[Approval Request Comment]
[Bug caused by] (feature/regressing bug #): This has been around forever I think
[User impact] if declined: Slower contacts
[Testing completed]: There's a bunch of contacts tests running everywhere I think
[Risk to taking this patch] (and alternatives if risky): Anything that could be wrong here would be immediately obvious, so given green tests I don't think there's much risk here.
[String changes made]: None
Flags: needinfo?(bent.mozilla)
CC'ing geo/edward chen to see if they are seeing any improvements in datazilla data around this.
Attachment #8552558 - Flags: approval-mozilla-b2g37? → approval-mozilla-b2g37+

Updated

4 years ago
No longer depends on: 1019081
You need to log in before you can comment on or make changes to this bug.