1117465 - [Calendar][FFOS7715 v2.1][performance] Cold launching Calendar app spends a longer time

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: Gaia::Calendar, defect)

Description

[ffos_st]

Description:
Open a background calendar app spend a longer time.

Device:
SPRD 7715ea
Build Identifier:
20150104132530

Steps to Reproduce:
1)Fill the device with dual SIM card(China Unicom, China Mobile),a speed Class4 8G size T card,50 call records,250 phone contacts,100 SMS,300 photos, 150 songs,50 videos.
2)Five minutes wait to open the boot (cold start) time consuming & not the first time the boot is opened (hot start) time-consuming.
3)Wait five minutes after boot & not the first time to open the boot.
4)Click application to start the timer icon.
5)All the icons are displayed to the end to complete the interface timing.
6)Repeat steps 1 through 4 to reproduce the timing.

Actual Result:
1)This version of the test three times a cold start & hot start, took the following seconds:
cold：2.718,2.756,3.356   Average：2.943 
hot：0.7,0.656,0.675   Average：0.677
2)Contrast version 7715ea-Android：
cold：1.450,1.381,1.225    Average：1.352   
hot：0.837,0.981,0.951    Average：0.923 
3)Contrast machine Flame Firefox:
cold：1.85,1.681,1.656   Average：1.729 
hot：0.631,0.563,0.531    Average：0.575
4)Contrast version of FireFox-V1.4:
cold：3.925,4.319,4.731	   Average：4.325
hot：0.573,0.466,0.579    Average：0.539

Cold start with 7715ea Android version & Contrast machine flame gap was：54% & 41%
Hot start with 7715ea Android version & Contrast machine flame gap was：15% & 20%

Expected Result:
This version Cold Start & Hot start time consuming and is not slow in comparison engine version 1.4 or earlier with similar.

Repro frequency:3/3,100%

Comment 1

[Steven Yang [:styang]]

major performance issue.

Comment 2

[Steven Yang [:styang]]

Danny, Chens, this is the major performance issue, please help to check it.

Comment 3

[Steven Yang [:styang]]

Need the updated data. ni? william

Comment 4

[William Hsu [:whsu]]

Dolphin v2.1 (512MB) test result.
Visually complete time (Calendar cold launch): 3598.3 ms

Detailed information.
@ "Calendar"

 - Workload: 900 events

 - Memory Usage:
      "mozPerfMemoryAverage": {
        "app": {
          "uss": "13.900",
          "pss": "17.290",
          "rss": "29.710",
          "vsize": "75.760"
        },

 - Cold launch time:
   ~ moz-chrome-dom-loaded: 2276.3 ms
   ~ moz-chrome-interactive: 2333.2 ms
   ~ moz-app-visually-complete : 3598.3 ms
   ~ moz-content-interactive : 3602.7 ms

@ Build information:
 - Gaia-Rev        2d0df3907319edf55a643b7d4a103534579ebef0
 - Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g34_v2_1s/rev/2a3804a0911a
 - Build-ID        20150128161200
 - Version         34.0
 - Device-Name     scx15_sp7715ea
 - FW-Release      4.4.2
 - FW-Incremental  eng.cltbld.20150128.193949
 - FW-Date         Wed Jan 28 19:40:01 EST 2015


Many thanks! :)

Comment 5

[William Hsu [:whsu]]

NI?whsu to do extra performance comparison. (Flame 512 MB: v1.4 vs v2.1)

Comment 6

[William Hsu [:whsu]]

Summarizing all data.

1. From partner,
  - 7715ea-FFOSv2.1 ：2.943s
  - Flame-FFOS      ：1.729s
  - 7715ea-Android  : 1.352s
  - 7715ea-FFOSv1.4 : 4.325s

2. From Mozilla,
  - 7715ea-FFOSv2.1：    3.598s
  - Flame v1.4 (512 MB): 1.663s  (Mean time to show calendar app)
  - Flame v2.1 (512 MB): 1.735s (Mean time to show calendar app)

3. Software configuration
  @ Workload: 900 events (Mozilla build)

  @ Build information
   - Flame v1.4 (JB, single-core with 512 MB)
    ~ Gaia-Rev        04265f42139a7a5c611c45e4869582642927e835
    ~ Gecko-Rev       af6e951d18ca
    ~ Build-ID        20150201160228
    ~ Version         30.0

   - Flame v2.1 (KK, single-core with 512 MB)
    ~ Gaia-Rev        63f291df9b9ad8498fb8fc7fb8bf070524406a5c
    ~ Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g34_v2_1/rev/70b8982a523d
    ~ Build-ID        20150202161206
    ~ Version         34.0
    ~ Device-Name     flame
    ~ FW-Release      4.4.2
    ~ Bootloader      L1TC100118D0


>>>>>>>>> Comments >>>>>>>>
1. Compare Flame v1.4 to Flame v2.1, there is no performance regression. ( They are 72ms apart)
2. Compare the cold launch time with different devices (Flame v2.1 & Dolphin v2.1s),
   this bug seems to happen on specific device.
3. We also can do a branch check if necessary. ( v2.1 vs v2.1s )

Comment 7

[Danny Liang [:dliang]]

Update profiling data on v2.1s and v1.4 by emulating gaia performance test on userdebug build. I added log in following 5 points.

(1) Get Content Parent
(2) App init
(3) Dom load
(4) Chrome interactive
(5) app-visually-complete

	        v2.1s	  v1.4
(1)->(3)       2.503s	1.673s
(1)->(5)       2.843s	 1.99s
(3)->(5)	0.34s	0.317s

By my profiling, looks like it consume much time from (1) to (3) on v2.1s on dolphin. But we didn't observe this situation on flame, it's weird. Will keep profiling in (1) -> (3).

Comment 8

[William Hsu [:whsu]]

Add Dolphin v1.4 (512 MB) and Dolphin v1.4 (256 MB) test result

> 1. From partner,
>   - 7715ea-FFOSv2.1 ：2.943s
>   - Flame-FFOS      ：1.729s
>   - 7715ea-Android  : 1.352s
>   - 7715ea-FFOSv1.4 : 4.325s
> 
> 2. From Mozilla,
>   - 7715ea-FFOSv2.1  (512 MB)： 3.598s
    - 7715ea-FFOSv1.4  (512 MB)： 2.056s
    - 7715ga-FFOSv1.4  (256 MB):  1.846s
>   - Flame v1.4 (512 MB):        1.663s (Mean time to show calendar app)
>   - Flame v2.1 (512 MB):        1.735s (Mean time to show calendar app)
> 
> 3. Software configuration
>   @ Workload: 900 events (Mozilla build)
> 
>   @ Build information
>    - Flame v1.4 (JB, single-core with 512 MB)
>     ~ Gaia-Rev        04265f42139a7a5c611c45e4869582642927e835
>     ~ Gecko-Rev       af6e951d18ca
>     ~ Build-ID        20150201160228
>     ~ Version         30.0
> 
>    - Flame v2.1 (KK, single-core with 512 MB)
>     ~ Gaia-Rev        63f291df9b9ad8498fb8fc7fb8bf070524406a5c
>     ~ Gecko-Rev      
>     ~ https://hg.mozilla.org/releases/mozilla-b2g34_v2_1/rev/70b8982a523d
>     ~ Build-ID        20150202161206
>     ~ Version         34.0
>     ~ Device-Name     flame
>     ~ FW-Release      4.4.2
>     ~ Bootloader      L1TC100118D0

     - Dolphin v1.4 (512 MB)
       ~ Gaia-Rev        04265f42139a7a5c611c45e4869582642927e835
       ~ Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g30_v1_4/rev/93a7fd645e82
       ~ Build-ID        20150204160202
       ~ Version         30.0
       ~ Device-Name     scx15_sp7715ea
       ~ FW-Release      4.4.2

     - Dolphin v1.4 (256MB)
       ~ Gaia-Rev        04265f42139a7a5c611c45e4869582642927e835
       ~ Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g30_v1_4/rev/93a7fd645e82
       ~ Build-ID        20150204160202
       ~ Version         30.0
       ~ Device-Name     scx15_sp7715ga
       ~ FW-Release      4.4.2

Comment 9

[Danny Liang [:dliang]]

Update more:
With GAIA_OPTIMIZE=1, it can save ~200ms in (1) to (3), and I saw the search bar is showed before main page of calendar, it might have some impacts.

Hi Chens, is there any way to remove search bar for test?

Comment 10

[Sherman Chen [:chens] (inactive)]

Hi Danny, you may try this patch: https://github.com/shamenchens/gaia/commit/04c5e4bbf4c89c779232dc9932eb71d97ed68d10

Comment 11

[Sherman Chen [:chens] (inactive)]

Hi Danny,

updating my patch, this add some log to know when app window/app chrome is rendered: 
https://github.com/shamenchens/gaia/commit/52f028caaa923930eda6d821df7a52164bb5027c

Comment 12

[Danny Liang [:dliang]]

Attachment: calendar-v2.1s.html

systrace for calendar cold launch of dolphin v2.2s

Comment 13

[Danny Liang [:dliang]]

Attachment: calendar-v1.4-2.html

systrace for calendar cold launch of dolphin v1.4

Comment 14

[Danny Liang [:dliang]]

By comparison on systrace of v1.4 and v2.1s, we found homescreen spent some time for GC on v2.1s. Will check GC by homescreen and estimate the overhead.

Comment 15

[Danny Liang [:dliang]]

There is obvious difference by removing GC of homescreen, it should not the main root cause.

w/ gc:
It spent 2.42s from (1) Get Content Parent to (5) app-visually-complete on eng build w/ enable systrace

w/o gc:
It spent 2.45s from (1) Get Content Parent to (5) app-visually-complete on eng build w/ enable systrace

Comment 16

[Danny Liang [:dliang]]

Summarize the profiling by systrace and gecko-profiler
By systrace, we have following findings on eng build
1. From click to app-visually-complete, v2.1s (512MB device) spent 2.44s and v1.4 (256MB device) spent 1.55s, the breakdown of big item as following (v2.1s, v1.4)
   - b2g: (587.73ms, 291.38ms)
   - homescreen: (104.22ms, 29.60ms)
   - calendar: (1238.23ms, 883.98ms)
   - compositor: (155.67ms, 142.14ms)
2. ksmd enabled on v2.1s (512MB device)

By gecko profiler to profile b2g, we found IPDL::PBrowser::RecvAsyncMessage spent more time and it's called by aw_handleEvent @app_window.js in system app, suspected it's caused by rocket bar?

Comment 17

[Danny Liang [:dliang]]

Attachment: profiling.tar.gz

systrace and gecko profiler log in both v1.4 and v2.1s

Comment 18

[Danny Liang [:dliang]]

Hi reporter,
Could you help to clarify why do we need to enable ksmd in 512MB device? It might consume more CPU at background in idle.

Hi Chens,
Would you mind take a look at calendar app to see if any change to cause page appear slowly?

Comment 19

[Sherman Chen [:chens] (inactive)]

Found two bugs related to calendar cold launch time: 

bug 1042422 fixed regression since 1.4, and introduce ~100ms extra launch time (per bug 1059349 comment 7)
bug 1079557 had improved `content-interactive` performance from >1.8s to <1.2s on 2.2, but code structure is completely different from 2.1, we would definitely take a good amount of work to make similar changes to 2.1 (per bug 1079557 comment 19)

Comment 20

[Danny Liang [:dliang]]

(In reply to Sherman Chen [:chens] from comment #19)
> Found two bugs related to calendar cold launch time: 
> 
> bug 1042422 fixed regression since 1.4, and introduce ~100ms extra launch
> time (per bug 1059349 comment 7)
> bug 1079557 had improved `content-interactive` performance from >1.8s to
> <1.2s on 2.2, but code structure is completely different from 2.1, we would
> definitely take a good amount of work to make similar changes to 2.1 (per
> bug 1079557 comment 19)

I didn't see obvious improvement on dolphin 512MB device by reverting commit of bug 1042422.
By my test, the default average launch time is 2.377s but it's 2.39s if we revert commit of bug 1042422.

Comment 21

[Danny Liang [:dliang]]

(In reply to Danny Liang [:dliang] from comment #18)
> Hi reporter,
> Could you help to clarify why do we need to enable ksmd in 512MB device? It
> might consume more CPU at background in idle.
> 
> Hi Chens,
> Would you mind take a look at calendar app to see if any change to cause
> page appear slowly?

Hi Siiaceon, could you help to check ksmd?

Comment 22

[Miller Medeiros [:millermedeiros]]

(In reply to Sherman Chen [:chens] from comment #19)
> Found two bugs related to calendar cold launch time: 
> 
> bug 1042422 fixed regression since 1.4, and introduce ~100ms extra launch
> time (per bug 1059349 comment 7)
> bug 1079557 had improved `content-interactive` performance from >1.8s to
> <1.2s on 2.2, but code structure is completely different from 2.1, we would
> definitely take a good amount of work to make similar changes to 2.1 (per
> bug 1079557 comment 19)

just to clarify that on Bug 1079557 we improved from 1.8s because our original v2.2 changes degraded the performance a lot (it was taking more than 2s before I started to make changes to improve the performance). Most of the gains was trying to make the new module system load as fast as it was with plain globals. The changes that would be more beneficial to v2.1 and easier to implement are described on Bug 1079557 comment 19. Some things we just can't get faster without improving IndexedDB or changing the way we store the data needed for first calendar render.

Comment 23

[siiaceon]

ksmd is inherited from Android which good for memory system, and it is always enable for a long term.  It will not change except for some reason must be.
However, ksmd is not the directly rootcause for this performance issue. So need try more to improve.

Comment 24

[Danny Liang [:dliang]]

(In reply to siiaceon from comment #23)
> ksmd is inherited from Android which good for memory system, and it is
> always enable for a long term.  It will not change except for some reason
> must be.
> However, ksmd is not the directly rootcause for this performance issue. So
> need try more to improve.

You guys told us you just enable ksmd on quad-core devices due to there is much CPU overhead, so we didn't enable it on 256MB dolphin device.
If we didn't enable ksmd on 256MB dolphin, why should we enable it on 512MB device?
I think it's non-necessary to enable ksmd on 512MB devices due to we don't encounter memory pressure problems.

Comment 25

[siiaceon]

Agree with you. 
But for 7715ea android enable it, whatever we think 256M is disable with risk. So default not change from original on 2.1ea even 512 with which being more customer than 1.4ga.
However 1.4ga no such big issue from customer for long time. We are trying more, if failed, try disable ksmd.  

Thanks Danny

Comment 26

[Sherman Chen [:chens] (inactive)]

Attachment: wip - improve calendar nexttick on 2.1

Comment 27

[siiaceon]

thanks Sherman
st pls pick out result then

Comment 28

[Danny Liang [:dliang]]

(In reply to Sherman Chen [:chens] from comment #26)
> Created attachment 8571881 [details]
> wip - improve calendar nexttick on 2.1

With the patch, still didn't see obvious improvement.
w/o patch, the average launch time is 2.463s, w/ patch, it's 2.483s

Hi Siiaceon, could you update your result w/ this patch?

Comment 29

[siiaceon]

Hi Danny, sorry for waiting more because of test resource leak.
By the way, we try disable ksmd, seem no effect.
( use "echo 0 > /sys/kernel/mm/ksm/run" to disable)

keep ni until st guys put result here.

Comment 30

[Danny Liang [:dliang]]

(In reply to siiaceon from comment #29)
> Hi Danny, sorry for waiting more because of test resource leak.
> By the way, we try disable ksmd, seem no effect.
> ( use "echo 0 > /sys/kernel/mm/ksm/run" to disable)
> 
> keep ni until st guys put result here.

W/ disable ksmd, it can improve ~30ms in calendar launch, the average launch time is 2.403s by my test.

Comment 31

[yong.ren]

Hi danny:

   Sorry to reply late, with this patch and our gaia system optimization,
   the latest data is 2.273s。 

   I think the patch have made some improvement, 
   but i don't know the exact saved time of the patch.

   we really appreciate for your support, thanks a lot.

Comment 32

[Danny Liang [:dliang]]

(In reply to yong.ren from comment #31)
> Hi danny:
> 
>    Sorry to reply late, with this patch and our gaia system optimization,
>    the latest data is 2.273s。 
> 
>    I think the patch have made some improvement, 
>    but i don't know the exact saved time of the patch.
> 
>    we really appreciate for your support, thanks a lot.

By comment9 and comment28, gaia optimization improve ~200ms but the patch looks no help.
What's your result w/o patch and gaia optimization?

Comment 33

[yong.ren]

sorry danny, cause of test resource leak, we can not provide the result w/o patch and gaia optimaization.

before we make some improvement in system and calendar, the data is as Description.

Comment 34

[BMO Automation]

Firefox OS is not being worked on