Closed Bug 1211395 Opened 4 years ago Closed 4 years ago

Performance regression in Message

Categories

(Firefox OS Graveyard :: Gaia::SMS, defect, P1)

ARM
Gonk (Firefox OS)
defect

Tracking

(blocking-b2g:2.5+)

RESOLVED FIXED
blocking-b2g 2.5+

People

(Reporter: bobby.chien+bugzilla, Assigned: steveck)

References

()

Details

(Keywords: perf, regression, Whiteboard: [p=2])

Attachments

(1 file, 1 obsolete file)

SMS v2.2 cold launch: 1340ms
SMS current cold launch: 1630ms (~290ms regression)
SMS v2.2 USS: 12.86MB
SMS current USS: 19.94MB (~7MB regression)
blocking-b2g: --- → 2.5+
Priority: -- → P1
I think the memory issue is tracked in bug 1197231 already.
Let's profile the launch time regression.
Whiteboard: [p=2]
I've profiled the master and 2.2(only gaia message app is 2.2, system and geck are still 2.5) here[1], I think the number is quite close to Bobby's numer that we're have more than 250ms regression. Some regression before navigationLoaded is expected because we split the style into more files and the number of the css is increased, but the duration between navigationInteractive and visuallyLoaded increased a lot. Will take some more profiling for this interval.

BTW the number of memory looks not increase that much, I suspect it would be more related to platform changes. But we also need more profiling to verify this(like message 2.5 + 2.2 platform).

[1] https://docs.google.com/a/mozilla.com/spreadsheets/d/1zKzlI7LIJAjZ0UopJObfUhIxb6aHVcSJvH3ChtJ2P_Y/edit?usp=sharing
I forgot to mention that the numbers above was based on light workload, and with raptor version 1.4
I did a profile of the startup that you can see in Cleopatra: https://people.mozilla.org/~bgirard/cleopatra/#report=974e27c536d1ed66207692eb1392ba7cd60da011&selection=0,168,652

Not sure I can analyze this now :)
Here is a better profile of the startup, with 1ms polling instead of 10ms:

https://people.mozilla.org/~bgirard/cleopatra/#report=3989c152339de1ea33c66d127006df4c4ee04541

I think the restyle takes a lot of time... I'll profile a 2.2 SMS on top of 2.5 gecko now, to see what I see as different. According to oleg in bug 1197231 comment 5, the regression is more in Gaia than in Gecko.
(In reply to Julien Wajsberg [:julienw] from comment #6)
> Here is a better profile of the startup, with 1ms polling instead of 10ms:

Sorry, I used 2ms, not 1ms.
Maybe a better profile of startup, I'm not sure if the one in comment 6 used an optimized version. This one is optimized.

SMS 2.5 / Gaia 2.5 / Gecko 2.5
https://people.mozilla.org/~bgirard/cleopatra/#report=74c70fd060f28d7d97b8214ffc20a7d227bcf99e
(In reply to Julien Wajsberg [:julienw] from comment #5)
> I did a profile of the startup that you can see in Cleopatra:
> https://people.mozilla.org/~bgirard/cleopatra/
> #report=974e27c536d1ed66207692eb1392ba7cd60da011&selection=0,168,652
> 
> Not sure I can analyze this now :)

Seems some important part at the beginning is dropped because of limited buffer. Tinyu said that we have to use option -e with few millions of entries to avoid the starting part lost. The command I used here is:
  ./profile.sh start -p b2g -t GeckoMain,Compositor -e 2000000 && ./profile.sh start -p PREALLOCATED_ID -e 2000000

I upload my 2.5 profiling data here: https://people.mozilla.org/~bgirard/cleopatra/#report=7d74a7e9e17fcd990779a8883748fb168b4b5a74 ,and you can see the raptor marks (navigationLaoded/visuallyLoaded/...) are also visible on the timeline. Will upload the 2.2 version later.
mmm OK I thought I got everything because other lines than Messages had data... I'll take care next time !
After some profiling, I found a regression mentioned in Bug 1203464, that we run the font fit for inbox edit form header before visually loaded, and it will take more than 100ms for sure. I think we can dealy the runFontFit until we enter the editing mode.
See Also: → 1203464
Except the bug 1203464, I found another regression in DateTimeFormat because we introduce to replace old API navigator.mozL10n.DateTimeFormat, but initialize Intl.DateTimeFormat will cost around more than 20ms. It seems might not bring the serious impact and we will cache it, our start up call path actually need the DateTimeFormat in container and conversation, and these first 2 initialization stap will increase nearly 50 ms. Not sure we're will the optimize this part here.

I also found longer restyle and reflow before visually loaded, so I add display none to the panel that is not active and it seems could shave 100ms per my testing. Will create a patch that contains the font-fit fix and css styling fix.
Assigning so that managers are happy.
Assignee: nobody → schung
Comment on attachment 8674081 [details] [review]
[gaia] steveck-chung:message-performance-improve > mozilla-b2g:master

This patch contains some ideas:
- Delay the edit mode header font fit: -50ms
- Hide the panel at the beginning : -100ms
- Lazyload the styles: -40ms
- Hide the edit form: -60ms

Based on my profiling, the launch time within this patch could reach the 2.2 standard(on the same gecko). There is a known side effect while displaying the edit form at the first time because we load the styling before display the form, so the style will be applied a little bit late. I will find some other way to show the edit form properly.
Attachment #8674081 - Flags: feedback?(felash)
Attachment #8674081 - Flags: feedback?(azasypkin)
Comment on attachment 8674081 [details] [review]
[gaia] steveck-chung:message-performance-improve > mozilla-b2g:master

Honestly I expected finding some bad impacts on edge cases but I couldn't see anything (on flame). So I'd say it's a win.

Maybe an idea about the style for edit mode: lazyloading while showing the action menu :) (although I didn't see any issue on flame)


Another thing that Vivien showed me and impact us on Aries, and on Flame with this patch (because it makes things faster):
* when launching the app, the splashscreen is removed only at the "load" event.
* the problem with the "load" event is that it's delayed if we start more loads before it happened.
* in our case, we start lazyloading at DOMContentLoaded... and it seems that if we're too quick (eg: on Aries, or on Flame with your patch, because less CSS means faster), our "load" event is delayed even more...
=> the splashscreen is actually dismissed later with your patch...

Vivien suggested that the splashscreen should be removed at the first paint after "visually loaded". NI Vivien about this.

The other alternative, for us, is to start lazyloading at the "load" event. Which is quite infortunate IMO because it could mean delaying some user actions... But this would be for another bug.
Flags: needinfo?(21)
Attachment #8674081 - Flags: feedback?(felash) → feedback+
Yeah I know the splashscreen issue because we already has longer screen than other apps, and discussed with alive before, but he is not sure if it's safe to dismiss the splashscreen earlier because most of the apps still listen to load event instead of DOMContentLoaded. It seems not guarantee that visually loaded will happen earlier than loaded event because I can still see the threads rendering sometimes. Anyway it's definitely good if we could dismiss the splashscreen once we get visually loaded event, otherwise we just produce the prettier profile number but user won't feel any improvement if they need to wait for the screen longer.
One more commit added for lazyload more styles and elements hiding, but the impact is trivial(only ~10ms reduced)
Comment on attachment 8674081 [details] [review]
[gaia] steveck-chung:message-performance-improve > mozilla-b2g:master

Looks good to me as well.

> Maybe an idea about the style for edit mode: lazyloading while showing the action menu :) (although I didn't see any issue on flame).

Or just automatically after "load" for example, but it doesn't look like a big problem to leave it as is right now.

> The other alternative, for us, is to start lazyloading at the "load" event. Which is quite infortunate IMO because it could mean delaying some user actions... But this would be for another bug.

On "load" _or_ as soon as we know that user wants to navigate somewhere, but agree it's definitely another bug.

I run raptor 20 times for the first version of the patch and noticed ~150-200KB memory impact, it maybe just inconsistency in raptor results, but please make sure that we're not regressing memory here :)

Thanks!
Attachment #8674081 - Flags: feedback?(azasypkin) → feedback+
trying more emails for vivien.
Flags: needinfo?(vnicolas)
Flags: needinfo?(gaia)
(In reply to Julien Wajsberg [:julienw] from comment #18)
> Vivien suggested that the splashscreen should be removed at the first paint
> after "visually loaded". NI Vivien about this.
> 

I mostly want a way for apps to control when the splash is removed. See bug 1211853 which is trying to offer that + a mozfirstpaint event so the app will know when to continue lazy loading without deferring first paint.
Flags: needinfo?(vnicolas)
Do you think this will be in 2.5, or rather not ?
Flags: needinfo?(vnicolas)
Flags: needinfo?(gaia)
Flags: needinfo?(21)
Comment on attachment 8674081 [details] [review]
[gaia] steveck-chung:message-performance-improve > mozilla-b2g:master

Tests added for review. And about the memory usage, I found the usage is actually reduced ~400KB per my profiling result. Pending the edit form style loading should gain small benefit in both performance and memory usage.
Attachment #8674081 - Flags: review?(felash)
Attachment #8674081 - Flags: review?(azasypkin)
(In reply to Julien Wajsberg [:julienw] from comment #24)
> Do you think this will be in 2.5, or rather not ?

I supposed the discussion on this particular subject on dev-platform end up too late for 2.5 :/
Flags: needinfo?(vnicolas)
Steve, I think it improves Raptor's numbers but then we find the issue with the "load" event being delayed because of the lazyloading... I think it happens on Aries with current master already, but with your patch it happens now on Flame. As a result the perceived time is _bigger_ with your patch, even though the Raptor time is better.

Therefore, what do you think of this commit on top of yours ?
https://github.com/mozilla-b2g/gaia/commit/3c12fb0a09746d48081c06db12ec84cbe0a766a7

From my tests, it "looks" most of the time faster, however entering a subpanel is most of the time slower (although this could be faster sometimes).
Flags: needinfo?(schung)
Comment on attachment 8674081 [details] [review]
[gaia] steveck-chung:message-performance-improve > mozilla-b2g:master

I left some simple nits in the test.

I'm keeping the r? request for now because I want to make sure this actually helps the user. So far I could compare on Flame only and for the user it's actually _worse_ despite the raptor numbers being better. I'd like to compare on 2 aries and I'll do this either tonight or tomorrow.

Also please look at my commit from comment 27 and tell me what you think.
(In reply to Julien Wajsberg [:julienw] from comment #27)
> Steve, I think it improves Raptor's numbers but then we find the issue with
> the "load" event being delayed because of the lazyloading... I think it
> happens on Aries with current master already, but with your patch it happens
> now on Flame. As a result the perceived time is _bigger_ with your patch,
> even though the Raptor time is better.
> 
> Therefore, what do you think of this commit on top of yours ?
> https://github.com/mozilla-b2g/gaia/commit/
> 3c12fb0a09746d48081c06db12ec84cbe0a766a7
> 
> From my tests, it "looks" most of the time faster, however entering a
> subpanel is most of the time slower (although this could be faster
> sometimes).

Totally agree that we should introduce you idea that helps the visually loaded "looks" earlier before we can control the splash screen in bug 1211853. I didn't expect the regression is that obvious because I can still see the thread rendering while launching sometimes, but I did see it was improved on Flame and this patch should also improve on Aris and brings even impact(in positive way).
Flags: needinfo?(schung)
Comment on attachment 8677463 [details] [review]
[gaia] julienw:1211395-wait-load-event > mozilla-b2g:master

Hey Steve,

I added unit tests for my additional commit.

From my tests:

* on Aries, your patch alone makes things a lot better than master, my additional commit does not bring much benefit because the `load` event did not happen before `visually-loaded`.

* on Flame, your patch makes things worse for the user because the `load` event happens after `visually-loaded` and then lazy-loading files delay the event even more. With my commit we delay things after the `load` event so the splashscreen removal happens about like on master (somewhat earlier, maybe 50ms), but then it's a lot longer to enter a subpanel -- most of the time.

Therefore my advice would be to land only your patch, and move mine to a separate bug in case we want to take it later on.

What do you think ?
Attachment #8674081 - Flags: review?(felash) → review+
Attachment #8677463 - Flags: feedback?(schung)
(In reply to Julien Wajsberg [:julienw] from comment #31)
> Comment on attachment 8677463 [details] [review]
> [gaia] julienw:1211395-wait-load-event > mozilla-b2g:master
> 
> Hey Steve,
> 
> I added unit tests for my additional commit.
> 
> From my tests:
> 
> * on Aries, your patch alone makes things a lot better than master, my
> additional commit does not bring much benefit because the `load` event did
> not happen before `visually-loaded`.
> 
> * on Flame, your patch makes things worse for the user because the `load`
> event happens after `visually-loaded` and then lazy-loading files delay the
> event even more. With my commit we delay things after the `load` event so
> the splashscreen removal happens about like on master (somewhat earlier,
> maybe 50ms), but then it's a lot longer to enter a subpanel -- most of the
> time.
> 
> Therefore my advice would be to land only your patch, and move mine to a
> separate bug in case we want to take it later on.
> 
> What do you think ?

Ok, I can't think of any proper way to reduce the time for entering the next panel. We can see if there's other solution could minimize the side effect or simply apply bug 1211853 if it could be landed in time. Anyway, thanks for the review :)
Blocks: 1217688
Create Bug 1217688 for dismissing the splash screen issue and Bug 1217685 for sms_test refactoring.
No longer blocks: 1217688
Blocks: 1217688
In master : https://github.com/mozilla-b2g/gaia/commit/5361f0e4d6cf2d8771bd5ca2daef5dbc82c65563

Hi Oleg, since already gave some feedback for the patch, I merge the patch first. please file bug if you have any other thought, Thanks!

BTW, do you think this patch addressed the issue in bug 1203464?
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Comment on attachment 8674081 [details] [review]
[gaia] steveck-chung:message-performance-improve > mozilla-b2g:master

(In reply to Steve Chung [:steveck] from comment #34)
> In master :
> https://github.com/mozilla-b2g/gaia/commit/
> 5361f0e4d6cf2d8771bd5ca2daef5dbc82c65563
> 
> Hi Oleg, since already gave some feedback for the patch, I merge the patch
> first. please file bug if you have any other thought, Thanks!

Ah, sorry, just returned back :/ It's in master already, so let's see if it sticks well then. And I see Julien reviewed it quite extensively anyway :)

> BTW, do you think this patch addressed the issue in bug 1203464?

Yeah, I think you addressed the most significant issue from that bug! But maybe we can still leave it open to try the last thing with lazy inserting 4 gaia-headers (2 edit, 1 for Report and 1 for Group views) to spent less time on gaia-header web component initialization (I commented on the bug, + we need to retake fresh profiles there to make sure that this can still be the issue).

Thanks!
Attachment #8674081 - Flags: review?(azasypkin)
Comment on attachment 8677463 [details] [review]
[gaia] julienw:1211395-wait-load-event > mozilla-b2g:master

Would you mind if we move the patch to bug 1217688 and start the discussion over there?
Flags: needinfo?(felash)
Attachment #8677463 - Flags: feedback?(schung)
Comment on attachment 8677463 [details] [review]
[gaia] julienw:1211395-wait-load-event > mozilla-b2g:master

Moved to bug 1217688
Attachment #8677463 - Attachment is obsolete: true
Flags: needinfo?(felash)
You need to log in before you can comment on or make changes to this bug.