Closed Bug 1369604 Opened 7 years ago Closed 7 years ago

Activity Stream Highlights query is very slow

Categories

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

enhancement

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: Grisha, Assigned: mcomella)

References

Details

(Whiteboard: [results comment 70] [MobileAS] 1.26 1.27)

Attachments

(10 files)

2.96 KB, patch
Details | Diff | Splinter Review
2.92 KB, patch
Details | Diff | Splinter Review
59 bytes, text/x-review-board-request
liuche
: review+
Details
59 bytes, text/x-review-board-request
liuche
: review+
Details
59 bytes, text/x-review-board-request
liuche
: review+
Details
59 bytes, text/x-review-board-request
liuche
: review+
Details
6.70 MB, application/x-gzip
Details
4.04 KB, patch
Details | Diff | Splinter Review
59 bytes, text/x-review-board-request
mcomella
: review+
Details
59 bytes, text/x-review-board-request
mcomella
: review+
Details
Priority: -- → P2
Whiteboard: [MobileAS]
Rank: 1
Whiteboard: [MobileAS] → [MobileAS] 1.26
Not my area of expertise but I'll take it as a learning opportunity. :)
Assignee: nobody → michael.l.comella
Iteration: --- → 1.26
Priority: P2 → P1
I tried using the method profiler to understand which calls were taking the most time but I can't seem to find the results – I think it could be that the thread that executes the DB query runs in an async task & clears itself up before I stop profiling so it can't retrieve the data associated with that thread.

Instead, I added some log statements between the various DB operations to get a sense of what was taking the most time to execute (see the attached patch). The phases are:

1) Read from disk:
> final Cursor candidatesCursor = BrowserDB.from(context)
>                 .getHighlightCandidates(context.getContentResolver(), candidatesLimit);

2) Enable updates from loader (via enableContentUpdates()): 
> context.getContentResolver()
>                 .registerContentObserver(BrowserContract.AUTHORITY_URI, true, observer);

3) Rank highlights with the CPU:
> final List<Highlight> highlights = HighlightsRanking.rank(candidatesCursor, highlightsLimit);

---

Unfortunately, I only have a small profile to test with (542 bookmarks, 209 history items [1]) so I question the accuracy of these numbers, but I get the following results on a few test runs on my N5, which is a pretty fast device (values in millis):

dbQuery: 30
contentUpdates: 4
rankTime: 49

dbQuery: 44
contentUpdates: 3
rankTime: 51

dbQuery: 26
contentUpdates: 1
rankTime: 34

dbQuery: 26
contentUpdates: 4
rankTime: 44

With the current dataset size, rankTime (3) often takes longer than reading from the disk (1). However, the number of items returning from the disk should be a small constant (10) so it's more likely the dbQuery will significantly grow in size as more items are adding rather than rankTime scaling with it. But that being said, ranking seems kind of inefficient (we do a lot of functional operations like map, filter, & sort but do so over the list many times).

I think we can rule out (2) content updates as a significant contributor to run time, however.

[1]: discovered by searching bookmarks/history with "http", selecting all, and seeing selection count
> However, the number of items returning from the disk should be a small constant (10)

Correction: this number is 500. My device has 170 items returned from (1) so it'll continue to decrease in performance until we hit 500 items. Note that any filtering we might do in rank could decrease this count and increase the performance of other rank operations.
I found the programmatic tracing (note my trace file is 60 MB so the buffer needs to be larger than that). With my small profile, the following methods have the following "Inclusive CPU time" for Wall Clock Time:
- 0.67% | LocalBrowserDB.getHighlightCandidates (read the disk)
- 99.25% | HighlightsRanking.rank (process in-memory)
- 77.12% | HighlightsRanking.extractFeatures
- 14.6% | HighlightsRanking.scoreEntries

While I don't have a big profile, which could make a big impact on the query time, it's pretty questionable how long this processing takes so I'm going to dig in there.

In particular, we pull everything out of the Cursor and construct new objects for them, which:
- duplicates non-reference types memory
- filters and dump from 500 items -> 10 items, which could additionally impact the garbage collector.

I wonder if accessing the memory in the Cursor is more efficient than putting it into new objects too.
Some other numbers of note:
- getColumnIndexOrThrow: 25%. Under the hood, it calls:
 - HashMap.get: 20.3% (plus other invocations)
 - String.equals: 16.2% (plus other invocations)
  - String.charAt: 13.7%
- HashMap.put: 9.7% (we use this for features.put)
- Uri.getPathSegments: 10.1%

getColumnIndex should be easy to fix - we get the indices once and then use those values in every other get call.

---

Also, inside HighlightsRanking.scoreEntries (14.6%):
- getFiltered: 7.3%
- getFeatureValue: 5.1%
- adjustScore: 1.7%
- decay: 4.3%
I made a patch where I reduced the number of `getColumnIndexOrThrow` calls to 9 (from 1.6k) and:
- HighlightsRanking.extractFeatures: 77.1% -> 40.8%, 14.6k ms -> 7.1k ms

Profiling is not perfect but this seems like a solid improvement.

Now the majority of runtime for extractFeatures is taken up by JSONObject.init inside Metadata.init, which may be hard to improve. We could also dig into the Uri calls, however.
This review request is only the first patch but, if we like, we can land it separately to see how it affects performance.
Comment on attachment 8889695 [details]
Bug 1369604: Use HighlightCandidateCursorIndices to cache.

https://reviewboard.mozilla.org/r/160758/#review167092

This looks sane to me, good find on the optimization. Let's get it into nightly and see if it improves loading!

Does this break any tests?
Attachment #8889695 - Flags: review?(liuche) → review+
(In reply to Michael Comella (:mcomella) from comment #2)
> Unfortunately, I only have a small profile to test with (542 bookmarks, 209
> history items [1]) so I question the accuracy of these numbers, but I get
> the following results on a few test runs on my N5, which is a pretty fast
> device (values in millis):

As you know, this is a pretty skewed profile for Sync users and for established single-device users. You should try timing this query with 10,000 history items and 100,000 history visits, distributed evenly over, say, 12 months.

With 200 history items the entire database will fit easily in memory, and loop joins and full table scans will be effectively free.

That said, if we're spending 50msec chewing on such a small result set, your other improvements are still worthwhile!
(In reply to Richard Newman [:rnewman] from comment #10)
> As you know, this is a pretty skewed profile for Sync users and for
> established single-device users.

True - I should have tried harder to find a more realistic profile. Chenxia recommended I use my personal Sync profile (I don't know why I didn't think of that...).

That being said, top sites/highlights only returns local search results so this will still be skewed from that perspective.

---

Trying with my profile (with ~3 local visits) on my aging GS5 with the first patch I wrote, it still seems our post-processing is taking up the most resources:
- LocalBrowserDB.getHighlightCandidates: 2.64% (I wonder if this is accurate because it makes a call to BrowserProvider through the Content Provider)
- HighlightsRanking.rank: 97.07%

Notes:
- There are 500 invocations of various functions so it seems we're post processing the limit of 500 items, the worst possible case for post-processing.
- If we only show local visits in top sites/highlights, shouldn't we filter this at the DB level instead? (what else could we filter at the DB level?)
- Thought: in the worst case, we could parallelize the processing of the lists
(In reply to Michael Comella (:mcomella) from comment #11)

> - LocalBrowserDB.getHighlightCandidates: 2.64% (I wonder if this is accurate
> because it makes a call to BrowserProvider through the Content Provider)

If you're doing end-to-end timing with one of the microsecond timing functions, then it should be accurate -- you want wall clock, right?

> - If we only show local visits in top sites/highlights, shouldn't we filter
> this at the DB level instead? (what else could we filter at the DB level?)

We mark visits with is_local, yeah. But I'd be surprised if we only wanted to revisit pages visited on the device, or only wanted to rank based on local visits.
(In reply to Chenxia Liu [:liuche] from comment #9)
> Does this break any tests?

I just checked locally - no, it does not. That being said, there is no coverage for these changes.
(In reply to Richard Newman [:rnewman] from comment #12)
> If you're doing end-to-end timing with one of the microsecond timing
> functions, then it should be accurate -- you want wall clock, right?

I'm using Debug.startMethodTracing(...), which is end-to-end timing as I understand it. I am also using wall clock.

> > - If we only show local visits in top sites/highlights, shouldn't we filter
> > this at the DB level instead? (what else could we filter at the DB level?)
> 
> We mark visits with is_local, yeah. But I'd be surprised if we only wanted
> to revisit pages visited on the device, or only wanted to rank based on
> local visits.

I'm not privvy to the latest top sites/highlight algos but in the past, I remember we waited local visits quite heavily because browsing habits are different on mobile and prior to that change, when you started syncing, the sites became undesirable because you would never visit them on mobile (e.g. gmail, facebook, where you have the apps). fwiw, I think Grisha made this change.

Anecdotally, In my local build, I synced my personal sync profile, visited three sites locally, and I only see local visits and defaults in top sites/highlights.
I know that iOS uses synced data in its Highlights, and Farhan has mentioned that nchapman has voiced the concerns that iOS highlights are not as good as Android ones. Obviously we could do a better job of using synced data, but currently that's not included in any platform's algorithms.
Further details in my commit message but for the latest changeset, here's a quote of the perf improvements on my skewed profile:

For perf, my changes affected multiple methods so the percentages are no longer
reliable but I can verify absolute runtime changes. I ran three tests, the best
of which showed an overall 33% runtime compared to the previous changeset and
the other two profiles showed a 66% overall runtime. In particular, for the
middle run, the changes for affected methods go from X microseconds to Y
microseconds:
- Features.get: 3,554,796 -> 322,145
- secondaryHash: 3,165,785 -> 35,253
- HighlightsRanking.normalize: 6,578,481 -> 1,734,078
- HighlightsRanking.scoreEntries: 3,017,272 -> 448,300

---

Unfortunately, I didn't see an improvement on the absolute runtimes when profiling on my GS5 (with my natural profile) but, anecdotally, it seems to be marginally faster when I look at the device myself.

We should probably land these changes together, see how it performs in the wild, and then decide if we want to reinvest in this effort (though I'll look for some quick wins before I move on).
I replaced JSON parsing for all highlight candidates (at most, 500) with a
faster estimation using regex: we only use the full JSON parsing to get the
perfect values for the items to be shown (~5).

One caveat of this change: JSON parsing will be moved to the main thread when
the getMetadataSlow is lazily-loaded.

Disclaimer: my device seems to be running faster than yesterday so profiling
may not be consistent but here are the profiling results:
- HighlightsRanking.extractFeatures: 78.1% -> 54.5%
- Highlight.<init>: 26.5% -> 14.5%
- JSONObject.<init>: 11.4% -> rm'd
- initFast*: (replaced JSONObject.<init> & friends) -> 4.2%

With ^ the disclaimer in mind, runtime decreased from 12.6s to 5.3s (this is
slower due to profiling).

Review commit: https://reviewboard.mozilla.org/r/162650/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/162650/
Attachment #8891534 - Flags: review?(liuche)
Attachment #8891535 - Flags: review?(liuche)
Attached file trace.tar.gz
Here's the final trace I took from my skewed profile - use the ModernAsyncTask #3 thread. Some potential remaining areas to address:

1) Optimize Uri accesses in HighlightsRanking.extractFeatures:
  - Uri$StringUrl.getPathSegments: 14.4%
  - Uri$AbstractHierarchicalUrl.getHost: 8.4%
  - Uri.getQueryParameterNames: 3.9%
We could use some estimation methods:
  - getPathSegments is used to get the size: could we find the number of '/'?
  - getQueryParameterNames is used to get the size: could we find the number of '='?
  - getHost: could we replace this with a regex?

2) Parallelize HighlighsRanking.extractFeatures: 54.% of runtime. This constructs all of our objects we later iterate over and can be done completely in parallel.
Comment on attachment 8891135 [details]
Bug 1369604: Replace features HashMap with indexing into an array.

https://reviewboard.mozilla.org/r/162320/#review168038

Looks good, switching from hashmap to array - this lets us avoid calculating the hash for each hash get, which I guess because we call it millions of times does add up.

::: mobile/android/base/java/org/mozilla/gecko/activitystream/ranking/HighlightCandidate.java:31
(Diff revision 2)
> +    @IntDef({FEATURE_AGE_IN_DAYS, FEATURE_BOOKMARK_AGE_IN_MILLISECONDS, FEATURE_DESCRIPTION_LENGTH,
> +            FEATURE_DOMAIN_FREQUENCY, FEATURE_IMAGE_COUNT, FEATURE_IMAGE_SIZE, FEATURE_PATH_LENGTH,
> +            FEATURE_QUERY_LENGTH, FEATURE_VISITS_COUNT})
> +    /* package-private */ @interface FeatureName {}
> +
> +    // IF YOU ADD A FIELD, INCREMENT `FEATURE_COUNT`!

Nit: add a comment here explaining why (that these ints are being used for perf improvements) and make the comment closer to the FEATURE_COUNT var.

::: mobile/android/base/java/org/mozilla/gecko/activitystream/ranking/HighlightsRanking.java:59
(Diff revision 2)
>      static {
> +        // In initialization, we put all data into a single data structure so we don't have to repeat
> +        // ourselves: this data structure is copied into two other data structures upon completion.
> +        //
> +        // To add a weight, just add it to tmpWeights as seen below.
>          // TODO: Needs confirmation from the desktop team that this is the correct weight mapping (Bug 1336037)

Nit: remove this comment too, this bug was WONTFIX-ed
https://bugzilla.mozilla.org/show_bug.cgi?id=1336037
Attachment #8891135 - Flags: review?(liuche) → review+
I created this patch to optimize our Uri accesses but it had negligible results: Uri.getPathPart takes up a lot of runtime in both cases (via .getPath?) so I think, after getting the path, .getPathSegments is fairly efficient.

We could continue improving this by iterating directly over the url String, instead of parsing it into Android's Uri class, to avoid the runtime overhead of .getPath & friends. Note that these are more likely to estimate a URL's validity, rather than getting it exactly correct.

That being said, the patch series I've created may be good enough for now – let's land it, see how it goes with a real population, and then determine if we should reinvest.
NI self to follow-up with live telemetry numbers after landing.
Flags: needinfo?(michael.l.comella)
Comment on attachment 8891534 [details]
Bug 1369604: Replace Metadata JSON parsing with faster regex matching.

https://reviewboard.mozilla.org/r/162650/#review168042

r+: use regex instead of JSON parsing, and replaced all the old calls to getMetadata.get\* (which parsed JSON) with either getFast\* or getMetadataSlow (for creating the actual highlight).

Clever improvement!

::: mobile/android/base/java/org/mozilla/gecko/activitystream/homepanel/model/Highlight.java:26
(Diff revision 1)
> +
> +    /**
> +     * A pattern matching a json object containing the key "image_url" and extracting the value. afaik, these urls
> +     * are not encoded so it's entirely possible that the url will contain a quote and we will not extract the whole
> +     * url. However, given these are coming from websites providing favicon-like images, it's not likely a quote will
> +     * appear and since these urls are only being used for comparisons, a partial URL may actually have the same

Nit: Add a little more detail on about "comparison"? maybe "(e.g. image equality comparisons between Highlight items)" so that the reason for using fast-image-urls is clearer.

::: mobile/android/base/java/org/mozilla/gecko/activitystream/ranking/HighlightCandidate.java:197
(Diff revision 1)
>      /* package-private */ String getHost() {
>          return host;
>      }
>  
> +    /**
> +     * todo: initilaization only for comparison. See for more details.

finish todo?
Attachment #8891534 - Flags: review?(liuche) → review+
Comment on attachment 8891535 [details]
Bug 1369604: Force lazily-loaded metadata to load on background thread.

https://reviewboard.mozilla.org/r/162658/#review168044

::: mobile/android/base/java/org/mozilla/gecko/activitystream/homepanel/HighlightsLoader.java:67
(Diff revision 1)
>          try {
>              // From now on get notified about content updates and reload data - until loader is reset.
>              enableContentUpdates();
>  
>              final List<Highlight> highlights = HighlightsRanking.rank(candidatesCursor, highlightsLimit);
> +            forceLoadHighlightMetadata(highlights); // force load now that we have a subset of the data.

nit: "short list" instead of "subset"?
Attachment #8891535 - Flags: review?(liuche) → review+
Comment on attachment 8891135 [details]
Bug 1369604: Replace features HashMap with indexing into an array.

https://reviewboard.mozilla.org/r/162320/#review168038

> Nit: add a comment here explaining why (that these ints are being used for perf improvements) and make the comment closer to the FEATURE_COUNT var.

Added the comment, moved FEATURE_COUNT to the top.
Comment on attachment 8891580 [details]
Bug 1369604 - review: rm comment from WONTFIX'd bug.

https://reviewboard.mozilla.org/r/162692/#review168052
Attachment #8891580 - Flags: review?(michael.l.comella) → review+
Comment on attachment 8891581 [details]
Bug 1369604: Add additional comments to Highlights performance changes.

https://reviewboard.mozilla.org/r/162694/#review168054

r=trivial
Attachment #8891581 - Flags: review?(michael.l.comella) → review+
We're sorry, Autoland could not rebase your commits for you automatically. Please manually rebase your commits and try again.

hg error in cmd: hg rebase -s a7c06ed0b3cb -d d394c7b2df1d: rebasing 410428:a7c06ed0b3cb "Bug 1369604: Use HighlightCandidateCursorIndices to cache. r=liuche"
rebasing 410429:b6bd0f7688ee "Bug 1369604: Replace features HashMap with indexing into an array. r=liuche"
rebasing 410430:7d206012f10a "Bug 1369604: Replace Metadata JSON parsing with faster regex matching. r=liuche"
merging mobile/android/base/java/org/mozilla/gecko/activitystream/homepanel/stream/HighlightItem.java
warning: conflicts while merging mobile/android/base/java/org/mozilla/gecko/activitystream/homepanel/stream/HighlightItem.java! (edit, then use 'hg resolve --mark')
unresolved conflicts (see hg resolve, then hg rebase --continue)
Pushed by michael.l.comella@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/9e2a5ef546dd
Use HighlightCandidateCursorIndices to cache. r=liuche
https://hg.mozilla.org/integration/autoland/rev/e226cd5d64b2
Replace features HashMap with indexing into an array. r=liuche
https://hg.mozilla.org/integration/autoland/rev/b33806ccdd9f
Replace Metadata JSON parsing with faster regex matching. r=liuche
https://hg.mozilla.org/integration/autoland/rev/e49ad83bc31b
Force lazily-loaded metadata to load on background thread. r=liuche
https://hg.mozilla.org/integration/autoland/rev/10a40b857266
review: rm comment from WONTFIX'd bug. r=mcomella
https://hg.mozilla.org/integration/autoland/rev/07ae1124989b
Add additional comments to Highlights performance changes. r=mcomella
Seems I forgot to add the file to the *other* build system. Unfortunately, I'm on my personal machine which is too slow to build so I'm going to try landing without rebuilding locally.
Pushed by michael.l.comella@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/371d34adf87a
Use HighlightCandidateCursorIndices to cache. r=liuche
https://hg.mozilla.org/integration/autoland/rev/f23174dcc5e6
Replace features HashMap with indexing into an array. r=liuche
https://hg.mozilla.org/integration/autoland/rev/7cd7e31b61ec
Replace Metadata JSON parsing with faster regex matching. r=liuche
https://hg.mozilla.org/integration/autoland/rev/7232652c0304
Force lazily-loaded metadata to load on background thread. r=liuche
https://hg.mozilla.org/integration/autoland/rev/fb8b790f8f47
review: rm comment from WONTFIX'd bug. r=mcomella
https://hg.mozilla.org/integration/autoland/rev/77abc92bd89c
Add additional comments to Highlights performance changes. r=mcomella
Backed out for Android bustage at testActivityStreamContextMenu.java:297: method fromCursor in class Highlight cannot be applied to given types:

https://hg.mozilla.org/integration/autoland/rev/45f201fe8a9a04031281696a9a25b8d96d636355
https://hg.mozilla.org/integration/autoland/rev/7d2a2ae193821b6f6d21169e2599f274ffef0a3b
https://hg.mozilla.org/integration/autoland/rev/ec0c38721aff0949da7d20fcb9d97fda66aefc00
https://hg.mozilla.org/integration/autoland/rev/995115af8e68b88ee391cc8c366bf6e58bfdc54b
https://hg.mozilla.org/integration/autoland/rev/f9d7a7441707424fa04e652f1c9bde00ba7dc8de
https://hg.mozilla.org/integration/autoland/rev/07120bb80702239ddea3fc465151a81b973830d8

Push with bustage: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=77abc92bd89c3c062124f8bea66efefa08662e1a&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable
Build log: https://treeherder.mozilla.org/logviewer.html#?job_id=119263241&repo=autoland

[task 2017-07-29T15:57:27.939624Z] 15:57:27     INFO -  /home/worker/workspace/build/src/mobile/android/tests/browser/robocop/src/org/mozilla/gecko/tests/testActivityStreamContextMenu.java:297: error: method fromCursor in class Highlight cannot be applied to given types;
[task 2017-07-29T15:57:27.939715Z] 15:57:27     INFO -                  final Highlight highlight = Highlight.fromCursor(cursor);
[task 2017-07-29T15:57:27.939760Z] 15:57:27     INFO -                                                       ^
[task 2017-07-29T15:57:27.939797Z] 15:57:27     INFO -    required: Cursor,HighlightCandidateCursorIndices
[task 2017-07-29T15:57:27.939823Z] 15:57:27     INFO -    found: Cursor
[task 2017-07-29T15:57:27.939861Z] 15:57:27     INFO -    reason: actual and formal argument lists differ in length
Iteration: 1.26 → 1.27
Whiteboard: [MobileAS] 1.26 → [MobileAS] 1.26 1.27
(In reply to Chenxia Liu [:liuche] from comment #9)
> This looks sane to me, good find on the optimization. Let's get it into
> nightly and see if it improves loading!
> 
> Does this break any tests?

Seems I forgot to run the robocop tests.
That's the only AS robocop test and it passes locally so let's try landing again.
Pushed by michael.l.comella@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/2c33020e12d1
Use HighlightCandidateCursorIndices to cache. r=liuche
https://hg.mozilla.org/integration/autoland/rev/fefc5d61b051
Replace features HashMap with indexing into an array. r=liuche
https://hg.mozilla.org/integration/autoland/rev/e755f4ab80fd
Replace Metadata JSON parsing with faster regex matching. r=liuche
https://hg.mozilla.org/integration/autoland/rev/dd051eb3bbf6
Force lazily-loaded metadata to load on background thread. r=liuche
https://hg.mozilla.org/integration/autoland/rev/95ca4a6f8957
review: rm comment from WONTFIX'd bug. r=mcomella
https://hg.mozilla.org/integration/autoland/rev/8227a596f3fd
Add additional comments to Highlights performance changes. r=mcomella
To follow up on my previous "What's next?" comment 22 & comment 24, another thought: moving the data from the Cursor into Java objects takes the most of the time so I wonder if we can do most the ranking in the DB so that we can avoid that step entirely. That being said, it'd probably be less readable for most us less frequent SQL users.
> Looking at the telemetry data, it seems that our highlights is very, very slow. 75th percentile is around one second!

fwiw, before I did my changes, there were already improvements in Highlights query times (for whatever unknown reason): median is 245ms and 75th percentile is 499.45ms.

https://telemetry.mozilla.org/new-pipeline/dist.html#!cumulative=0&end_date=2017-07-31&keys=__none__!__none__!__none__&max_channel_version=nightly%252F56&measure=FENNEC_ACTIVITY_STREAM_HIGHLIGHTS_LOADER_TIME_MS&min_channel_version=nightly%252F52&processType=*&product=Fennec&sanitize=1&sort_keys=submissions&start_date=2017-06-12&table=0&trim=1&use_submission_date=0

My one day of changes looks like it's only marginally faster: 211ms median & 75th percentile is worse at 508ms. Let's wait a few more days to see what has changed.
An idea from Susheel: rather than improving the query time, we could cache the results and update it every few days (though we'll still need to query the DB to get the specific assets for those cached items).

Also, looking Chenxia's phone (Moto X), AS still loads really slowly, top sites included – I speculate the device might have slow disk accesses. I wonder if I should have been profiling a device more like Chenxia's than the ones I had on hand (GS5, N5).
Another note: the query times (e.g. comment 0) represent the time for the database queries (and other background processing) to complete, not the time until the highlights/top sites draw on the screen. In an extreme case, e.g. on Chenxia's phone the queries may complete quickly but it takes a long time to draw to the screen because the main thread is blocked.
(In reply to Michael Comella (:mcomella) from comment #67)
> An idea from Susheel: rather than improving the query time, we could cache
> the results and update it every few days (though we'll still need to query
> the DB to get the specific assets for those cached items).

This is what iOS does, for both top sites and highlights.


> Also, looking Chenxia's phone (Moto X), AS still loads really slowly, top
> sites included – I speculate the device might have slow disk accesses. I
> wonder if I should have been profiling a device more like Chenxia's than the
> ones I had on hand (GS5, N5).

This used to be a real problem with early Samsung Galaxy devices — some of them had disk accesses ten times slower than other phones, thanks to a bad choice of filesystem. There might be simulator options to simulate slow disk access, or perhaps we should invest in shitty phones…
- Pre-landing: 7/1-7/31 [1]
- Post-landing: 8/2-8/6 [2]

Notes:
- The median time improved ~40ms (to 220ms)
- The 25th percentile improved ~35ms (to 91ms)
- The 75th percentile improved ~60ms (to 464ms)
- The 95th percentile improved ~140ms (to 1.29k ms)

Considering I just slowed down the top sites query by 20ms (to 60.2ms median, bug 1386052), these gains don't seem that significant. :P

Caveat: I don't know that 5 days of data (post-landing) is statistically significant.

That being said, I think we should retriage future improvements so I filed a follow-up: bug 1388187. This bug is an optimization that I don't think it'll make a huge UX difference. As far as I know, once once the new design is implemented, Highlights is below the fold *and* below Pocket suggestions, which gets much more engagement on desktop.

[1]: https://telemetry.mozilla.org/new-pipeline/dist.html#!cumulative=0&end_date=2017-07-31&keys=__none__!__none__!__none__&max_channel_version=nightly%252F56&measure=FENNEC_ACTIVITY_STREAM_HIGHLIGHTS_LOADER_TIME_MS&min_channel_version=nightly%252F52&processType=*&product=Fennec&sanitize=1&sort_keys=submissions&start_date=2017-07-01&table=0&trim=1&use_submission_date=0
[2]: https://telemetry.mozilla.org/new-pipeline/dist.html#!cumulative=0&end_date=2017-08-06&keys=__none__!__none__!__none__&max_channel_version=nightly%252F57&measure=FENNEC_ACTIVITY_STREAM_HIGHLIGHTS_LOADER_TIME_MS&min_channel_version=null&processType=*&product=Fennec&sanitize=1&sort_keys=submissions&start_date=2017-08-02&table=0&trim=1&use_submission_date=0
Status: NEW → RESOLVED
Closed: 7 years ago
Flags: needinfo?(michael.l.comella)
Keywords: leave-open
Resolution: --- → FIXED
Whiteboard: [MobileAS] 1.26 1.27 → [results comment 70] [MobileAS] 1.26 1.27
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.