753127 - Required: telemetry for tab switching speed

Status: RESOLVED FIXED

(Firefox :: Tabbed Browser, defect)

Description

[(dormant account)]

Would've been nice to have this for bug 743877, but we definitely need this to track future progress.

Comment 1

[Bellindira Castillo [:bellindira]]

Attachment: Added telemetry for tab switching speed

Comment 2

[Dão Gottwald [:dao]]

Comment on attachment 658680 [details] [diff] [review]
Added telemetry for tab switching speed

>+ * Widget tabbox.xml tab switching speed telemetry.

This comment seems bogus. You're not touching tabbox.xml in this patch.

>+HISTOGRAM(TAB_SWITCHING_SPEED_MS, 1, 50000000, 10, EXPONENTIAL, "Tab switching speed on ms")

move this to the Firefox-specific section and prefix the histogram name with FX_

>+          let telemetrySwitchStart = new Date();
>+
>           this.parentNode._selectNewTab(this);
> 
>           var isTabFocused = false;
>           try {
>             isTabFocused = (document.commandDispatcher.focusedElement == this);
>           } catch (e) {}
> 
>           // Set '-moz-user-focus' to 'ignore' so that PostHandleEvent() can't
>           // focus the tab; we only want tabs to be focusable by the mouse if
>           // they are already focused. After a short timeout we'll reset
>           // '-moz-user-focus' so that tabs can be focused by keyboard again.
>           if (!isTabFocused) {
>             this.setAttribute("ignorefocus", "true");
>             setTimeout(function (tab) tab.removeAttribute("ignorefocus"), 0, this);
>           }
>+
>+          let tmp = {};
>+          Components.utils.import("resource://gre/modules/Services.jsm", tmp);
>+          let Services = tmp.Services;
>+          Services.telemetry.getHistogramById("TAB_SWITCHING_SPEED_MS")
>+            .add(new Date() - telemetrySwitchStart);

use TelemetryStopwatch (already available in tabbrowser.xml)

Are you sure you're measuring the right thing here, i.e. that the time we care about is exclusively spent in _selectNewTab?

Comment 3

[Bellindira Castillo [:bellindira]]

Attachment: Patch v2: Added telemetry for tab switching speed

Fixes:
- Fixed the comment
- Moved histogram definition on Firefox specific 
- Use TelemetryStopwatch
- Measuring only _selectNewTab

Comment 4

[Dão Gottwald [:dao]]

(In reply to Dão Gottwald [:dao] from comment #2)
> Are you sure you're measuring the right thing here, i.e. that the time we
> care about is exclusively spent in _selectNewTab?

(In reply to Bellindira Castillo [:bellindira] from comment #3)
> - Measuring only _selectNewTab

This doesn't answer my question.

Comment 5

[Dão Gottwald [:dao]]

(In reply to Dão Gottwald [:dao] from comment #2)
> Comment on attachment 658680 [details] [diff] [review]
> Added telemetry for tab switching speed
> 
> >+ * Widget tabbox.xml tab switching speed telemetry.
> 
> This comment seems bogus. You're not touching tabbox.xml in this patch.

Wait, you *are* implementing this in tabbox.xml, but you shouldn't be. We're only interested in the tabbed browser here.

Comment 6

[(dormant account)]

Comment on attachment 658728 [details] [diff] [review]
Patch v2: Added telemetry for tab switching speed

--- a/toolkit/components/telemetry/TelemetryHistograms.h
+++ b/toolkit/components/telemetry/TelemetryHistograms.h

Update your tree. TelemetryHistograms.h became Histograms.json

Comment 7

[Bellindira Castillo [:bellindira]]

(In reply to Dão Gottwald [:dao] from comment #4)
> (In reply to Dão Gottwald [:dao] from comment #2)
> > Are you sure you're measuring the right thing here, i.e. that the time we
> > care about is exclusively spent in _selectNewTab?
> 
> (In reply to Bellindira Castillo [:bellindira] from comment #3)
> > - Measuring only _selectNewTab
> 
> This doesn't answer my question.

There are different events to switch tabs as mousedown and keypress combinations. I think that the time we care is the time spent on the method _selectNewTab (tabbox.xml) and on the setter of the selectedTab property (tabbrowser.xml). However, I am not sure if it is exactly the measure that you want because there are other things that happen between user action and _selectNewTab (or setting selectedTab). E.g. User press (CMD + ALT + VK_LEFT), so Firefox should switch the selected tab to the one on the left, so the code first check if there are more than one tab, and if true it should select it. Then, it is not measuring the time spent on validations, only the time on switching to a valid tab. But if we include the validations on the measurement and then we realized that it cannot switch to another tab, we would be adding an invalid measurement.
Please let me know what do you think about it.

> Wait, you *are* implementing this in tabbox.xml, but you shouldn't be. We're only > interested in the tabbed browser here.

Also, as tabbed browser extends from tabbox.xml, the only way I can think to measure the tab switching speed (_selectNewTab) is to add code directly on tabbox.xml. And to make sure that we only record tabbed browser data, we could check that the element id is tabbrowser-tabs.

Comment 8

[Dão Gottwald [:dao]]

(In reply to Bellindira Castillo [:bellindira] from comment #7)
> There are different events to switch tabs as mousedown and keypress
> combinations. I think that the time we care is the time spent on the method
> _selectNewTab (tabbox.xml) and on the setter of the selectedTab property
> (tabbrowser.xml).

Does this include the time it takes to render the newly selected browser?

> Also, as tabbed browser extends from tabbox.xml, the only way I can think to
> measure the tab switching speed (_selectNewTab) is to add code directly on
> tabbox.xml. And to make sure that we only record tabbed browser data, we
> could check that the element id is tabbrowser-tabs.

This still seems somewhat unreliable. I imagine add-ons and other applications could have copied part of our tabbed browser code, including the <tabs> element's id.

Comment 9

[Bellindira Castillo [:bellindira]]

(In reply to Dão Gottwald [:dao] from comment #8)
> (In reply to Bellindira Castillo [:bellindira] from comment #7)
> > There are different events to switch tabs as mousedown and keypress
> > combinations. I think that the time we care is the time spent on the method
> > _selectNewTab (tabbox.xml) and on the setter of the selectedTab property
> > (tabbrowser.xml).
> 
> Does this include the time it takes to render the newly selected browser?

No, it doesn't. It only includes the time to switch to a different tab of the one selected.

> > Also, as tabbed browser extends from tabbox.xml, the only way I can think to
> > measure the tab switching speed (_selectNewTab) is to add code directly on
> > tabbox.xml. And to make sure that we only record tabbed browser data, we
> > could check that the element id is tabbrowser-tabs.
> 
> This still seems somewhat unreliable. I imagine add-ons and other
> applications could have copied part of our tabbed browser code, including
> the <tabs> element's id.

Yes, but I think this could also happen if this code would be in tabbrowser.xml instead of tabbox.xml. A simple solution could be to add an additional check, as identify if the parentNode id of the element is equal to 'TabsToolbar' (which refers to Fx browser). If you have other ideas, please let me know!

Comment 10

[:Gavin Sharp [email: [e-mail]]]

To start, getting coverage just for time spent under onUpdateCurrentBrowser would be pretty valuable.

Comment 11

[:Gavin Sharp [email: [e-mail]]]

Sorry, I meant updateCurrentBrowser(). But we definitely do also want more realistic overall tab switching telemetry, so maybe we can split that out into another bug.

Comment 12

[Bellindira Castillo [:bellindira]]

(In reply to :Gavin Sharp (use [e-mail] for email) from comment #11)
> Sorry, I meant updateCurrentBrowser(). But we definitely do also want more
> realistic overall tab switching telemetry, so maybe we can split that out
> into another bug.

Yes, I think it is better to split into another bug however I can also add it here if you wish.

Comment 13

[Bellindira Castillo [:bellindira]]

Attachment: Patch v3: Added telemetry for tab switching speed

Here is a new version of the patch. I added telemetry directly to _selectNewTab (tabbox.xml) and to the setter of the selectedTab property(tabbrowser.xml), please let me know if it is ok or if you have other suggestions/fixes for this.

Comment 14

[Dão Gottwald [:dao]]

Comment on attachment 660268 [details] [diff] [review]
Patch v3: Added telemetry for tab switching speed

(In reply to Bellindira Castillo [:bellindira] from comment #12)
> (In reply to :Gavin Sharp (use [e-mail] for email) from comment
> #11)
> > Sorry, I meant updateCurrentBrowser(). But we definitely do also want more
> > realistic overall tab switching telemetry, so maybe we can split that out
> > into another bug.
> 
> Yes, I think it is better to split into another bug however I can also add
> it here if you wish.

Please file a new bug. We need to think more about how this would be implemented best.

In tabbrowser.xml, measure the time in updateCurrentBrowser rather than in then selectedTab setter. Note that TelemetryStopwatch is already available there, you don't need to import it.

Comment 15

[Bellindira Castillo [:bellindira]]

(In reply to Dão Gottwald [:dao] from comment #14)
> Comment on attachment 660268 [details] [diff] [review]
> Patch v3: Added telemetry for tab switching speed
> 
> (In reply to Bellindira Castillo [:bellindira] from comment #12)
> > (In reply to :Gavin Sharp (use [e-mail] for email) from comment
> > #11)
> > > Sorry, I meant updateCurrentBrowser(). But we definitely do also want more
> > > realistic overall tab switching telemetry, so maybe we can split that out
> > > into another bug.
> > 
> > Yes, I think it is better to split into another bug however I can also add
> > it here if you wish.
> 
> Please file a new bug. We need to think more about how this would be
> implemented best.

Here is the link of the new bug:
https://bugzilla.mozilla.org/show_bug.cgi?id=790752

> In tabbrowser.xml, measure the time in updateCurrentBrowser rather than in
> then selectedTab setter. Note that TelemetryStopwatch is already available
> there, you don't need to import it.

Let me get this, updateCurrentBrowser is called when onselect event (from tabbox inside tabbrowser) is triggered. 
So, I just want to know what would you like to measure exactly? If it is the time to process the updateCurrentBrowser method, the new bug I just filed makes no sense and it should be cancelled. Also, I should remove the telemetry code on tabbox.xml.

I mean, when an user selects a tab what happens is 
1) __selectNewTab (tabbox.xml)
or 
2) selectedTab property (tabbrowser.xml)

and both trigger the onselect event which executes updateCurrentBrowser (and this method renders the newly selected browser).

Then, it seems that the measurement you wanted is the speed time to render the new selected browser (updateCurrentBrowser) and no the telemetry of _selectNewTab or selectedTab. Is it right?

Comment 17

[:Gavin Sharp [email: [e-mail]]]

Let's do this:
- Add some simple telemetry in this bug for time spent under updateCurrentBrowser (just within that function)
- Use the followup you filed (bug 790752) to investigate more comprehensive measures of tab switching speed that include painting, event handler responsiveness, etc.

Comment 18

[Bellindira Castillo [:bellindira]]

Attachment: Patch v4. Added telemetry for time spent under updateCurrentBrowser

Comment 19

[:Gavin Sharp [email: [e-mail]]]

We should probably use a more specific name for the probe (FX_TAB_SWITCH_UPDATE_MS?), and make the probe comment more specific as well e.g. "time in ms spent updating UI in response to a tab switch".

Comment 20

[Dão Gottwald [:dao]]

Comment on attachment 661399 [details] [diff] [review]
Patch v4. Added telemetry for time spent under updateCurrentBrowser

>       <method name="updateCurrentBrowser">
>         <parameter name="aForceUpdate"/>
>         <body>
>           <![CDATA[
>+            TelemetryStopwatch.start("FX_TAB_SWITCHING_SPEED_MS");
>             var newBrowser = this.getBrowserAtIndex(this.tabContainer.selectedIndex);
>             if (this.mCurrentBrowser == newBrowser && !aForceUpdate)
>               return;

You shouldn't start the stopwatch if the new browser was already selected. (Not even if aForceUpdate is true, I think.)

See also Gavin's comment.

Comment 21

[Andres Hernandez [:andreshm]]

Attachment: Patch v5

Updated patch. 

I continue with this bug, since Bellindira is currently on vacations.

Comment 22

[Dão Gottwald [:dao]]

Comment on attachment 663191 [details] [diff] [review]
Patch v5

>       <method name="updateCurrentBrowser">
>         <parameter name="aForceUpdate"/>
>         <body>
>           <![CDATA[
>             var newBrowser = this.getBrowserAtIndex(this.tabContainer.selectedIndex);
>             if (this.mCurrentBrowser == newBrowser && !aForceUpdate)
>               return;
> 
>+            if (!aForceUpdate) {
>+              TelemetryStopwatch.start("FX_TAB_SWITCH_UPDATE_MS");
>+            }
>             var oldTab = this.mCurrentTab;

nit: remove braces as per local style and insert a blank line before |var oldTab...|.

>                 let focusFlags = fm.FLAG_NOSCROLL;
>                 if (newFocusedElement &&
>                     (newFocusedElement instanceof HTMLAnchorElement ||
>                      newFocusedElement.getAttributeNS("http://www.w3.org/1999/xlink", "type") == "simple"))
>                   focusFlags |= fm.FLAG_SHOWRING;
>                 fm.setFocus(newBrowser, focusFlags);
>               } while (false);
>             }
>+            if (!aForceUpdate) {
>+              TelemetryStopwatch.finish("FX_TAB_SWITCH_UPDATE_MS");
>+            }

ditto (with blank line before the added lines)

>+  "FX_TAB_SWITCH_UPDATE_MS": {
>+    "kind": "exponential",
>+    "high": "100000",
>+    "n_buckets": 10,
>+    "description": "Firefox: Time in ms spent updating UI in response to a tab switch."
>+  },

100000 seems somewhat excessive for this. I'm not sure whether and how this matters.

Comment 23

[Nathan Froyd [:froydnj]]

(In reply to Dão Gottwald [:dao] from comment #22)
> >+  "FX_TAB_SWITCH_UPDATE_MS": {
> >+    "kind": "exponential",
> >+    "high": "100000",
> >+    "n_buckets": 10,
> >+    "description": "Firefox: Time in ms spent updating UI in response to a tab switch."
> >+  },
> 
> 100000 seems somewhat excessive for this. I'm not sure whether and how this
> matters.

I wouldn't expect tab switching to take up to 100 seconds (!).  You should probably reduce the high end and look at this histogram in about:telemetry to make sure the distribution of buckets makes sense for what you're measuring before committing the patch.  I suspect a high of 1000 with ~20 buckets makes much more sense, even if that's not completely optimal either.

Comment 24

[Andres Hernandez [:andreshm]]

Attachment: Patch v6

Applied suggested changes.

Comment 25

[Dão Gottwald [:dao]]

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

Comment 26

[Ryan VanderMeulen [:RyanVM]]

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