709078 - Takes ~10 seconds for awesomescreen results to appear on first startup

Status: VERIFIED FIXED

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

Description

[Joe Drew (not getting mail)]

On my Nexus S, with a mostly-empty profile, it takes a very long time (~10 seconds-ish) for awesomescreen results to appear on first startup. Tapping on the URL bar itself reacts quickly, but the awesomescreen stays empty for a long time. Subsequent taps of the awesomescreen see results in ~1 second.

Comment 1

[Doug Turner (:dougt)]

can you reproduce this with your own build?  If so -- i can tell you how to get a profile.

Comment 2

[Aakash Desai [:aakashd]]

I've seen this on my LG Revolution as well. It started 2 days ago.

Comment 3

[Wesley Johnston (:wesj)]

Attachment: Patch

This patch cuts back on the number of rows we request from the database when it is first shown (but every time it is shown) to 20. If you scroll to the bottom, we'll extend it and search for 100. That feels faster to me. Probably need to get some numbers.

Comment 4

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

Comment on attachment 585912 [details] [diff] [review]
Patch


>+        allPagesList.setOnScrollListener(new OnScrollListener(){
>+            boolean updateScroll = true;

What if we just remove the OnScrollListener instead of this boolean?

>+            public void onScroll(AbsListView view, int firstVisibleItem, int visibleItemCount, int totalItemCount) {

>+                if (totalItemCount > 0 && firstVisibleItem + visibleItemCount > totalItemCount - 5) {

What is the magic | 5 | about?

Looks good. Get some numbers to see what difference this makes.

Comment 5

[Lucas Rocha (:lucasr)]

Wes, have you tried to simply reducing MAX_RESULTS to a number that works well and provides enough entries. I personally think 100 is too much. My guess is that users rarely scroll through more than 30 items. They probably just type more stuff in order to find what they want on the top visible URLs. I'd keep MAX_RESULTS = 100 for the history tab though.

Comment 6

[Lucas Rocha (:lucasr)]

This is just to say that I think your patch adds a complexity that can probably be avoided by simply returning less results from the query.

Comment 7

[Wesley Johnston (:wesj)]

Attachment: Patch

I'm good with that too, although I'm using 20 here. Do we need to go higher than that?

Tried some logging using this in runQuery:

long start = new Date().getTime();
Cursor c = BrowserDB.filter(resolver, constraint, ALLPAGES_MAX_RESULTS);
c.getCount();
Log.i(LOGTAG, "xxx - Got cursor in " + (new Date().getTime() - start) + "ms");
return c;

I'll leave that in the patch if we want it (without the xxx). I also put some logging in AwesomeBarCursorAdapter.getView(), but the time to create each view is only a few ms, and Android is smart enough to only create the views that are visible (i.e. this time seems negligible).

If I'm showing the popup long after Gecko has started (wait for the throbber to appear and disappear once), both 20 or 100 results takes around 500-1000ms on my phone. Subsequent taps also show the results in about the same time for both 100 and 20 results. Around 400ms. (i.e. there doesn't seem to be a win from doing this).

I also tried force showing the AwesomeScreen at the start of GeckoThread.run() in order to simulate tapping the awesomebar during startup (for some reason this triggers the awesomebar to show over and over a few times, which acts as a nice way to repeat the test over and over). On my phone to search for 100 results yields times between 1500ms and 2500ms for. 20 results yields times between 700 - 1200 ms. So there's a win there although its noisy and only during Gecko load.

I also played with passing null for selection in ContentResolver.query if constraint is "" (i.e. removing the WHERE clauses), and see maybe a small boost there (queries done after Gecko load are now around 300 ms for 20 results).

I DON'T think this will magically solve these 10 second load times. I'm not sure what they are. Maybe the logging will help, although I suspect that this time is lost in ContentResolver.

Comment 8

[Wesley Johnston (:wesj)]

Attachment: Patch

Whoops. This doesn't break filter as you type.

Comment 9

[Lucas Rocha (:lucasr)]

(In reply to Wesley Johnston (:wesj) from comment #8)
> Created attachment 586164 [details] [diff] [review]
> Patch
> 
> Whoops. This doesn't break filter as you type.

This patch has some unrelated css changes. Wrong one I guess :-)

Comment 10

[Wesley Johnston (:wesj)]

Attachment: Patch

Comment 11

[Lucas Rocha (:lucasr)]

Comment on attachment 586452 [details] [diff] [review]
Patch

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

Looks good with the nits fixed and patches split. Maybe double-check with UX guys if 20 is a good enough number?

::: mobile/android/base/AwesomeBarTabs.java
@@ +103,4 @@
>  
>      // FIXME: This value should probably come from a
>      // prefs key (just like XUL-based fennec)
> +    private static final int ALLPAGES_MAX_RESULTS = 20;

ALL_PAGES

@@ +624,4 @@
>          mAllPagesCursorAdapter.setFilterQueryProvider(new FilterQueryProvider() {
>              public Cursor runQuery(CharSequence constraint) {
>                  ContentResolver resolver = mContext.getContentResolver();
> +                long start = new Date().getTime();

Add empty line here.

@@ +625,5 @@
>              public Cursor runQuery(CharSequence constraint) {
>                  ContentResolver resolver = mContext.getContentResolver();
> +                long start = new Date().getTime();
> +                Cursor c = BrowserDB.filter(resolver, constraint, ALLPAGES_MAX_RESULTS);
> +                c.getCount();

Explain why you're calling getCount() here. Add empty line here.

@@ +627,5 @@
> +                long start = new Date().getTime();
> +                Cursor c = BrowserDB.filter(resolver, constraint, ALLPAGES_MAX_RESULTS);
> +                c.getCount();
> +                long end = new Date().getTime();
> +                Log.i(LOGTAG, "Got cursor in " + (end - start) + "ms");

Add empty line here.

@@ +628,5 @@
> +                Cursor c = BrowserDB.filter(resolver, constraint, ALLPAGES_MAX_RESULTS);
> +                c.getCount();
> +                long end = new Date().getTime();
> +                Log.i(LOGTAG, "Got cursor in " + (end - start) + "ms");
> +                return c;

I feel that this patch to add the timer should be separate from the other changes.

::: mobile/android/base/db/AndroidBrowserDB.java
@@ +62,5 @@
>      private static final Uri BOOKMARKS_CONTENT_URI_POST_11 = Uri.parse("content://com.android.browser/bookmarks");
>  
>      public Cursor filter(ContentResolver cr, CharSequence constraint, int limit) {
> +        String selection = null;
> +        String[] selectionArgs = null;

Add empty line here. Add a comment explaining why padding null for selection and selectionArgs when constraint is empty is important here.

@@ +63,5 @@
>  
>      public Cursor filter(ContentResolver cr, CharSequence constraint, int limit) {
> +        String selection = null;
> +        String[] selectionArgs = null;
> +        if (!constraint.equals("")) {

Maybe use TextUtils.isEmpty() here? It handles empty string and null.

Comment 12

[Wesley Johnston (:wesj)]

pushed the logging to inbound:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b725e5995f1f

After talking madhava on irc, he suggested that he'd like at least 50 results in the initial query. We'd need to either increase ALL_PAGES_MAX_RESULTS, or come up with a fancier scheme (like my first patch?) to set off a second slow query when the first faster one finished. I can do that but the win didn't seem great enough. Going to look into other things that could possibly be causing this slowness instead.

Comment 13

[Matt Brubeck (:mbrubeck)]

Logging: https://hg.mozilla.org/mozilla-central/rev/b725e5995f1f

Comment 14

[Lucas Rocha (:lucasr)]

Attachment: Only load necessary cols on awesomescreen filter and about:home queries

We were loading thumbnails for each URL in awesomescreen filter query. The query time is cut by half with this patch (for the first time the query runs).

Comment 15

[Brad Lassey [:blassey] (use needinfo?)]

Comment on attachment 588441 [details] [diff] [review]
Only load necessary cols on awesomescreen filter and about:home queries

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

mostly style nits. r=me, but happy to re-review if you'd like

::: mobile/android/base/db/AndroidBrowserDB.java
@@ +63,5 @@
>      private static final String URL_COLUMN_DELETED = "deleted";
>  
>      private static final Uri BOOKMARKS_CONTENT_URI_POST_11 = Uri.parse("content://com.android.browser/bookmarks");
>  
> +    private Cursor filterAllSites(ContentResolver cr, String[] selection, CharSequence constraint, int limit, CharSequence urlFilter) {

s/selection/projection

::: mobile/android/base/db/BrowserDB.java
@@ +41,5 @@
>  import android.database.Cursor;
>  import android.graphics.drawable.BitmapDrawable;
>  
>  public class BrowserDB {
> +    public static String TOP_SITES_URL_FILTER = "about:%";

ABOUT_PAGES_URL_FILTER

@@ +56,5 @@
>  
>      public interface BrowserDBIface {
> +        public Cursor filter(ContentResolver cr, CharSequence constraint, int limit);
> +
> +        public Cursor getTopSites(ContentResolver cr, int limit);

put the impls for these functions here

::: mobile/android/base/db/LocalBrowserDB.java
@@ +96,5 @@
>  
>          return new LocalDBCursor(c);
>      }
>  
> +    public Cursor filter(ContentResolver cr, CharSequence constraint, int limit) {

as far as I can tell this is the same impl as AndroidBrowserDB, except for s/HISTORY/BOOKMARK_COLUMNS. Add getters for those and move it there.

I'm assuming this can be done for other code as well, please file a code clean-up follow-up bug

Comment 16

[Lucas Rocha (:lucasr)]

(In reply to Brad Lassey [:blassey] from comment #15)
> Comment on attachment 588441 [details] [diff] [review]
> Only load necessary cols on awesomescreen filter and about:home queries
> 
> Review of attachment 588441 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> mostly style nits. r=me, but happy to re-review if you'd like
> 
> ::: mobile/android/base/db/AndroidBrowserDB.java
> @@ +63,5 @@
> >      private static final String URL_COLUMN_DELETED = "deleted";
> >  
> >      private static final Uri BOOKMARKS_CONTENT_URI_POST_11 = Uri.parse("content://com.android.browser/bookmarks");
> >  
> > +    private Cursor filterAllSites(ContentResolver cr, String[] selection, CharSequence constraint, int limit, CharSequence urlFilter) {
> 
> s/selection/projection

Done.
 
> ::: mobile/android/base/db/BrowserDB.java
> @@ +41,5 @@
> >  import android.database.Cursor;
> >  import android.graphics.drawable.BitmapDrawable;
> >  
> >  public class BrowserDB {
> > +    public static String TOP_SITES_URL_FILTER = "about:%";
> 
> ABOUT_PAGES_URL_FILTER

Done.

> @@ +56,5 @@
> >  
> >      public interface BrowserDBIface {
> > +        public Cursor filter(ContentResolver cr, CharSequence constraint, int limit);
> > +
> > +        public Cursor getTopSites(ContentResolver cr, int limit);
> 
> put the impls for these functions here

Hmm. This is an interface, no method implementation here. Also, see my comment below.

> ::: mobile/android/base/db/LocalBrowserDB.java
> @@ +96,5 @@
> >  
> >          return new LocalDBCursor(c);
> >      }
> >  
> > +    public Cursor filter(ContentResolver cr, CharSequence constraint, int limit) {
> 
> as far as I can tell this is the same impl as AndroidBrowserDB, except for
> s/HISTORY/BOOKMARK_COLUMNS. Add getters for those and move it there.

The queries just happen to be similar right now. I'm almost sure they'll become more different as part of a fix for bug 704977. I'd prefer to keep them separate.
 
> I'm assuming this can be done for other code as well, please file a code
> clean-up follow-up bug

I think we wouldn't gain much as all queries (except for top sites and filter) are pretty simple anyway. And, as I said, the queries will end up being less similar to each other as we improve local DB schema for our needs.

Comment 17

[Lucas Rocha (:lucasr)]

Pushed: http://hg.mozilla.org/integration/mozilla-inbound/rev/4c09a651bcc1

Comment 18

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/4c09a651bcc1

Comment 19

[Lucas Rocha (:lucasr)]

Comment on attachment 588441 [details] [diff] [review]
Only load necessary cols on awesomescreen filter and about:home queries

Improves awesomebar performance, especially on devices with slow filesystems. Patch only rearranges code to only load necessary cols from DB on top sites and awesome screen filtering query. Mobile-only.

Comment 20

[Alex Keybl [:akeybl]]

Comment on attachment 588441 [details] [diff] [review]
Only load necessary cols on awesomescreen filter and about:home queries

[Triage Comment]
Mobile only - approved for Aurora.

Comment 21

[Brad Lassey [:blassey] (use needinfo?)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/d1b26813ca3f

Comment 22

[Brad Lassey [:blassey] (use needinfo?)]

actually, only the logging patch landed, unmarking fixed for status-firefox11

Comment 23

[Matt Brubeck (:mbrubeck)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/4708e808a27d

Comment 24

[Catalin Suciu [:csuciu]]

I cannot reproduce this issue on Nightly 13.0a1 (2012-02-01)
                                 Aurora  11.0a2 (2012-02-01)
Device: Nexus S Android 2.3.6

Verifying.