1174674 - Clear out all pending pings when FHR is deactived

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect, P1)

Description

[Georg Fritzsche [:gfritzsche]]

Bug 1120379 now triggers deletion pings when FHR is deactived, requesting server-side deletion of the Telemetry data.
However, we may still have pending pings stored locally and would send them when we re-activate FHR.

We should clear the local pending pings out when FHR is deactivated.

Comment 1

[Benjamin Smedberg]

I don't think this makes sense.

If the user disables FHR, we still intend to collect the data locally to power the self-support feature: they are only disabling *sending* of the data. Therefore we should keep the pings locally.

The only time this might make sense is if telemetry archiving or the entire telemetry feature were disabled, but since we're not going to expose that in the UI I don't think we need to do dynamic deletion in those cases.

Comment 2

[Georg Fritzsche [:gfritzsche]]

This is about the pending pings, i.e. pings that are outgoing and not sent yet.

The ping archive is backed by a different ping store.

Comment 3

[Benjamin Smedberg]

Ah yeah, ok.

Comment 4

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Remove pending pings when disabling ping upload

Comment 5

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Add test coverage

Comment 6

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8661849 [details] [diff] [review]
part 1 - Remove pending pings when disabling ping upload

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

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +609,3 @@
>      yield this._cleanArchiveTask;
>      yield this._enforcePendingPingsQuotaTask;
> +    yield this._removePendingPingsTask;

I think the shutdown here is really sensitive to rejections/exceptions.

We basically want to finish all those tasks, even if one of them failed.
try-catching each might be a bit awkward though, maybe we should just make this an array of tasks that we sequentially walk through and catch all rejections?

Happy to do this in a separate patch though.

@@ +1325,5 @@
> +   */
> +  promisePendingPingSaves: function () {
> +    this._log.trace("promisePendingPingSaves - Waiting for ping task");
> +    let p = [for (p of this._activePendingPingSaves) p.catch(ex => {
> +      this._log.error("promisePendingPingSaves - failed to save ping", ex);

Don't we log this elsewhere already?
If so, lets not log redundantly here.

@@ +1353,5 @@
> +
> +  removePendingPings: Task.async(function*() {
> +    this._log.trace("removePendingPings - removing all pending pings");
> +
> +    // Wait on pending pings being still saved.

Nit: still being saved
Also comment on what condition/scenario this addresses.

@@ +1363,5 @@
> +    let iter = new OS.File.DirectoryIterator(directory);
> +    let exists = yield iter.exists();
> +
> +    if (!exists) {
> +      yield iter.close();

You are not closing the iterator on success.
Maybe just cover both cases with a big try-finally{iter.close()}?

@@ +1364,5 @@
> +    let exists = yield iter.exists();
> +
> +    if (!exists) {
> +      yield iter.close();
> +      return [];

Why return anything on this path?

Comment 7

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Remove pending pings when disabling ping upload - v2

Thanks Georg. I've taken care of cleaning up the shutdown, as discussed.

Comment 8

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8665492 [details] [diff] [review]
part 1 - Remove pending pings when disabling ping upload - v2

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

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +605,5 @@
>      this._shutdown = true;
> +
> +    // If the following tasks are still running, block on them. They will bail out as soon
> +    // as possible.
> +    let cleanupTasks = {

Ok, looking at this now, i think this function will be much more readable for casual readers if we instead to something like:

  yield a().catch(ex => {
    ... log
  });
  yield b().catch(ex => {
    ... log
  });
  ...

@@ +1335,5 @@
> +   * @return {Object<Promise>} A promise resolved when all the pending pings save promises
> +   *         are resolved.
> +   */
> +  promisePendingPingSaves: function () {
> +    this._log.trace("promisePendingPingSaves - Waiting for ping task");

I don't think this logging adds any real info, lets remove it.

@@ +1366,5 @@
> +  removePendingPings: Task.async(function*() {
> +    this._log.trace("removePendingPings - removing all pending pings");
> +
> +    // Wait on pending pings still being saved, so we also remove in-flight pending
> +    // pings.

Nit: "... so we also remove any pending pings that are currently being saved."

@@ +1372,5 @@
> +
> +    // Individually remove existing pings, so we don't interfere with operations expecting
> +    // the pending pings directory to exist.
> +    const directory = TelemetryStorage.pingDirectoryPath;
> +    let iter = new OS.File.DirectoryIterator(directory);

The way we have it now, its way too easy to miss `iter.close()` when updating code here or adding return paths.

We should do something like:

  let iter = ...
  try {
    ...
  } finally {
    yield iter.close();
  }

@@ +1376,5 @@
> +    let iter = new OS.File.DirectoryIterator(directory);
> +    let exists = yield iter.exists();
> +
> +    if (!exists) {
> +      yield iter.close();

You need to |return| here, the below code should not run.
You don't need to return any specific value though.

Comment 9

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8661850 [details] [diff] [review]
part 2 - Add test coverage

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

::: toolkit/components/telemetry/tests/unit/test_TelemetryController.js
@@ +154,5 @@
>    const PREF_TELEMETRY_SERVER = "toolkit.telemetry.server";
>  
> +  // Add a pending ping which will get deleted when disabling upload.
> +  const pendingPingId =
> +    yield TelemetryController.addPendingPing("test-ping", {}, { overwrite: true });

Can we make this a bit more realistic?
* disable the ping server
* submit the ping normally
* disable fhr upload
* check that pending pings get cleared out
* check that we receive a deletion ping

I guess that fits better into the second part of this test function.

Side note: This test function could be better named now - test_disableDataUpload()?

Comment 10

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Remove pending pings when disabling ping upload - v3

Comment 11

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Remove pending pings when disabling ping upload - v3

Whoops sorry, wrong file.

Comment 12

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Remove pending pings when disabling ping upload - v4

This patch takes care of the races that were detected with the tests.

Comment 13

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Add test coverage - v2

Comment 14

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8668388 [details] [diff] [review]
part 1 - Remove pending pings when disabling ping upload - v4

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

::: toolkit/components/telemetry/TelemetryController.jsm
@@ +924,5 @@
> +        this.submitExternalPing(PING_TYPE_DELETION, {}, { addClientId: true });
> +      }
> +    }.bind(this));
> +
> +    this._shutdownBarrier.client.addBlocker("TelemetryController: completing pending pings clenup", p);

"TelemetryController: removing pending pings after data upload was disabled"

::: toolkit/components/telemetry/TelemetrySend.jsm
@@ +715,5 @@
>  
> +  /**
> +   * Clear out unpersisted, yet to be sent, pings and cancel outgoing ping requests.
> +   */
> +  clearCurrentPings: Task.async(function*() {

We have potential shutdown races here against the shutdown order in TelemetryController._cleanupOnShutdown.

I think we need two shutdown checks here:
(1) when entering here, doing an early-return if TelemetrySend was shutdown already.
(2) before spinning the SendScheduler again below

@@ +731,5 @@
> +      }
> +    }
> +
> +    // Enable the scheduler again and spin the send task.
> +    SendScheduler._shutdown = false;

This directly accesses internals and is very hard to find for future changes.
We need to do this differently.

We can probably add a SendScheduler.start() and use that here and in SendScheduler.reset().

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +602,5 @@
> +    if (this._removePendingPingsTask) {
> +      yield this._removePendingPingsTask.catch(ex => {
> +        this._log.error("shutdown - the pending pings removal task failed", ex);
> +      });
> +    }

Should we wait on _activePendingPingSaves here too?

@@ +1297,5 @@
> +   */
> +  promisePendingPingSaves: function () {
> +    // Make sure to wait for all the promises, even if they reject. We don't need to log
> +    // the failures here, as they are already logged elsewhere.
> +    let promises = [for (p of this._activePendingPingSaves) p.catch(ex => {})];

Nit: 
let dummy = () => {};
let promises = [... .catch(dummy)];

We also have waitForAll() in TelemetryStorage (which looks like it should be updated to the above pattern).

Comment 15

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8668394 [details] [diff] [review]
part 2 - Add test coverage - v2

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

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +236,5 @@
>  
>    /**
> +   * Test method that allows waiting on the ping removal task to finish.
> +   */
> +  testRemovePendingPingsPromise: function() {

Do we really need this?

::: toolkit/components/telemetry/tests/unit/test_TelemetryController.js
@@ +173,5 @@
>    // Disable FHR upload to send a deletion ping again.
>    Preferences.set(PREF_FHR_UPLOAD_ENABLED, false);
> +
> +  // Wait for the pending pings to be deleted.
> +  yield TelemetryStorage.testRemovePendingPingsPromise();

Why do we need this explicitly and why is TelemetryController.reset() below not enough?
Maybe we need to properly TelemetryController.shutdown() or make TelemetryController.reset() behave better?

Comment 16

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Remove pending pings when disabling ping upload - v5

Thanks Georg, that should be it. As discussed, I've moved the part which blocks on pending ping saves to a separate patch.

Comment 17

[Alessio Placitelli [:Dexter]]

Attachment: part 3 - Make TelemetryStorage wait on pending pings on shutdown

This doesn't cost us much and helps us rule out any problem due to shutting down when pings are still being written.

Comment 18

[Alessio Placitelli [:Dexter]]

Attachment: part 4 - Bonus - Suppress octal values syntax errors

Since we're here, let's fix this as well.

Comment 19

[Alessio Placitelli [:Dexter]]

Also, I've manually tested the patches in this bug to make sure that:

- The pending pings get deleted.
- The deletin ping gets sent.
- The deletion ping gets properly serialized in case of connection problems.

Comment 20

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8668547 [details] [diff] [review]
part 4 - Bonus - Suppress octal values syntax errors

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

rs=me

Comment 21

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8668536 [details] [diff] [review]
part 1 - Remove pending pings when disabling ping upload - v5

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

::: toolkit/components/telemetry/TelemetrySend.jsm
@@ +662,3 @@
>      this._currentPings = new Map();
>  
>      this._overduePingCount = 0;

Whats up with the empty lines here?
The _shutdown, _currentPings, _overduePingCount don't need empty lines between them.

@@ +726,5 @@
> +   * Clear out unpersisted, yet to be sent, pings and cancel outgoing ping requests.
> +   */
> +  clearCurrentPings: Task.async(function*() {
> +    if (this._shutdown) {
> +      this._log.trace("clearCurrentPings - we are shutting down");

"... - in shutdown, bailing out"

@@ +739,5 @@
> +    this._cancelOutgoingRequests();
> +
> +    // Also, purge current pings.
> +    for (let [id, ping] in this._currentPings) {
> +      if (!isDeletionPing(ping)) {

We are now submitting the deletion ping after all the cleanup, which means we don't need to watch out for deletion pings anymore.
Just clear out everything.

@@ +744,5 @@
> +        this._currentPings.delete(id);
> +      }
> +    }
> +
> +    // We need to check that again, in case shutdown was just issued.

"We might have been interrupted and shutdown could have been started.
We need to bail out in that case to avoid triggering send activity etc.
at unexpected times."

@@ +746,5 @@
> +    }
> +
> +    // We need to check that again, in case shutdown was just issued.
> +    if (this._shutdown) {
> +      this._log.trace("clearCurrentPings - we are shutting down");

"... - in shutdown, not spinning SendScheduler up again"

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +116,5 @@
>   * always resolves its promise with undefined, and never rejects.
>   */
>  function waitForAll(it) {
> +  let dummy = () => {};
> +  let promises = [for (p of Array.from(it)) p.catch(dummy)];

Why do you need that `Array.from()` part?
Array comprehensions of the form `[for (x of Y) ...]` only require `Y` to be an iterable.
`(p of it)` should be fine.

@@ +1286,5 @@
> +    // Make sure to wait for all the promises, even if they reject. We don't need to log
> +    // the failures here, as they are already logged elsewhere.
> +    let dummy = () => {};
> +    let promises = [for (p of this._activePendingPingSaves) p.catch(dummy)];
> +    return Promise.all(promises);

Use `waitForAll()` here.

@@ +1313,5 @@
> +  removePendingPings: Task.async(function*() {
> +    this._log.trace("removePendingPings - removing all pending pings");
> +
> +    // Wait on pending pings still being saved, so we also remove any pending pings
> +    // that are currently being saved.

"... so we don't miss removing them."

@@ +1323,5 @@
> +    let iter = new OS.File.DirectoryIterator(directory);
> +
> +    try {
> +      if (!(yield iter.exists())) {
> +        return;

log.trace()?

Comment 22

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Remove pending pings when disabling ping upload - v6

Comment 23

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Add test coverage - v3

Comment 24

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8668914 [details] [diff] [review]
part 2 - Add test coverage - v3

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

r=me with the below fixed.

::: toolkit/components/telemetry/tests/unit/test_TelemetryController.js
@@ +179,2 @@
>    // Wait for the send task to terminate, flagging it to do so at the next opportunity and
>    // cancelling any timeouts.

Lets fix up this comment too.

@@ +181,5 @@
>    yield TelemetryController.reset();
>  
> +  // Disabling Telemetry upload must clear out all the pending pings.
> +  Assert.equal(TelemetryStorage.pendingPingCount, 0,
> +               "All the pending pings should have been deleted");

After `.shutdown()` and `.reset()` we dont have any cached pings from scanning.
Use `yield Telemetry.loadPendingPingList()` instead `pendingPingCount`, that lazily scans the disk.

Comment 25

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8668546 [details] [diff] [review]
part 3 - Make TelemetryStorage wait on pending pings on shutdown

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

r=me with the below fixed.

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +598,5 @@
>          this._log.error("shutdown - the pending pings removal task failed", ex);
>        });
>      }
> +
> +    // Wait on pending pings still being saved, just to be safe.

"Wait on pending pings still being saved. While OS.File should have shutdown blockers in place, we a) have seen weird errors being reported that might indicate a bad shutdown path and b) might have completion handlers hanging off the save operations that don't expect to be late in shutdown."

@@ +1568,2 @@
>        this.savePingToFile(ping, gAbortedSessionFilePath, true));
> +    this._trackPendingPingSaveTask(p);

We don't need this change, we already sync this on shutdown by flushing the _abortedSessionSerializer.

Comment 26

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Add test coverage - v4

Comment 27

[Alessio Placitelli [:Dexter]]

Attachment: part 3 - Make TelemetryStorage wait on pending pings on shutdown - v2

Comment 28

[Alessio Placitelli [:Dexter]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=805b2cf7c68d

Comment 29

[Alessio Placitelli [:Dexter]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=325c936be683

Comment 30

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Add test coverage - v5

This fixes the fallout from the try server.

Comment 31

[Alessio Placitelli [:Dexter]]

https://hg.mozilla.org/integration/fx-team/rev/15ec43f9dcfca975016dd1576f88ad1dfbeb0c0e
Bug 1174674 - Clear out all pending pings when FHR is deactived. r=gfritzsche

https://hg.mozilla.org/integration/fx-team/rev/5b50080b012b5d5bb7e34c959edc5d2bc197abfd
Bug 1174674 - Add test coverage. r=gfritzsche

https://hg.mozilla.org/integration/fx-team/rev/b19e47b1b33302a0e85013c81e81c4f655d305ee
Bug 1174674 - Always block Telemetry shutdown on pending ping writes. r=gfritzsche

https://hg.mozilla.org/integration/fx-team/rev/fc2079a6af20853d4f26a474e904c691d1fac097
Bug 1174674 - Remove octal value syntax errors from Telemetry tests. r=gfritzsche

Comment 32

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/15ec43f9dcfc
https://hg.mozilla.org/mozilla-central/rev/5b50080b012b
https://hg.mozilla.org/mozilla-central/rev/b19e47b1b333
https://hg.mozilla.org/mozilla-central/rev/fc2079a6af20

Comment 33

[Alessio Placitelli [:Dexter]]

Attachment: Fx_43 - Folded patches for Beta

Approval Request Comment
[Feature/regressing bug #]: This removes already pending pings so that they don't get sent to the servers after disabling telemetry upload.
[User impact if declined]: Undesired pings may get uploaded to Telemetry servers.
[Describe test coverage new/current, TreeHerder]: Automated test coverage already present. This has lived for a while on m-c with no issues.
[Risks and why]: Low-risk - manually tested, properly covered by automated testing. Changes limited to Telemetry pending ping management.
[String/UUID change made/needed]: None

Comment 34

[Sylvestre Ledru [:Sylvestre]]

Alessio, why do you want to uplift that now? We released two versions with this issue (which is not big deal to me).

Comment 35

[Alessio Placitelli [:Dexter]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=294428905db8

Comment 36

[Georg Fritzsche [:gfritzsche]]

This is a privacy issue: we might in rare cases send out data when we should not.
I think we should fix this rather sooner.

Comment 37

[Liz Henry (:lizzard) (relman/hg->git project)]

Comment on attachment 8683695 [details] [diff] [review]
Fx_43 - Folded patches for Beta

Let's take this for beta, as it is a privacy fix. If there are any problems with the uplifts or regressions, please back out the changes and let it ride with 44.

Comment 38

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/releases/mozilla-beta/rev/e7f899e48fc6