1123660 - Measure the impact that using Hello has on overall time spent browsing on Firefox

Status: VERIFIED FIXED

(Hello (Loop) :: Client, defect, P2)

Comment 1

[Romain Testard [:RT]]

Saptarshi, can you please help clarify what needs to happen on the client side in order to be able to deliver this for Fx38 or after given the new possibilities in place from Fx38 on?

Comment 2

[Romain Testard [:RT]]

Per discussions we want the desktop client to add the following details to the FHR session packet:
- an array allowing to identify the number of calls and the per call duration

This will enable identification of Hello activity per browser session, therefore allowing to tie Hello usage and session duration. The understanding is that browser sessions can be correlated.

Mika, can you please take a look and validate if this is OK from your standpoint?

Comment 3

[Mika]

Hi Romain, since this involves an additional data  metric it should go to the Data Steward for review per the data compliance program that Marshall leads.  I'm both copying Travis and Marshall.

Comment 4

["Saptarshi Guha[:joy]"]

(In reply to Romain Testard [:RT] from comment #1)
> Saptarshi, can you please help clarify what needs to happen on the client
> side in order to be able to deliver this for Fx38 or after given the new
> possibilities in place from Fx38 on?

Yes, I recommend measuring per session
- how many calls participated in (successful or not)
- how many unique rooms joined (successful or not)
- total minutes/seconds spent in calls
- total minutes/seconds spent in room

To report the success of the product, we need these measurements for release hence they should be in FHR as opposed to being in Telemetry

Comment 5

[Merwin]

Adding Benjamin Smedberg to this.  As the data steward for the firefox org, he has point for decisions regarding adding parameters to FHR collection. We are tyring to push these decisions down into the appropriate business units and will trust that Benjamin loops legal and compliance in appropriately if he decides this makes sense from his perspective.  

my two cents - I suspect we'll need to have a longer conversation if this does loop back our way. Using FHR to measure the effect of Hello on time spent on Firefox doesn't make much sense to me.

Marshall

Comment 6

[Chris Karlof [:ckarlof]]

> Using FHR to measure the effect of Hello on time spent on Firefox doesn't make much sense to me.

To goal is to determine if increased usage and engagement with Hello is correlated with increased usage of Firefox.

IMO, daily usage hours is one of the more useful proxies we have for user retention and engagement.

Comment 7

[John Jensen]

Please permit me to speak generally for a second.

If Hello doesn't perform -- calls hang or crash, or the interface is hard to use, or it doesn't work with other browsers or versions, or many other reasons -- we are not providing value to our users. I don't think anyone would dispute that. 

For any product or feature, in order to understand problem rates, we need divisors:

           number of problems
-----------------------------------------
number of opportunities to have a problem

Generally, we want the resulting number to stay flat or go down over time.

for Hello, this could be things like:

number of aborted calls
-----------------------
total number of calls

or

number of aborted calls
------------------------
total minutes spent on calls

...etc.

My point here is that, yes, as a side effect of understanding whether or not our feature works we will be able to understand how it affects overall usage of the product. But the primary goal is to make sure our features work as intended so that we can make a better product.

Comment 8

[Romain Testard [:RT]]

(In reply to John Jensen from comment #7)
> Please permit me to speak generally for a second.
> 
> If Hello doesn't perform -- calls hang or crash, or the interface is hard to
> use, or it doesn't work with other browsers or versions, or many other
> reasons -- we are not providing value to our users. I don't think anyone
> would dispute that. 
> 
> For any product or feature, in order to understand problem rates, we need
> divisors:
> 
>            number of problems
> -----------------------------------------
> number of opportunities to have a problem
> 
> Generally, we want the resulting number to stay flat or go down over time.
> 
> for Hello, this could be things like:
> 
> number of aborted calls
> -----------------------
> total number of calls
> 
> or
> 
> number of aborted calls
> ------------------------
> total minutes spent on calls
> 
> ...etc.
> 
> My point here is that, yes, as a side effect of understanding whether or not
> our feature works we will be able to understand how it affects overall usage
> of the product. But the primary goal is to make sure our features work as
> intended so that we can make a better product.
Sure and this is being dealt with as part of the on-going reporting effort for Hello:
https://bugzilla.mozilla.org/showdependencytree.cgi?id=1122505&hide_resolved=1
https://bugzilla.mozilla.org/showdependencytree.cgi?id=1122494&hide_resolved=1

This bug is very specific to measuring the impact that Hello has on overall time spent using Firefox in order to determine the impact Hello has on our goal to grow Firefox usage overall.

Comment 9

[Benjamin Smedberg]

I sent email about this, and I don't think I can provide further input until we have a dedicated meeting. I am not concerned about measuring the usage of Hello in general, but I am concerned about measuring things like call durations which can make the payload much more identifying. My goal is to collect the least information possible that will let us answer the questions we care about, at least for release users. And that we have identified the user benefit in enough detail that when we're done we know whether we are actually providing that benefit.

Comment 10

[Romain Testard [:RT]]

Per our meeting tody I updated the user story field with the requirements.

Comment 11

[Romain Testard [:RT]]

Benjamin, after discussions with abr on the subject, he raised that using 9 bucket categories for room/call duration and number may help us get a better reflection of actual user activity on Hello while preserving user privacy -  few, some, many calls per week; crossed with short, medium, and long call durations

Do you think this is an acceptable approach?

Comment 12

[Benjamin Smedberg]

What are the buckets?

Since our unit of measurement is the session, not the week, can we just do counts per session in three buckets (short/medium/long)? That's fine with me.

Comment 13

[Romain Testard [:RT]]

Counts per session seem fine so long as we'll get info on the session duration.
Indeed we can do counts per session for successful Hello sessions in three buckets.

An example of a session could be:
  * 10 successful Hello sessions 
        - 1 short
        - 7 medium
        - 2 long
  * 3 failed Hello sessions

I updated the user story field with these details as well as tentative definitions for short, medium and long sessions. I NI Adam in case he has further thoughts on this.

Comment 14

[Adam Roach [:abr]]

(In reply to Romain Testard [:RT] from comment #13)
> I updated the user story field with these details as well as tentative
> definitions for short, medium and long sessions. I NI Adam in case he has
> further thoughts on this.

This looks good to me. We might want to tweak the definitions of short/medium/long after we get data coming in, but I can't argue with these for initial values.

Comment 15

[Romain Testard [:RT]]

Thanks abr
Shell could we bring this to the Fx38 scope since it's part of the reporting effort.
I'm not sure of the complexity here but maybe something we can discuss in our next stand-ups?

Comment 16

[:shell escalante]

shell add to trello

Comment 17

[Jared Wein [:jaws] (please needinfo? me)]

Attachment: WIP Patch

Comment 18

[Jared Wein [:jaws] (please needinfo? me)]

Attachment: Patch

Comment 19

[Jared Wein [:jaws] (please needinfo? me)]

Attachment: Patch almost ready

Might just need some jsdoc stuff.

Comment 20

[Jared Wein [:jaws] (please needinfo? me)]

This is mostly working, but we're noticing that about:telemetry shows an entry in the "failure" bucket upon startup of the browser before any calls have been made.

We probably need to track also when local publish has started (before both sides of the media are connected) so we will be able to better track the failure state.

Comment 21

[Dan Mosedale (:dmosedale, :dmose)]

Gavin also pointed out that we need to set the opt-in flag for Telemetry, and we also need to be sure that whatever data review procedures go with that are done.

Comment 22

[Jared Wein [:jaws] (please needinfo? me)]

(In reply to Dan Mosedale (:dmose) - needinfo? me for response from comment #21)
> Gavin also pointed out that we need to set the opt-in flag for Telemetry,
> and we also need to be sure that whatever data review procedures go with
> that are done.

I thought we wanted opt-out (FHR) behavior here though? Yes, I do agree that we need to follow the data review procedures regardless.

Comment 23

[Dan Mosedale (:dmosedale, :dmose)]

You're quite right that we want opt out behavior; that was a think-o on my part.

Comment 24

[Dan Mosedale (:dmosedale, :dmose)]

https://wiki.mozilla.org/Firefox/Data_Collection is the process, it looks like.

Comment 25

[Dan Mosedale (:dmosedale, :dmose)]

After discussion, jaws and I think that the thing that's practical to implement and framed sufficiently crisply is a slight different user story:

(Commenting on User Story)
> As a product manager I want to measure the impact that the Hello service has
> on the time users spend on Firefox in general.
> 
> In FF38, Telemetry and FHR will be merged and metrics will be measured
> longitudinally (i.e. a time series of profiles metrics will be stored thus
> we can we see usage changes before the profile used Hello and after etc).
> 
> Acceptance criteria:

-The following data gets added to FHR
  * Number of Hello sessions where media connection completed on both sides, per session duration category:
  ** SHORTER_THAN_10S
  ** 10S_TO_30S
  ** 30S_TO_5M
  ** 5M_OR_LONGER

> Hello successful session definition: direct call, URL call-back or
> conversation instance where 2 peers are concurrently present with
> bi-directionnal media for more than 10s. We are counting here every session
> regardless of whether the browser user is the A party or the B party.
> 
> Hello failed session definition: initiated direct call or conversation
> instance where both peers could not success in being present with
> bi-directionnal media or could but for less than 10s. We are counting here
> every session regardless of whether the browser user is the A party or the B
> party.

The reasoning for this is because calling shorter than 10S failure seems extremely easy to inadvertently confuse with cases where the called failed before media connection setup completed.  RT, does this work for you?

If so, jaws and I will update the user story here and then request needing on bsmedberg for opt-in collection of this.

Comment 26

[Dan Mosedale (:dmosedale, :dmose)]

And, of course, I meant "opt-out" in that last comment.

Comment 27

[Jared Wein [:jaws] (please needinfo? me)]

Attachment: with changes

Comment 28

[Dan Mosedale (:dmosedale, :dmose)]

Attachment: Add telemetry probes for measuring failed, short, medium, and long calls. Paired with :dmose

Comment 29

[Jared Wein [:jaws] (please needinfo? me)]

Attachment: Patch should be ready for landing

Comment 30

[Romain Testard [:RT]]

> The reasoning for this is because calling shorter than 10S failure seems
> extremely easy to inadvertently confuse with cases where the called failed
> before media connection setup completed.  RT, does this work for you?
> 
> If so, jaws and I will update the user story here and then request needing
> on bsmedberg for opt-in collection of this.

TO be sure I understand, the failed calls will be counted in the SHORTER_THAN_10S bucket as well as calls lasting for less than 10s, is that right?

Comment 31

[Dan Mosedale (:dmosedale, :dmose)]

(In reply to Romain Testard [:RT] from comment #30)
> > The reasoning for this is because calling shorter than 10S failure seems
> > extremely easy to inadvertently confuse with cases where the called failed
> > before media connection setup completed.  RT, does this work for you?
> 
> TO be sure I understand, the failed calls will be counted in the
> SHORTER_THAN_10S bucket as well as calls lasting for less than 10s, is that
> right?

If by "failed calls", you mean "calls that failed after the link-clicker or direct call initiator clicked Join or Call, but before bi-directional media was connected", the answer is that they will not be in that bucket, and a big part of the reason we wanted to rename it was to make this more clear.

That set of failures really consists of multiple chunks, and the data is spread out across various places.   because the room and call models are substantially different, I'd suggest spinning off two separate bugs if you want to collect that data also, as this bug is already somewhat substantial.

Given all that, are you okay with the definition I've proposed above?

Comment 32

[Dan Mosedale (:dmosedale, :dmose)]

Note if there's something else you can think of that we could do to make the terminology for the data set in this blog even more clear, feel free.

Comment 33

[Dan Mosedale (:dmosedale, :dmose)]

Perhaps calling this the "loop media connection length" (and changing the constants in the code) would help too...

Comment 34

[Romain Testard [:RT]]

> Given all that, are you okay with the definition I've proposed above?

Thanks for clarifying.
Yes let's do that, I changed the US field to reflect that decision and created the bug 1139317 to follow-up with tracking of failed calls.

Comment 35

[Dan Mosedale (:dmosedale, :dmose)]

Benjamin, the updated user story at the top of the bug describes where we landed with the exact data we'd like to collect.   My understanding is that you and ABR and RT have already spent time talking about this in some detail. Requesting approval for this to be an opt out property, as this is one of our best proxies for overall use and  we'd like to correlate it with overall opt out usage numbers.

Comment 36

[Benjamin Smedberg]

As with the similar passwords bug, I think it's fine to collect this for a limited time period (6 months) to get a better understanding of user behavior and that this data can definitely drive product improvements. We should set the histogram to expire in Firefox 43 and have a conversation before then about whether/how this data collect will provide long-term user benefit.

Comment 37

[Dan Mosedale (:dmosedale, :dmose)]

Comment on attachment 8571616 [details] [diff] [review]
Patch should be ready for landing

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

Spent some time testing and going over our patches today, and found some stuff.  This is going to need some updating.  Changes to include:

* we don't show up in telemetry when the remote caller hangs up but the local caller is still connected.  This needs a fix and a test.
* expiring in 6 months per bsmedberg's request
* a functional test, if this isn't too painful
* various things need JSDoc commentary

More comments in-line.

::: browser/components/loop/MozLoopAPI.jsm
@@ +626,5 @@
> +    LOOP_CONNECTION_LENGTH: {
> +      enumerable: true,
> +      get: function() {
> +        return Cu.cloneInto(LOOP_CONNECTION_LENGTH, targetWindow);
> +      }

I'm going to change the various incarnations of LOOP_CONNECTION_LENGTH to LOOP_2WAY_MEDIA_CONN_LENGTH to be very clear about what we're measuring here.  Should be a straightforward search and replace.

::: browser/components/loop/content/shared/js/otSdkDriver.js
@@ +514,5 @@
> +        console.error("_validateAndNoteConnectionLength called with " +
> +                      " invalid startTime, either the calls were never" +
> +                      " connected or there is a bug",
> +                      startTime);
> +        return;

Since this often is a completely valid thing, I'm going to change this from console.error to console.log or something similar.

::: toolkit/components/telemetry/Histograms.json
@@ +7158,5 @@
>    },
> +  "LOOP_CLIENT_CONNECTION_LENGTH": {
> +    "expires_in_version": "never",
> +    "kind": "count",
> +    "keyed": true,

Closer inspection of both about:telemetry and <https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Adding_a_new_Telemetry_probe> reveal that we don't want keyed histograms.  Keyed histograms are a collection of histograms, and in this case, each with just 0 and 1 buckets, which doesn't make much sense.  We want enumerated, and we just have to keep track of the enum <-> int mapping ourselves.

Comment 38

[Mark Banner (:standard8)]

Comment on attachment 8571616 [details] [diff] [review]
Patch should be ready for landing

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

::: browser/components/loop/content/shared/js/otSdkDriver.js
@@ +25,5 @@
>        }
>  
>        this.dispatcher = options.dispatcher;
>        this.sdk = options.sdk;
> +      this.mozLoop = options.mozLoop;

Can you add a comment here to be explicit about this being optional? I'm a bit concerned by people seeing it and potentially assuming they can use it whenever, but not being able to.

Comment 39

[Dan Mosedale (:dmosedale, :dmose)]

(In reply to Mark Banner (:standard8) from comment #38)
> Comment on attachment 8571616 [details] [diff] [review]
> Patch should be ready for landing
> 
> Review of attachment 8571616 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: browser/components/loop/content/shared/js/otSdkDriver.js
> @@ +25,5 @@
> >        }
> >  
> >        this.dispatcher = options.dispatcher;
> >        this.sdk = options.sdk;
> > +      this.mozLoop = options.mozLoop;
> 
> Can you add a comment here to be explicit about this being optional? I'm a
> bit concerned by people seeing it and potentially assuming they can use it
> whenever, but not being able to.

Added this:

      // Note that this will only be defined and usable in a desktop-local
      // context, not in the standalone web client.
      this.mozLoop = options.mozLoop;

Comment 40

[Dan Mosedale (:dmosedale, :dmose)]

(In reply to Benjamin Smedberg  [:bsmedberg] from comment #36)
> As with the similar passwords bug, I think it's fine to collect this for a
> limited time period (6 months) to get a better understanding of user
> behavior and that this data can definitely drive product improvements. We
> should set the histogram to expire in Firefox 43 and have a conversation
> before then about whether/how this data collect will provide long-term user
> benefit.

Latest patch expires this in 43.

Comment 41

[Dan Mosedale (:dmosedale, :dmose)]

(In reply to Dan Mosedale (:dmose) - needinfo? me for response from comment #37)
 
> ::: toolkit/components/telemetry/Histograms.json
> @@ +7158,5 @@
> >    },
> > +  "LOOP_CLIENT_CONNECTION_LENGTH": {
> > +    "expires_in_version": "never",
> > +    "kind": "count",
> > +    "keyed": true,
> 
> Closer inspection of both about:telemetry and
> <https://developer.mozilla.org/en-US/docs/Mozilla/Performance/
> Adding_a_new_Telemetry_probe> reveal that we don't want keyed histograms. 
> Keyed histograms are a collection of histograms, and in this case, each with
> just 0 and 1 buckets, which doesn't make much sense.  We want enumerated,
> and we just have to keep track of the enum <-> int mapping ourselves.

I decided to leave this alone.  While the above is true, it seems both more error prone and makes the output of about:telemtry as well as the telemetry data itself hard to interpret, without going and looking up the enumeration string -> constants mappings by hand.

Comment 42

[Dan Mosedale (:dmosedale, :dmose)]

Attachment: https://github.com/dmose/gecko-dev/pull/5

This is almost guaranteed to be easier to review commit-by-commit using GitHubs PR tool, as it makes it very easy to switch between that view and the full changes view, so I'm starting there.  If you'd prefer a different method, I'm happy to put something else up, and I'm also happy to pair-review on it if you're so inclined.

It doesn't have all the functional testing I'd like just yet, but it seems like a substantial step forward that is probably worth landing standalone.  I'm open to various ideas of how we handle ongoing concerns here, but I suspect they problem want spin off bugs.

Comment 43

[Mark Banner (:standard8)]

Comment on attachment 8574511 [details] [review]
https://github.com/dmose/gecko-dev/pull/5

As I commented on the bug (with a few other nits/comments):

I think in general this looks reasonable. However, the functional test feels at the wrong level to me - it feels like its trying to unit/integration test otSdkDriver, rather than functional test the complete process - for a better functional test I'd expect to be looking at the logged telemetry information inside gecko rather than bits of Loop itself.

I think we can handle that in a follow-up though. Please can you file follow-ups for improving the test, and for splitting out the test into separate files etc.

Comment 44

[Dan Mosedale (:dmosedale, :dmose)]

Attachment: Add telemetry probes for measuring failed, short, medium, and long calls. Largely paired w/jaws

Comment 45

[Dan Mosedale (:dmosedale, :dmose)]

Attachment: Add telemetry probes for measuring failed, short, medium, and long calls. Largely paired w/jaws, for opt-out metric

Comment 46

[Dan Mosedale (:dmosedale, :dmose)]

https://hg.mozilla.org/integration/fx-team/rev/bc2b7db48fba

Comment 47

[Dan Mosedale (:dmosedale, :dmose)]

Comment on attachment 8574956 [details] [diff] [review]
Add telemetry probes for measuring failed, short, medium, and long calls. Largely paired w/jaws,   for opt-out metric

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

The patch that actually landed; carrying forward r=jaws,Standard8, and me, along with a=bsmedberg for the opt-out metric.

Comment 48

[Dan Mosedale (:dmosedale, :dmose)]

(In reply to Mark Banner (:standard8) from comment #43)
> Comment on attachment 8574511 [details] [review]
> https://github.com/dmose/gecko-dev/pull/5
> 
> As I commented on the bug (with a few other nits/comments):
> 
> I think in general this looks reasonable. However, the functional test feels
> at the wrong level to me - it feels like its trying to unit/integration test
> otSdkDriver, rather than functional test the complete process - for a better
> functional test I'd expect to be looking at the logged telemetry information
> inside gecko rather than bits of Loop itself.

I've filed bug 1141366 here.
 
> I think we can handle that in a follow-up though. Please can you file
> follow-ups for improving the test, and for splitting out the test into
> separate files etc.

I'll spend some time in the morning tidying up the various loose ends, probably after you and I get a chance to pow-wow about some of the future direction.

Comment 49

[Carsten Book [:Tomcat]]

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

Comment 50

[Dan Mosedale (:dmosedale, :dmose)]

To write the remaining tests for this bug, we're going to need to modularize things a bit, which bug 1071977 is tracking (though it's really a spike, which will likely need a follow-on implementation bug.

Writing the remaining integration tests for rooms telemetry is bug 1141690.

Writing a test for direct call functionality working at all is bug 1141694.

Writing a functional/integration tests for the direct call telemetry cases already implemented is bug 1141695.

Comment 51

[Dan Mosedale (:dmosedale, :dmose)]

Attachment: WIP - add logging to Loop media conneciton telemetry

Comment 52

[Dan Mosedale (:dmosedale, :dmose)]

Basic logging turned up some problems in the code itself.  Next step: fix the code is executing on both desktop and standalone sides; then see if the logging is clean enough to be useful in qe-verify.

Comment 53

[Mark Banner (:standard8)]

Comment on attachment 8577520 [details] [diff] [review]
WIP - add logging to Loop media conneciton telemetry

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

::: browser/components/loop/content/shared/js/otSdkDriver.js
@@ +454,5 @@
> +     * @private
> +     */
> +    _setTwoWayMediaStartTime: function(start) {
> +      this.__twoWayMediaStartTime = start;
> +      console.log("Loop Telemetry: noted two-way connection start, " +

When we land this, I think the logging should be behind a pref. We shouldn't need this on by default. I don't think we want to add a new pref, but harmonise some of our existing ones - I've been intending on doing that for a while. Might see if I can whip up a patch for it today.

Comment 54

[Dan Mosedale (:dmosedale, :dmose)]

Attachment: add logging to Loop media conneciton telemetry

Comment 55

[Dan Mosedale (:dmosedale, :dmose)]

It wasn't obvious to me what existing pref this would make sense under, so I just added a new one.  I'm happy to change it if you wish.

Comment 56

[Mark Banner (:standard8)]

Comment on attachment 8579649 [details] [diff] [review]
add logging to Loop media conneciton telemetry

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

nit: "connection" spelt wrongly in commit message.

I think its reasonable to add another pref for now - I'm hoping to unify these as part of bug 1118842.

::: browser/components/loop/content/shared/js/otSdkDriver.js
@@ +32,1 @@
>        this.mozLoop = options.mozLoop;

I don't think this comment really makes sense. It basically says it'll be defined in both places where we exist.

We don't actually pass it in on standalone:

http://mxr.mozilla.org/mozilla-central/source/browser/components/loop/standalone/content/js/webapp.jsx#1044

So whilst I agree its not a good proxy for isDesktop, I don't see why it would cause issues currently.

I think we should also re-organise this section to be more explicit about the intent, something like:

this.isDesktop = !!options.isDesktop

if (this.isDesktop) {
  if (!options.mozLoop) {
    throw new Error("Missing option mozLoop");
  }
  this.mozLoop = options.mozLoop;
}

@@ +32,3 @@
>        this.mozLoop = options.mozLoop;
>  
> +      this.isDesktop = !!options.isDesktop;

Also, I think we're gradually moving to the underscore form for private member variables, so please use this._isDesktop.

@@ +41,5 @@
>          "setMute"
>        ]);
>  
> +      // Set loop.debug.twoWayMediaTelemetry to true in the browser, or
> +      // standalone: localStorage.setItem("debug.twoWayMediaTelemetry", true);

The standalone comment here is a bit redundant since this code doesn't run on standalone anyway.

@@ +474,5 @@
> +        console.log("Loop Telemetry: noted two-way connection start, " +
> +                    "start time in ms:", start);
> +      }
> +    },
> +    _getTwoWayMediaStartTime: function() {

I think it would be worth documenting that this is exposed for debug purposes, which is why its a separate function.

Otherwise, I don't really see an advantage to make this into an extra wrapper function.

@@ +614,5 @@
> +    /*
> +     * XXX all of the bi-directional media connection telemetry stuff in this
> +     * file, (much, but not all, of it is below) should be hoisted into its
> +     * own object for maintainability and clarity, also in part because this
> +     * stuff only wants to run one side of the connection, not both.

Please file a bug for this and reference it here, if we're not going to do it now.

@@ +677,5 @@
>        if (startTime == this.CONNECTION_START_TIME_ALREADY_NOTED ||
> +        startTime == this.CONNECTION_START_TIME_UNINITIALIZED ||
> +        startTime > endTime) {
> +
> +        if (this._debugTwoWayMediaTelemetry) {

I think you can just extend the previous if statement with this.

nit: I think the previous if should line up with the first line (as per our prevailing style, then you don't need the extra space here.

if (startTime...
    startTime....

etc

@@ +694,5 @@
> +    /**
> +     * If set to true, make it easy to test/verify 2-way media connection
> +     * telemetry code operation by viewing the logs.
> +     */
> +    _debugTwoWayMediaTelemetry: false

I don't think you need to default this as its set in the constructor.

Comment 57

[Dan Mosedale (:dmosedale, :dmose)]

(In reply to Mark Banner (:standard8) from comment #56)
> Comment on attachment 8579649 [details] [diff] [review]
> add logging to Loop media conneciton telemetry
> 
> Review of attachment 8579649 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> nit: "connection" spelt wrongly in commit message.

Fixed.

> ::: browser/components/loop/content/shared/js/otSdkDriver.js
> @@ +32,1 @@
> >        this.mozLoop = options.mozLoop;
> 
> I don't think this comment really makes sense. It basically says it'll be
> defined in both places where we exist.

Good catch; deleted.

> We don't actually pass it in on standalone:
> 
> http://mxr.mozilla.org/mozilla-central/source/browser/components/loop/
> standalone/content/js/webapp.jsx#1044
> 
> So whilst I agree its not a good proxy for isDesktop, I don't see why it
> would cause issues currently.

I just did some debugging, and you're quite right. I'm not sure what I was running into earlier.

> I think we should also re-organise this section to be more explicit about
> the intent, something like:
> 
> this.isDesktop = !!options.isDesktop
> 
> if (this.isDesktop) {
>   if (!options.mozLoop) {
>     throw new Error("Missing option mozLoop");
>   }
>   this.mozLoop = options.mozLoop;
> }

Done.

> @@ +32,3 @@
> >        this.mozLoop = options.mozLoop;
> >  
> > +      this.isDesktop = !!options.isDesktop;
> 
> Also, I think we're gradually moving to the underscore form for private
> member variables, so please use this._isDesktop.

Good to know, thanks -- I was wondering about that as I wrote the code.  Changed.

> @@ +41,5 @@
> >          "setMute"
> >        ]);
> >  
> > +      // Set loop.debug.twoWayMediaTelemetry to true in the browser, or
> > +      // standalone: localStorage.setItem("debug.twoWayMediaTelemetry", true);
> 
> The standalone comment here is a bit redundant since this code doesn't run
> on standalone anyway.

Fixed.

> @@ +474,5 @@
> > +        console.log("Loop Telemetry: noted two-way connection start, " +
> > +                    "start time in ms:", start);
> > +      }
> > +    },
> > +    _getTwoWayMediaStartTime: function() {
> 
> I think it would be worth documenting that this is exposed for debug
> purposes, which is why its a separate function.
> 
> Otherwise, I don't really see an advantage to make this into an extra
> wrapper function.

Indeed; documented more.
 
> @@ +614,5 @@
> > +    /*
> > +     * XXX all of the bi-directional media connection telemetry stuff in this
> > +     * file, (much, but not all, of it is below) should be hoisted into its
> > +     * own object for maintainability and clarity, also in part because this
> > +     * stuff only wants to run one side of the connection, not both.
> 
> Please file a bug for this and reference it here, if we're not going to do
> it now.

Bug 1145237 filed.  I'd do it now, but this bug has already exploded, and needs to be put to bed.
 
> @@ +677,5 @@
> >        if (startTime == this.CONNECTION_START_TIME_ALREADY_NOTED ||
> > +        startTime == this.CONNECTION_START_TIME_UNINITIALIZED ||
> > +        startTime > endTime) {
> > +
> > +        if (this._debugTwoWayMediaTelemetry) {
> 
> I think you can just extend the previous if statement with this.

I don't think so, because we want to return from this function regardless of whether we're logging.  Leaving it as is.

> nit: I think the previous if should line up with the first line (as per our
> prevailing style, then you don't need the extra space here.
> 
> if (startTime...
>     startTime....

Fixed.

> @@ +694,5 @@
> > +    /**
> > +     * If set to true, make it easy to test/verify 2-way media connection
> > +     * telemetry code operation by viewing the logs.
> > +     */
> > +    _debugTwoWayMediaTelemetry: false
> 
> I don't think you need to default this as its set in the constructor.

Correct, but having a default value provides a place to hang the JSDoc.

Comment 58

[Dan Mosedale (:dmosedale, :dmose)]

Attachment: add logging to Loop media connection telemetry

Comment 59

[Dan Mosedale (:dmosedale, :dmose)]

https://hg.mozilla.org/integration/fx-team/rev/f79e4acd9172

Comment 60

[Dan Mosedale (:dmosedale, :dmose)]

Setting qe-verify+.  Steps for hand-verifying key rooms cases which don't currently have automated tests are at https://bugzilla.mozilla.org/show_bug.cgi?id=1141690#c1

Comment 61

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

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

Comment 62

[Dan Mosedale (:dmosedale, :dmose)]

It would be very helpful if this Could be verified before 39 uplifts to Aurora.  Adding a needinfo to FlorinM to get this on that radar.

Comment 63

[[SV Manager] Florin Mezei, QA (:FlorinMezei)]

I tested this today using:
- a Mac running OS X 10.7.5 + a PC running Windows 7 x64
- latest Firefox 39 Nightly running on each machine - BuildID=20150326030212
- e10s ON & OFF

Using the cases from https://bugzilla.mozilla.org/show_bug.cgi?id=1141690#c1, I got the following results:

== cases 1, 2, & 3 ==
a) caller gets the following messages in console:
----- when callee accepts conversation -----
"Loop Telemetry: noted two-way connection start, start time in ms:" -1
"Loop Telemetry: noted two-way connection start, start time in ms:" 8500.318651…
----- on hangup (from any side) -----
"Loop Telemetry: noted two-way connection start, start time in ms:" -2
"Loop Telemetry: noted two-way media connection in bucket: " “BETWEEN_10S_AND_30S”
"Loop Telemetry: noted two-way connection start, start time in ms:" -1
----- if caller clicks "x" (inset chat window) after the callee ended the conversation -----
"Loop Telemetry: noted two-way connection start, start time in ms:" -1
b) callee gets no Loop Telemetry messages in console

== case 4 ==
a) caller gets the following messages in console:
----- on accept conversation -----
"Loop Telemetry: noted two-way connection start, start time in ms:" -1
"Loop Telemetry: noted two-way connection start, start time in ms:" 8500.318651…
----- on hangup (any side) -----
"Loop Telemetry: noted two-way connection start, start time in ms:" -2
"Loop Telemetry: noted two-way media connection in bucket: " “BETWEEN_30S_AND_5M”
b) callee gets no Loop Telemetry messages in console

It seems only one "bucket" message is logged for every single conversation, which seems expected. Same goes for the "start time" that's not "-1" or "-2"... seems expected.

I'm not sure if the "start time" messages with "-1" and "-2" are expected though. Any thoughts on this Dan?

Comment 64

[Dan Mosedale (:dmosedale, :dmose)]

Florin: thanks!  Yes, the -1 and -2 messages can be ignored, they're just for debugging.

Comment 65

[[SV Manager] Florin Mezei, QA (:FlorinMezei)]

Thanks Dan, marking this as Verified then.