898184 - Restore telemetry measurements that were removed when transitioning to the SessionWorker

Status: RESOLVED FIXED

(Firefox :: Session Restore, defect)

Description

[Tim Taubert [:ttaubert] (inactive)]

The patch that introduced the SessionWorker removed a couple of telemetry measurements:

https://hg.mozilla.org/mozilla-central/rev/242b07a68acf

We should re-add them. Those are the timestamps that aren't recorded anymore:

FX_SESSION_RESTORE_READ_FILE_MS
FX_SESSION_RESTORE_BACKUP_FILE_MS (the time to move the file)

FX_SESSION_RESTORE_WRITE_FILE_MS should probably be moved to the Worker as well to get a real timing without any event queue hiccups.

As the operations are running on the worker synchronously, we can use Date.now() to measure the running time and return those numbers to the chrome process via messages. The chrome process can then submit those values to Telemetry like here:

http://mxr.mozilla.org/mozilla-central/source/toolkit/components/telemetry/TelemetryStopwatch.jsm#108

Comment 1

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

Seems like a good companion to smacleod's other telemetry bug!

Comment 2

[Steven MacLeod [:smacleod]]

Attachment: Patch - Restore telemetry measurements

The worker now returns a telemetry object which can contain measurements taken inside. It is the callers responsibilities to record the measurements.

FX_SESSION_RESTORE_READ_FILE_MS and FX_SESSION_RESTORE_BACKUP_FILE_MS have been restored, and FX_SESSION_RESTORE_WRITE_FILE_MS now measures just the write inside the worker.

Try: https://tbpl.mozilla.org/?tree=Try&rev=bca5db918ebd

Comment 3

[Tim Taubert [:ttaubert] (inactive)]

Comment on attachment 783435 [details] [diff] [review]
Patch - Restore telemetry measurements

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

Great patch! A few things:

::: browser/components/sessionstore/src/SessionWorker.js
@@ +25,1 @@
>   *                                id: custom_id}

Nit: can we maybe put that 'fail' object on the next line?

@@ +124,5 @@
>    /**
>     * Write the session to disk.
>     */
>    write: function (stateString, options) {
> +    let telemetry = {}

Nit: missing semicolon.

@@ +143,5 @@
>      let bytes = Encoder.encode(stateString);
> +    let startMs = Date.now();
> +    let result = File.writeAtomic(this.path, bytes, {tmpPath: this.path + ".tmp"});
> +    telemetry.FX_SESSION_RESTORE_WRITE_FILE_MS =  Date.now() - startMs;
> +    return {result: result, telemetry: telemetry};

We could move those lines into a separate _write() method maybe? So write() and writeLoadStateOnceAfterStartup() could share code as long as the latter still exists.

@@ +178,5 @@
> +    let bytes = Encoder.encode(stateString);
> +    let telemetry = {};
> +    let options = {tmpPath: this.path + ".tmp", outExecutionDuration: null};
> +    let result = File.writeAtomic(this.path, bytes, options);
> +    telemetry.FX_SESSION_RESTORE_WRITE_FILE_MS = options.outExecutionDuration;

I don't think that outExecutionDuration is supported?

Comment 4

[Steven MacLeod [:smacleod]]

Attachment: Patch - Restore telemetry measurements v2

Updated patch based on Tim's feedback. Also fixed a bug causing writeLoadStateOnceAfterStartup to fail.

Comment 5

[Steven MacLeod [:smacleod]]

try: https://tbpl.mozilla.org/?tree=Try&rev=f42132e58c99

Comment 6

[Tim Taubert [:ttaubert] (inactive)]

Comment on attachment 783849 [details] [diff] [review]
Patch - Restore telemetry measurements v2

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

I think we can make this code a little easier even:

::: browser/components/sessionstore/src/SessionWorker.js
@@ +141,5 @@
>      }
>  
> +    let writeResult = this._write(stateString);
> +    telemetry.FX_SESSION_RESTORE_WRITE_FILE_MS = writeResult.durationMs;
> +    return {result: writeResult.result, telemetry: telemetry};

return this._write(stateString, telemetry);

@@ +176,5 @@
> +    let writeResult = this._write(JSON.stringify(state));
> +    return {
> +      result: writeResult.result,
> +      telemetry: {FX_SESSION_RESTORE_WRITE_FILE_MS: writeResult.durationMs}
> +    };

return this._write(JSON.stringify(state));

@@ +182,5 @@
> +
> +  /**
> +   * Write a stateString to disk
> +   */
> +  _write: function (stateString) {

_write: function (stateString, telemetry = {}) {

@@ +186,5 @@
> +  _write: function (stateString) {
> +    let bytes = Encoder.encode(stateString);
> +    let durationMs = Date.now();
> +    let result = File.writeAtomic(this.path, bytes, {tmpPath: this.path + ".tmp"});
> +    durationMs = Date.now() - durationMs;

telemetry.FX_SESSION_RESTORE_WRITE_FILE_MS = Date.now() - durationMs;

@@ +187,5 @@
> +    let bytes = Encoder.encode(stateString);
> +    let durationMs = Date.now();
> +    let result = File.writeAtomic(this.path, bytes, {tmpPath: this.path + ".tmp"});
> +    durationMs = Date.now() - durationMs;
> +    return {result: result, durationMs: durationMs};

return {result: result, telemetry: telemetry};

Comment 7

[Steven MacLeod [:smacleod]]

Attachment: Patch - Restore telemetry measurements v3

Updated patch based on Tim's review. Much nicer :D

Comment 8

[Tim Taubert [:ttaubert] (inactive)]

Comment on attachment 783899 [details] [diff] [review]
Patch - Restore telemetry measurements v3

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

Cool, thanks!

Comment 9

[Ryan VanderMeulen [:RyanVM]]

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

Comment 10

[Ryan VanderMeulen [:RyanVM]]

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