Clear out all pending pings when FHR is deactived

RESOLVED FIXED in Firefox 43

Status

()

defect
P1
normal
RESOLVED FIXED
4 years ago
4 years ago

People

(Reporter: gfritzsche, Assigned: Dexter)

Tracking

(Blocks 1 bug)

Trunk
mozilla44
Points:
2
Dependency tree / graph

Firefox Tracking Flags

(firefox41 wontfix, firefox42 wontfix, firefox43 fixed, firefox44 fixed)

Details

(Whiteboard: [unifiedTelemetry][measurement:client])

Attachments

(5 attachments, 11 obsolete attachments)

1.31 KB, patch
gfritzsche
: review+
Details | Diff | Splinter Review
16.51 KB, patch
Dexter
: review+
Details | Diff | Splinter Review
1.25 KB, patch
Dexter
: review+
Details | Diff | Splinter Review
2.91 KB, patch
Dexter
: review+
Details | Diff | Splinter Review
20.46 KB, patch
Details | Diff | Splinter Review
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

4 years ago
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.
Status: NEW → RESOLVED
Last Resolved: 4 years ago
Resolution: --- → WONTFIX
Reporter

Comment 2

4 years ago
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.
Status: RESOLVED → REOPENED
Resolution: WONTFIX → ---

Comment 3

4 years ago
Ah yeah, ok.
Reporter

Updated

4 years ago
Whiteboard: [b5] [unifiedTelemetry]
Reporter

Updated

4 years ago
Blocks: 1122482
No longer blocks: 1120356
Whiteboard: [b5] [unifiedTelemetry] → [unifiedTelemetry]
Assignee

Updated

4 years ago
Priority: -- → P2
Assignee

Updated

4 years ago
Blocks: 1201022
No longer blocks: 1122482
Priority: P2 → --
Assignee

Updated

4 years ago
Assignee: nobody → alessio.placitelli
Reporter

Updated

4 years ago
Status: REOPENED → ASSIGNED
Reporter

Updated

4 years ago
Points: --- → 2
Assignee

Comment 5

4 years ago
Posted patch part 2 - Add test coverage (obsolete) — Splinter Review

Updated

4 years ago
Priority: -- → P1
Whiteboard: [unifiedTelemetry] → [unifiedTelemetry][measurement:client]
Reporter

Comment 6

4 years ago
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?
Attachment #8661849 - Flags: review?(gfritzsche) → feedback+
Assignee

Comment 7

4 years ago
Thanks Georg. I've taken care of cleaning up the shutdown, as discussed.
Attachment #8661849 - Attachment is obsolete: true
Attachment #8665492 - Flags: review?(gfritzsche)
Reporter

Comment 8

4 years ago
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.
Attachment #8665492 - Flags: review?(gfritzsche) → feedback+
Reporter

Comment 9

4 years ago
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()?
Attachment #8661850 - Flags: feedback+
Assignee

Comment 10

4 years ago
Attachment #8665492 - Attachment is obsolete: true
Attachment #8666695 - Flags: review?(gfritzsche)
Assignee

Comment 11

4 years ago
Whoops sorry, wrong file.
Attachment #8666695 - Attachment is obsolete: true
Attachment #8666695 - Flags: review?(gfritzsche)
Attachment #8666697 - Flags: review?(gfritzsche)
Reporter

Updated

4 years ago
Attachment #8666697 - Flags: review?(gfritzsche) → review+
Assignee

Comment 12

4 years ago
This patch takes care of the races that were detected with the tests.
Attachment #8666697 - Attachment is obsolete: true
Attachment #8668388 - Flags: review?(gfritzsche)
Assignee

Comment 13

4 years ago
Attachment #8661850 - Attachment is obsolete: true
Attachment #8668394 - Flags: review?(gfritzsche)
Reporter

Comment 14

4 years ago
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).
Attachment #8668388 - Flags: review?(gfritzsche) → feedback+
Reporter

Comment 15

4 years ago
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?
Attachment #8668394 - Flags: review?(gfritzsche)
Assignee

Comment 16

4 years ago
Thanks Georg, that should be it. As discussed, I've moved the part which blocks on pending ping saves to a separate patch.
Attachment #8668388 - Attachment is obsolete: true
Attachment #8668536 - Flags: review?(gfritzsche)
Assignee

Comment 17

4 years ago
This doesn't cost us much and helps us rule out any problem due to shutting down when pings are still being written.
Attachment #8668546 - Flags: review?(gfritzsche)
Assignee

Comment 18

4 years ago
Since we're here, let's fix this as well.
Attachment #8668547 - Flags: review?(gfritzsche)
Assignee

Comment 19

4 years ago
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.
Reporter

Comment 20

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

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

rs=me
Attachment #8668547 - Flags: review?(gfritzsche) → review+
Reporter

Comment 21

4 years ago
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()?
Attachment #8668536 - Flags: review?(gfritzsche) → review+
Assignee

Comment 23

4 years ago
Attachment #8668394 - Attachment is obsolete: true
Attachment #8668536 - Attachment is obsolete: true
Attachment #8668914 - Flags: review?(gfritzsche)
Reporter

Comment 24

4 years ago
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.
Attachment #8668914 - Flags: review?(gfritzsche) → review+
Reporter

Comment 25

4 years ago
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.
Attachment #8668546 - Flags: review?(gfritzsche) → review+
Assignee

Comment 26

4 years ago
Attachment #8668914 - Attachment is obsolete: true
Attachment #8668929 - Flags: review+
Assignee

Comment 30

4 years ago
This fixes the fallout from the try server.
Attachment #8668929 - Attachment is obsolete: true
Attachment #8669741 - Flags: review+
Assignee

Comment 33

4 years ago
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
Attachment #8683695 - Flags: approval-mozilla-beta?
Alessio, why do you want to uplift that now? We released two versions with this issue (which is not big deal to me).
Flags: needinfo?(alessio.placitelli)
Reporter

Comment 36

4 years ago
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.
Flags: needinfo?(alessio.placitelli)
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.
Attachment #8683695 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
You need to log in before you can comment on or make changes to this bug.