730105 - top sites takes almost 3 seconds to load content

Status: VERIFIED FIXED

(Firefox for Android Graveyard :: General, defect, P2)

Description

[Dietrich Ayala (:dietrich)]

start cold
open a new tab

the Top Sites content area is blank white for up to 3 seconds.

opening warm shows a visible delay also, but not as bad, less than 1 second.

Comment 1

[Mark Finkle (:mfinkle) (use needinfo?)]

What buildid? This should be fixed by bug 725914

Comment 2

[Dietrich Ayala (:dietrich)]

How do I find buildid on native Fennec?

Comment 3

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

place about:buildconfig in the url

Comment 4

[Dietrich Ayala (:dietrich)]

built from http://hg.mozilla.org/mozilla-central/rev/5e756e59a794

Comment 5

[Mark Finkle (:mfinkle) (use needinfo?)]

That build has bug 725914 in it. We'll need to know the type of device and the size of your browser.db file. You should be able to "Move to SDCard" in Android > Settings > Applications > Nightly to do the move. Then you can pull off the DB.

Naoki might have an add-on to give a rough estimate of the DB size too.

Comment 6

[Kevin Brosnan [Ex-Mozilla]]

The simplest way to check db size is to open the Android settings > Applicaitons > Manage Applications > find Nightly and select it > press move to sdcard > go back to your home screen and launch Nightly. Then attach your phone to your computer as a storage device. check /Android/data/org.mozilla.fennec/files/mozilla/$profile-name.

Comment 7

[Dietrich Ayala (:dietrich)]

Nexus S didn't have it there. It has no removable storage. It had a "move to usb storage" option, which moved the data to http://cl.ly/3225322t333Z3M3i0I23.

Looks like some secure storage option maybe?

Comment 8

[JP Rosevear [:jpr]]

Mark, Lucas can we help Dietrich extract his database size and figure out what's going on here?

Comment 9

[Mark Finkle (:mfinkle) (use needinfo?)]

(In reply to JP Rosevear [:jpr] from comment #8)
> Mark, Lucas can we help Dietrich extract his database size and figure out
> what's going on here?

While we try to do that... Dietrich, can you make a video of this happening? It might be useful to see what aspects of the UI are loading slowly.

Comment 10

[Johnathan Nightingale [:johnath]]

Also - can we reproduce this on other Nexus S phones, or is it specific to Dietrich's profile?

Comment 11

[Mark Finkle (:mfinkle) (use needinfo?)]

Could be fixed by bug 735660 too.

Comment 12

[Lucas Rocha (:lucasr)]

As Mark mentioned, I just found out yesterday that the perf improvements on DB were not being used at all. This means that even though Dietrich reproduce this bug on a build with my patches, the code that I added was simply not being used.

So, hopefully, once my patch for bug 735660 reaches Nightly, this bug will actually be fixed.

Comment 13

[Lucas Rocha (:lucasr)]

I think the most outcome for this bug should be a talos test for the awesomebar filter function. This way we can have a better picture of what kind of performance we have on a history table with a few thousand entries.

Comment 14

[Lucas Rocha (:lucasr)]

Attachment: (1/3) Fix content provider registration in ContentProviderTest

Comment 15

[Lucas Rocha (:lucasr)]

Attachment: (2/3) Ensure test query arg on all ContentProvider operations

Comment 16

[Lucas Rocha (:lucasr)]

Attachment: (3/3) Add Talos test for AwesomeBar frecency filter

Comment 17

[Lucas Rocha (:lucasr)]

These patches add a talos test for our awesomebar filter query. It adds 10k rows to history then runs the query with a known value. This should allow us to spot regressions and to track awesomebar DB performance from now on.

Comment 18

[Geoff Brown [:gbrown]]

Comment on attachment 606597 [details] [diff] [review]
(3/3) Add Talos test for AwesomeBar frecency filter

This test looks good to me but I want to get Joel's input since I am not as familiar with Talos. 

I think we want the new test listed in the Talos section of robocop.ini and commented out, like testPan and testCheck. Joel, is that right?

I am seeing run times for testBrowserProviderPerf of about 180 seconds -- is that reasonable for a Talos test?

Comment 19

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 606597 [details] [diff] [review]
(3/3) Add Talos test for AwesomeBar frecency filter

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

there is no UI interaction?  Does this need to be a robocop based test?  

180 seconds is not a big deal.  It is longer, but we have a lot of tests which are much longer.  Do you want to measure the time, or another factor?  How stable is the number over 10 runs?

::: mobile/android/base/tests/robocop.ini
@@ +13,5 @@
>  [testPasswordProvider]
>  [testPasswordEncrypt]
>  [testFormHistory]
>  [testBrowserProvider]
> +[testBrowserProviderPerf]

this is a talos test, please put in the section below as :gbrown mentioned.

Comment 20

[Geoff Brown [:gbrown]]

(In reply to Joel Maher (:jmaher) from comment #19)
> 180 seconds is not a big deal.  It is longer, but we have a lot of tests
> which are much longer.  Do you want to measure the time, or another factor? 
> How stable is the number over 10 runs?

Most of the 180 second run-time is spent inserting history entries; after that is set up, the test measures and reports only the time for a filter operation, which is relatively quick: For 3 runs I got 273, 264, 269 ms.

Comment 21

[Joel Maher ( :jmaher ) (UTC -8)]

great, those are fairly consistent.  The more runs the better, but at 3 minutes+/run, this could take a long time if we do 10 iterations.  Will 5 data points averaged out be good for reporting?

Comment 22

[Lucas Rocha (:lucasr)]

(In reply to Joel Maher (:jmaher) from comment #21)
> great, those are fairly consistent.  The more runs the better, but at 3
> minutes+/run, this could take a long time if we do 10 iterations.  Will 5
> data points averaged out be good for reporting?

Yes, 5 data points averaged should be enough.

Comment 23

[Lucas Rocha (:lucasr)]

Attachment: Add Talos test for AwesomeBar frecency filter

Comment 24

[Lucas Rocha (:lucasr)]

This patch moves the test to the right section of robocop.ini

Comment 25

[Lucas Rocha (:lucasr)]

Pushed:
http://hg.mozilla.org/integration/mozilla-inbound/rev/c46674a93ef0
http://hg.mozilla.org/integration/mozilla-inbound/rev/13a22b4849b4
http://hg.mozilla.org/integration/mozilla-inbound/rev/991782b44d41

Comment 26

[Marco Bonardo [:mak]]

https://hg.mozilla.org/mozilla-central/rev/c46674a93ef0
https://hg.mozilla.org/mozilla-central/rev/13a22b4849b4
https://hg.mozilla.org/mozilla-central/rev/991782b44d41

Comment 27

[Mark Finkle (:mfinkle) (use needinfo?)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/92c37fb62be5
https://hg.mozilla.org/releases/mozilla-aurora/rev/804baf4a522d
https://hg.mozilla.org/releases/mozilla-aurora/rev/5c7568cddff5

Comment 28

[Dietrich Ayala (:dietrich)]

I'm still seeing long delay fairly often when loading top sites and about:home (which loads some top sites). Using Nightly build 4/09.

Comment 29

[Mark Finkle (:mfinkle) (use needinfo?)]

(In reply to Dietrich Ayala (:dietrich) from comment #28)
> I'm still seeing long delay fairly often when loading top sites and
> about:home (which loads some top sites). Using Nightly build 4/09.

Delays are not out of the question depending on the phone, the OS version and the amount of data you have in the DB.

Is it still ~ 3 seconds? The original bug we fixed took a ~15 sec delay to ~2. Using a newer version of Android (with it's newer version of sqlite) took it <1 sec.

Comment 30

[Mark Finkle (:mfinkle) (use needinfo?)]

Also, do you see a delay when tapping in the awesomebar?

Comment 31

[Dietrich Ayala (:dietrich)]

just tried a cold start and top sites in about:home took 12 seconds to load.

(In reply to Mark Finkle (:mfinkle) from comment #30)
> Also, do you see a delay when tapping in the awesomebar?

i've seen 3+ second delays there recently. i just tried a few times at cold start and got 1-2 seconds.

Comment 32

[Dietrich Ayala (:dietrich)]

ok, if i cold start and as quick as possible focus the location bar, i can get 4 seconds to load it. db contention as top sites are probably also loading?

Comment 33

[Cristian Nicolae (:xti)]

Verified fixed on:

Firefox 14.0a2, Firefox 15.0a1 (2012-05-02)
Device: Samsung Captivate
OS: Android 2.2