723165 - Telemetry for time needed to show the Bookmarks toolbar

Status: RESOLVED FIXED

(Toolkit :: Places, defect)

Description

[Marco Bonardo [:mak]]

While we don't enable the toolbar by default, a lot of users have it enabled, and it does increase startup time perception.

Comment 1

[Marco Bonardo [:mak]]

Attachment: patch v1.0

I tried to make a test, but it would either be fragile (if another test shows the toolbar before it will fail) or more complicated than I'd like (the test should recreate another toolbar with all the special children like dropIndicator, chevron, ... just to emulate the real one).

Comment 2

[Dietrich Ayala (:dietrich)]

Comment on attachment 594715 [details] [diff] [review]
patch v1.0

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

::: browser/components/places/content/browserPlacesViews.js
@@ +809,4 @@
>  };
>  
>  function PlacesToolbar(aPlace) {
> +  let startTime = Date.now();

new Date();

also, is this executed only at startup, or every time the toolbar is initialized?

and does that matter? do we want to measure only the startup cost of toolbar display?

@@ +839,5 @@
>  
>    PlacesViewBase.call(this, aPlace);
> +
> +  Services.telemetry.getHistogramById("PLACES_TOOLBAR_INIT_TIME_MS")
> +                    .add(Date.now() - startTime);

ditto.

::: toolkit/components/telemetry/TelemetryHistograms.h
@@ +289,4 @@
>  HISTOGRAM(PLACES_AUTOCOMPLETE_1ST_RESULT_TIME_MS, 50, 500, 10, EXPONENTIAL, "PLACES: Time for first autocomplete result if > 50ms (ms)")
>  HISTOGRAM(PLACES_IDLE_FRECENCY_DECAY_TIME_MS, 50, 10000, 10, EXPONENTIAL, "PLACES: Time to decay all frecencies values on idle (ms)")
>  HISTOGRAM(PLACES_IDLE_MAINTENANCE_TIME_MS, 1000, 30000, 10, EXPONENTIAL, "PLACES: Time to execute maintenance tasks on idle (ms)")
> +HISTOGRAM(PLACES_TOOLBAR_INIT_TIME_MS, 50, 5000, 10, EXPONENTIAL, "PLACES: Time to initialize the bookmarks toolbar view (ms)")

this should be in the firefox section, and prefixed with FX_ instead of PLACES_ probably.

Comment 3

[Marco Bonardo [:mak]]

(In reply to Dietrich Ayala (:dietrich) from comment #2)
> >  function PlacesToolbar(aPlace) {
> > +  let startTime = Date.now();
> 
> new Date();

is it more efficient?

> also, is this executed only at startup, or every time the toolbar is
> initialized?
> 
> and does that matter? do we want to measure only the startup cost of toolbar
> display?

Every time, but I don't think the difference matters here, we want to know how expensive is to load the toolbar on the ui thread, so any counting is fine.

> ::: toolkit/components/telemetry/TelemetryHistograms.h
> > +HISTOGRAM(PLACES_TOOLBAR_INIT_TIME_MS, 50, 5000, 10, EXPONENTIAL, "PLACES: Time to initialize the bookmarks toolbar view (ms)")
> 
> this should be in the firefox section, and prefixed with FX_ instead of
> PLACES_ probably.

Well, most of the time is clearly spent in Places, than in the frontend code, but could make sense to split frontend from backend.

Comment 4

[Dietrich Ayala (:dietrich)]

(In reply to Marco Bonardo [:mak] from comment #3)
> > new Date();
> 
> is it more efficient?

Brendan told Taras who told me that it is. So, maybe :)

> > this should be in the firefox section, and prefixed with FX_ instead of
> > PLACES_ probably.
> 
> Well, most of the time is clearly spent in Places, than in the frontend
> code, but could make sense to split frontend from backend.

Since it's directly related to UI, should be in FX_ - because it also counts a lot of things like expensive DOM building operations and reflows and other stuff caused by the toolbar.

If was an abstract measurement of Places query speed, then should be in PLACES_ I think. Also, it's /browser code, so leaving it in the PLACES_ section would result in histogram of empty data for non-Firefox apps.

Comment 5

[Marco Bonardo [:mak]]

Attachment: patch v1.1

I kept Date.now() for laziness :) While there is evidence new Date() is faster than Date.now(), diffing later is slower. In the end the difference is negligible for this kind of code.

Comment 6

[Dietrich Ayala (:dietrich)]

Comment on attachment 595030 [details] [diff] [review]
patch v1.1

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

r=me with these changes.

::: toolkit/components/telemetry/TelemetryHistograms.h
@@ +323,4 @@
>  HISTOGRAM_BOOLEAN(FX_KEYWORD_URL_USERSET, "Firefox: keyword.URL has a user-set value")
>  HISTOGRAM(FX_IDENTITY_POPUP_OPEN_MS, 1, 1000, 10, EXPONENTIAL, "Firefox: Time taken by the identity popup to open in milliseconds")
>  HISTOGRAM(FX_APP_MENU_OPEN_MS, 1, 1000, 10, EXPONENTIAL, "Firefox: Time taken by the app-menu opening in milliseconds")
> +HISTOGRAM(FX_BOOKMARKS_TOOLBAR_INIT_TIME_MS, 50, 5000, 10, EXPONENTIAL, "Firefox: Time to initialize the bookmarks toolbar view (ms)")

why starting at 50ms? won't that screen out the number of non-problematic toolbar loads?

also, could remove TIME_ from the histogram name since the MS makes it redundant.

Comment 7

[Marco Bonardo [:mak]]

(In reply to Dietrich Ayala (:dietrich) from comment #6)
> why starting at 50ms? won't that screen out the number of non-problematic
> toolbar loads?

All the minor times will just be coalesced in the <50 bucket, if we consider 50ms a Snappy time, as we usually did, anything below 50ms is not important to distinguish.

> also, could remove TIME_ from the histogram name since the MS makes it
> redundant.

Sure, I kept TIME cause was coherent with the other PLACES_ measures, but now that it's in FX_ doesn't matter.

Comment 8

[Marco Bonardo [:mak]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/d6e811c2b127

Comment 9

[Ed Morley [:emorley]]

https://hg.mozilla.org/mozilla-central/rev/d6e811c2b127