985170 - [B2G] [Marketplace] [The Weather Channel] App takes a long time to load when launching the app a second time

Status: RESOLVED DUPLICATE of bug 984618

(Core :: Graphics, defect, P1)

Description

[Chris Kreinbring [:CKreinbring]]

Attachment: Video of Weather Channel relaunch

Description:
Launching the Weather Channel app after the first time takes a while to load the city weather page.  The user does not see a prompt that the app is loading data.

Repro Steps:
1) Update Buri to Build ID: 20140317040204
2) Launch the Marketplace and download the Weather Channel app.
3) Return to the homescreen and launch The Weather Channel.
4) Navigate through the setup until the city weather page is reached.
5) Long tap on the Home button then swipe the Weather Channel card upwards to close it.
6) Relaunch The Weather Channel. 
7) Observe the app as it is launched, and note how long it takes to go to the city weather page.

Actual:
The app launches, but there is no loading icon.  The also takes a long time to load, about 15 seconds.

Expected:
The app launches and loads quickly.  There is also a loading icon present as the app loads.

Environmental Variables
Device: Buri 1.4 mozilla RIL
Build ID: 20140317040204
Gecko: https://hg.mozilla.org/mozilla-central/rev/25cfa01ba054
Gaia: 8f802237927c7d5e024fb7dca054dd5efef6b2e6
Platform Version: 30.0a1
Firmware Version: V1.2-device.cfg

Notes:
Repro frequency: 100%
See attached video clip and logcat logs

Comment 1

[Chris Kreinbring [:CKreinbring]]

On the Buri 1.3 mozilla RIL, there is still no loading icon but the subsequent launches are much faster, taking about 5.5 seconds.

Build ID: 20140318004002
Gecko: https://hg.mozilla.org/releases/mozilla-b2g28_v1_3/rev/cf2042938526
Gaia: 2ea2aab306bd1c941719160cdcb49ee9d755dc17
Platform Version: 28.0
Firmware Version: V1.2-device.cfg

Comment 2

[Jason Smith [:jsmith]]

The loading icon is really an app-specific issue, so I'd suggest filing that as a separate bug. Can you open a different bug for that?

As for the subsequent launch performance - can you provide measurements from a stopwatch on subsequent launch time for this app on 1.3 vs. 1.4 ran 5 times in a row?

Comment 3

[Chris Kreinbring [:CKreinbring]]

After five launch/close cycles, the 1.4 had an average load time of 10.5 seconds.  This is an improvement over the original build, which was close to 15 seconds.  The 1.3 had an average launch time of 6.5 seconds.

Comment 4

[Jason Smith [:jsmith]]

(In reply to ckreinbring from comment #3)
> After five launch/close cycles, the 1.4 had an average load time of 10.5
> seconds.  This is an improvement over the original build, which was close to
> 15 seconds.  The 1.3 had an average launch time of 6.5 seconds.

Can you also check 1.1 as a point of comparison?

Comment 5

[Chris Kreinbring [:CKreinbring]]

On the 1.1 build, the average launch time was also 6.5 seconds.

Build ID: 20140318041202
Gecko: https://hg.mozilla.org/releases/mozilla-b2g18/rev/2c70ef07c5b3
Gaia: 44a2ddf63373f8e95c784faf4ed4d60081699c61
Platform Version: 18.1
Firmware Version: V1.2-device.cfg

Comment 6

[Jason Smith [:jsmith]]

Okay - so we've got a gecko regression here then by roughly 4 seconds on a partner app.

Comment 7

[Jason Smith [:jsmith]]

Oh and leaving qawanted here to see if this reproduces with tiling disabled.

Comment 8

[Preeti Raghunath(:Preeti)]

Per the video it does seem fairly long for the launch of the weather channel.

Comment 9

[Josh Schmitt [Joshs]]

(In reply to Jason Smith [:jsmith] from comment #7)
> Oh and leaving qawanted here to see if this reproduces with tiling disabled.

With tiling disabled The Weather Channel takes around 7.0 seconds to fully load to the city of choice. There is no loading icon either.

Environmental Variables:
Device: Buri 1.4 MOZ
BuildID: 20140320000349
Gaia: 53edbf08b0a750c31e8c6b2c20f2b1315b1412d1
Gecko: 9b482d6994fd
Version: 30.0a2
Firmware Version: V1.2-device.cfg

Comment 10

[Jason Smith [:jsmith]]

We need a logcat here.

We do know this is a tiling regression though.

Comment 11

[Matthew Vaughan]

Attachment: LogCat for the issue.

(In reply to Jason Smith [:jsmith] from comment #10)
> We need a logcat here.
> 
> We do know this is a tiling regression though.

Attached is the requested logcat.

Comment 12

[Jason Smith [:jsmith]]

Lots of genlock errors in the logcat.

03-20 16:35:30.849: E/libgenlock(751): perform_lock_unlock_operation: GENLOCK_IOC_DREADLOCK failed (lockType0x1, err=Connection timed out fd=31)

Comment 13

[Jason Smith [:jsmith]]

I'm adding the dependency here to bug 984618 as the same genlock errors are seen in both bugs & bug 984618 has a patch. When that lands, we should retest this.

Comment 14

[Benoit Girard (:BenWa)]

Attachment: Pseudo-hang when profiling start up

Comment 15

[Benoit Girard (:BenWa)]

I'm seeing a multisecond IPC call to GetCookieString at:

    __futex_syscall3
    IPDL::PCookieService::SendGetCookieString
    crtg_getCookie() @ http://m.uk.weather.com/:1289
    <Anonymous>() @ http://m.uk.weather.com/:1285
    js::RunScript
    JS::EvaluateString
    html5::RunFlushLoop
    Startup::XRE_InitChildProcess
    (root)

and:

    __futex_syscall3
    IPDL::PCookieService::SendGetCookieString
    jQuery.cookie() @ jquery-1.7.1-IE7-twccore.min.js:208
    TWC.initpco/init() @ pco:649
    TWC.initpco() @ pco:117
    <Anonymous>() @ http://m.uk.weather.com/:1320
    js::RunScript
    JS::EvaluateString
    html5::RunFlushLoop
    Startup::XRE_InitChildProcess
    (root)

Those are the major bottlenecks. This app also forces several reflows that hurt the performance a bit.

Comment 16

[Benoit Girard (:BenWa)]

Here's a profile of the entire system. I'm actually not seeing the GetCookieString anymore. I'm instead seeing 8 seconds of idle time during the startup:

http://people.mozilla.org/~bgirard/cleopatra/#report=b3a5a788f8a1e29c75a1ce9b2d2d66b91638e689

I don't see any platform bugs other than bug 987951.

Comment 17

[Milan Sreckovic [:milan] (needinfo for best results)]

So, the bug 984618 issues were just masking a problem that is elsewhere?

Comment 18

[Benoit Girard (:BenWa)]

(In reply to Milan Sreckovic [:milan] from comment #17)
> So, the bug 984618 issues were just masking a problem that is elsewhere?

I think bug 984618 were accounting for some large delays but they were not the only cause of delay.

I'm not sure if the cookie stuff is generally reproducible or was just a rare instance of the main process being slow (maybe even because of bug 984618).

I was able to reproduce bug 987951 reliably however.

Comment 19

[No-Jun Park [:njpark]]

On latest master, this is the result:

With HWC enabled: 15.5 Seconds until it reaches the city weather page, and it shows rendering error like bug 984618 in the end.

With HWC disabled: 6.5 seconds until it reaches the city weather page, and there is no rendering error.

Gaia      80af23f8c74d9d2e9388d8ed3c204040b5c528ec                         │
│ Gecko     https://hg.mozilla.org/mozilla-central/rev/c69c55582faa          │
│ BuildID   20140326040202                                                   │
│ Version   31.0a1

Comment 20

[Jason Smith [:jsmith]]

QA wanted - can we retest this on today's trunk build?

Comment 21

[No-Jun Park [:njpark]]

The performance is much better with HWC enabled on today's master branch:

With HWC enabled / disabled: 4 seconds until it reaches the city weather page, and there is no rendering error.

│ Gaia      9da1b9c11bf518bce882be305ae121c44c5d1e05                         │
│ Gecko     https://hg.mozilla.org/mozilla-central/rev/9afe2a1145bd          │
│ BuildID   20140327040202                                                   │
│ Version   31.0a1