1268104 - Consolidate telemetry logging in UITelemetry.js

Status: NEW

(Firefox for Android :: Metrics, defect)

Description

[:Margaret Leibovic]

Right now we have logging in Telemetry.java for sending UI events and starting/stopping sessions. If we move this to UITelemetry.js, we'll have this logging available for both Java and JS probes.

Comment 1

[:Margaret Leibovic]

Attachment: MozReview Request: Bug 1268104 - Consolidate telemetry logging in UITelemetry.js. r=mcomella,gfritzsche

Review commit: https://reviewboard.mozilla.org/r/52051/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/52051/

Comment 2

[:Margaret Leibovic]

I used a pref to enable this by default for mobile, but not for desktop. I'm open to change that if people would like to use this on desktop as well.

One thing to note is that this requires that you have telemetry enabled, whereas the old log statements didn't. I could move the logging above the enabled check, but it's also not hard to flip the telemetry pref locally for testing.

Comment 3

[:Margaret Leibovic]

Hm... this made me notice that some of our events might be wrong:

05-11 18:07:48.772  7075  7095 I GeckoConsole: UITelemetry: stopSession: awesomescreen.1
05-11 18:07:49.056  7075  7095 I GeckoConsole: UITelemetry: addEvent: action = action.1 method = actionbar timestamp = 2191333410 extras = new_tab
05-11 18:07:49.229  7075  7095 I GeckoConsole: UITelemetry: stopSession: reader.1
05-11 18:07:49.229  7075  7095 I GeckoConsole: UITelemetry: addEvent: action = show.1 method = button timestamp = reader_unavailable extras = undefined
05-11 18:07:49.395  7075  7095 I GeckoConsole: UITelemetry: stopSession: reader.1
05-11 18:07:49.395  7075  7095 I GeckoConsole: UITelemetry: addEvent: action = show.1 method = button timestamp = reader_unavailable extras = undefined
05-11 18:07:50.037  7075  7095 I GeckoConsole: UITelemetry: addEvent: action = loadurl.1 method = suggestion timestamp = 2191334393 extras = 1
05-11 18:07:50.049  7075  7095 I GeckoConsole: UITelemetry: stopSession: awesomescreen.1
05-11 18:07:50.371  7075  7095 I GeckoConsole: UITelemetry: stopSession: reader.1
05-11 18:07:50.371  7075  7095 I GeckoConsole: UITelemetry: addEvent: action = show.1 method = button timestamp = reader_unavailable extras = undefined
05-11 18:08:04.214  7075  7095 I GeckoConsole: UITelemetry: stopSession: frecency.1

Check out that "reader_unavailable" event... that's my fault, I need to fix that. I'll file another bug.

Yay for logging!

Comment 4

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

r? redirect to someone else

Comment 5

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8751499 [details]
MozReview Request: Bug 1268104 - Consolidate telemetry logging in UITelemetry.js. r=mcomella,gfritzsche

https://reviewboard.mozilla.org/r/52051/#review49377

::: toolkit/components/telemetry/UITelemetry.jsm:31
(Diff revision 1)
> +    if (this._loggingEnabled) {
> +      Services.console.logStringMessage("UITelemetry: " + msg);

How about using Log.jsm here?
Or does it seem like overkill for this?

For comparison, other Telemetry logging preferences are documented here:
http://gecko.readthedocs.io/en/latest/toolkit/components/telemetry/telemetry/preferences.html

::: toolkit/components/telemetry/UITelemetry.jsm:128
(Diff revision 1)
> +    this._log("addEvent: action = " + aAction + " method = " + aMethod +
> +      " timestamp = " + aTimestamp + " extras = " + aExtras);

Template strings seem cleaner here. Also would be nice to have a separator between the elements:
```
this._log(`addEvent: action = ${aAction}, ...`)
```

Comment 6

[:Margaret Leibovic]

(In reply to Georg Fritzsche [:gfritzsche] from comment #5)
> Comment on attachment 8751499 [details]
> MozReview Request: Bug 1268104 - Consolidate telemetry logging in
> UITelemetry.js. r=mfinkle,gfritzsche
> 
> https://reviewboard.mozilla.org/r/52051/#review49377
> 
> ::: toolkit/components/telemetry/UITelemetry.jsm:31
> (Diff revision 1)
> > +    if (this._loggingEnabled) {
> > +      Services.console.logStringMessage("UITelemetry: " + msg);
> 
> How about using Log.jsm here?
> Or does it seem like overkill for this?
> 
> For comparison, other Telemetry logging preferences are documented here:
> http://gecko.readthedocs.io/en/latest/toolkit/components/telemetry/telemetry/
> preferences.html

Does Log.jsm work with Android? Is there a way to get that to appear in logcat?

The main use case here is seeing these messages get printed to logcat or a console as you do stuff with the browser, so I don't know how valuable it is to have these events in a log. I'd also prefer to make it as easy as possible to actually enable seeing these events, so product/UX people could use this as well.

Comment 7

[:Margaret Leibovic]

Comment on attachment 8751499 [details]
MozReview Request: Bug 1268104 - Consolidate telemetry logging in UITelemetry.js. r=mcomella,gfritzsche

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52051/diff/1-2/

Comment 8

[Michael Comella (:mcomella) [needinfo or I won't see it]]

Comment on attachment 8751499 [details]
MozReview Request: Bug 1268104 - Consolidate telemetry logging in UITelemetry.js. r=mcomella,gfritzsche

https://reviewboard.mozilla.org/r/52051/#review52664

Nice cleanup!

Looks mostly good – see my comments.

::: mobile/android/app/mobile.js:854
(Diff revision 2)
>  // Telemetry settings.
>  // Whether to use the unified telemetry behavior, requires a restart.
>  pref("toolkit.telemetry.unified", false);
>  
> +// Whether to enable UI telemetry logging
> +pref("toolkit.telemetry.uiTelemetryLogging", true);

We seem to set it true here, but false in init.js – why is that?

Also, do we need to specify the value for this preference twice? Is the idea to turn it on on mobile but off on desktop by default?

In any case, I'd expect this to be disabled by default.

::: toolkit/components/telemetry/UITelemetry.jsm:30
(Diff revision 2)
>    _enabled: undefined,
> +  _loggingEnabled: undefined,
>    _activeSessions: {},
>    _measurements: [],
>  
> +  _log(msg) {

Maybe I'm not up on my JS syntax but doesn't this have to be declared as a member? e.g.

`_log: function (msg) {`

or with an anonymous fn.

::: toolkit/components/telemetry/UITelemetry.jsm:83
(Diff revision 2)
>              this._measurements = [];
>            }
>            break;
> -      }
> +        }
> +        case PREF_LOGGING_ENABLED: {
> +          this._loggingEnabled = Services.prefs.getBoolPref(PREF_LOGGING_ENABLED);

I'm surprised the changed value isn't passed with the on change event!

Comment 9

[Georg Fritzsche [:gfritzsche]]

(In reply to :Margaret Leibovic from comment #6)
> > How about using Log.jsm here?
> > Or does it seem like overkill for this?
...
> The main use case here is seeing these messages get printed to logcat or a
> console as you do stuff with the browser, so I don't know how valuable it is
> to have these events in a log. I'd also prefer to make it as easy as
> possible to actually enable seeing these events, so product/UX people could
> use this as well.

I see, sounds reasonable.

Comment 10

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8751499 [details]
MozReview Request: Bug 1268104 - Consolidate telemetry logging in UITelemetry.js. r=mcomella,gfritzsche

https://reviewboard.mozilla.org/r/52051/#review54350

::: toolkit/components/telemetry/UITelemetry.jsm:83
(Diff revision 2)
>              this._measurements = [];
>            }
>            break;
> -      }
> +        }
> +        case PREF_LOGGING_ENABLED: {
> +          this._loggingEnabled = Services.prefs.getBoolPref(PREF_LOGGING_ENABLED);

No try-catch here in case of missing prefs?