Last Comment Bug 730105 - top sites takes almost 3 seconds to load content
: top sites takes almost 3 seconds to load content
Status: VERIFIED FIXED
:
Product: Firefox for Android
Classification: Client Software
Component: General (show other bugs)
: unspecified
: ARM Android
: P2 normal (vote)
: Firefox 14
Assigned To: Lucas Rocha (:lucasr)
:
Mentors:
Depends on:
Blocks: 721731
  Show dependency treegraph
 
Reported: 2012-02-23 14:03 PST by Dietrich Ayala (:dietrich)
Modified: 2012-06-02 08:40 PDT (History)
13 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---
fixed
verified
verified
beta+


Attachments
(1/3) Fix content provider registration in ContentProviderTest (3.96 KB, patch)
2012-03-16 09:20 PDT, Lucas Rocha (:lucasr)
gbrown: review+
Details | Diff | Review
(2/3) Ensure test query arg on all ContentProvider operations (5.61 KB, patch)
2012-03-16 09:20 PDT, Lucas Rocha (:lucasr)
gbrown: review+
Details | Diff | Review
(3/3) Add Talos test for AwesomeBar frecency filter (5.26 KB, patch)
2012-03-16 09:21 PDT, Lucas Rocha (:lucasr)
jmaher: feedback+
Details | Diff | Review
Add Talos test for AwesomeBar frecency filter (5.18 KB, patch)
2012-03-19 08:07 PDT, Lucas Rocha (:lucasr)
gbrown: review+
Details | Diff | Review

Description Dietrich Ayala (:dietrich) 2012-02-23 14:03:13 PST
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?) 2012-02-23 14:08:53 PST
What buildid? This should be fixed by bug 725914
Comment 2 Dietrich Ayala (:dietrich) 2012-02-23 14:39:49 PST
How do I find buildid on native Fennec?
Comment 3 Naoki Hirata :nhirata (please use needinfo instead of cc) 2012-02-23 14:51:27 PST
place about:buildconfig in the url
Comment 4 Dietrich Ayala (:dietrich) 2012-02-23 14:55:00 PST
built from http://hg.mozilla.org/mozilla-central/rev/5e756e59a794
Comment 5 Mark Finkle (:mfinkle) (use needinfo?) 2012-02-23 15:27:18 PST
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 [:kbrosnan] 2012-02-23 17:28:05 PST
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) 2012-02-23 18:10:20 PST
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] 2012-03-09 10:07:39 PST
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?) 2012-03-09 10:22:27 PST
(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] 2012-03-14 10:04:03 PDT
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?) 2012-03-14 10:46:07 PDT
Could be fixed by bug 735660 too.
Comment 12 Lucas Rocha (:lucasr) 2012-03-15 05:11:02 PDT
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) 2012-03-16 04:13:47 PDT
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) 2012-03-16 09:20:39 PDT
Created attachment 606595 [details] [diff] [review]
(1/3) Fix content provider registration in ContentProviderTest
Comment 15 Lucas Rocha (:lucasr) 2012-03-16 09:20:54 PDT
Created attachment 606596 [details] [diff] [review]
(2/3) Ensure test query arg on all ContentProvider operations
Comment 16 Lucas Rocha (:lucasr) 2012-03-16 09:21:11 PDT
Created attachment 606597 [details] [diff] [review]
(3/3) Add Talos test for AwesomeBar frecency filter
Comment 17 Lucas Rocha (:lucasr) 2012-03-16 09:22:38 PDT
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] (pto May 28-June 13) 2012-03-16 11:09:40 PDT
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) 2012-03-16 11:24:50 PDT
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] (pto May 28-June 13) 2012-03-16 12:30:24 PDT
(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) 2012-03-16 12:35:47 PDT
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) 2012-03-19 03:18:12 PDT
(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) 2012-03-19 08:07:13 PDT
Created attachment 607170 [details] [diff] [review]
Add Talos test for AwesomeBar frecency filter
Comment 24 Lucas Rocha (:lucasr) 2012-03-19 08:09:23 PDT
This patch moves the test to the right section of robocop.ini
Comment 28 Dietrich Ayala (:dietrich) 2012-04-10 14:01:05 PDT
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?) 2012-04-10 14:09:09 PDT
(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?) 2012-04-10 14:09:37 PDT
Also, do you see a delay when tapping in the awesomebar?
Comment 31 Dietrich Ayala (:dietrich) 2012-04-12 14:40:57 PDT
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) 2012-04-12 14:42:31 PDT
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) 2012-05-02 07:50:11 PDT
Verified fixed on:

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

Note You need to log in before you can comment on or make changes to this bug.