1178262 - Fix persisted deletion ping handling

Status: RESOLVED FIXED

(Toolkit :: Telemetry, defect, P2)

Description

[Georg Fritzsche [:gfritzsche]]

I discovered that we could never submit deletion pings if we failed on the first try.
We need to extend the existing test-coverage on this.

Comment 1

[Georg Fritzsche [:gfritzsche]]

We stumbled over a short-coming in how we allow "deletion" pings through, which is not cheaply to solve (we currently don't know the type of persisted pings without loading them, so we couldn't tell which pings to send without hitting the disk).
To fix it, it would simplify things a-lot if we could always only send the latest "deletion" ping (ignoring the corner-cases where you accumulate >1 outgoing "deletion" ping) as previously suggested by vladan.

Per bug 1156712, comment 61, its fine server-side for mreid.
The only concern i can see right now is that someone could:
1) opt-out of FHR (offline)
2) opt-in to FHR (still offline)
3) reset/change client id
4) opt-out of FHR (still offline)
5) go online
6) server will only unlink records with the new client id

Benjamin - is that ok for you from a privacy & product perspective?

Comment 2

[Benjamin Smedberg]

It used to be that opting out of FHR would delete/reset the clientID. I don't think that's useful any longer, because of the way we store historical pings on disk. So assuming we don't do that any more, then I don't care about the case where somebody is manually messing with their clientID in step #3, and so this proposal is fine.

Comment 3

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Change the deletion ping logic

Comment 4

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Extend test coverage

This also fixes a small glitch which produced an error message in XPCSHELL tests.

Comment 5

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Extend test coverage

Comment 6

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8631027 [details] [diff] [review]
part 2 - Extend test coverage

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

::: toolkit/components/telemetry/tests/unit/test_TelemetryController.js
@@ +168,5 @@
> +  // Simulate a failure in sending the deletion ping by disabling the HTTP server.
> +  yield PingServer.stop();
> +  // Disable FHR upload to send a deletion ping again.
> +  Preferences.set(PREF_FHR_UPLOAD_ENABLED, false);
> +  // The next line will wait for the send task to terminate, flagging it to do so at the

Nit: Just "Wait for the ..."?

Comment 7

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8631024 [details] [diff] [review]
part 1 - Change the deletion ping logic

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

::: toolkit/components/telemetry/TelemetrySend.jsm
@@ +961,5 @@
>      // The Telemetry pref enables sending extended data sets instead.
>      if (IS_UNIFIED_TELEMETRY) {
> +      // Deletion pings are sent even if the upload is disabled. We check the ping
> +      // type if available, otherwise we query TelemetryStorage.
> +      if (ping && (isDeletionPing(ping) || TelemetryStorage.isDeletionPing(ping.id))) {

I don't think overloading the function this way is easy to follow.

In SendScheduler._doSendTask(), we know exactly whether we filter on 1) a list of pings or 2) a list of ping info objects.
We can just always check TelemetryStorage.isDeletionPing(pingInfo.id) for 2) (i.e. |pending = pending.filter(pingInfo => ...)|).

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +1003,5 @@
> +    };
> +
> +    // If we're saving a deletion ping as pending, we need to write it to a special
> +    // location.
> +    if (ping.type == PING_TYPE_DELETION) {

I'd rather not have this special-casing (magically different behavior depending on ping content).
Instead lets add a separate save function so its clear that its a separate code path, similar to saveAbortedSessionPing().

@@ +1073,5 @@
>        yield iter.close();
>        return [];
>      }
>  
> +    let _doAddFile = Task.async(function*(path) {

I don't think sharing this between the two places below really helps.
We don't need to stat() the deletion ping; we know it has no UUID in its filename.

Let's just leave the scanning below and add the few lines to directly handle the deletion ping.

@@ +1273,5 @@
> +    this._log.trace("_saveDeletionPing - ping path: " + gDeletionPingFilePath);
> +    yield OS.File.makeDir(gDataReportingDir, { ignoreExisting: true });
> +
> +    return this._deletionPingSerializer.enqueueTask(() =>
> +      this.savePingToFile(ping, gDeletionPingFilePath, true));

So, we are serializing saves, but what about removing it?

Comment 8

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Extend test coverage - v2

Comment 9

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Change the deletion ping logic - v2

Comment 10

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8631559 [details] [diff] [review]
part 1 - Change the deletion ping logic - v2

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

::: toolkit/components/telemetry/TelemetrySend.jsm
@@ +398,5 @@
>        let current = TelemetrySendImpl.getUnpersistedPings();
>        this._log.trace("_doSendTask - pending: " + pending.length + ", current: " + current.length);
> +      // Note that the two lists contain different data.
> +      pending = pending.filter(pingInfo => (TelemetrySendImpl.canSend(pingInfo) ||
> +                                            TelemetryStorage.isDeletionPing(pingInfo.id)));

Why does this still use canSend()?

@@ +729,5 @@
>            yield this._doPing(ping, ping.id, false);
>          } catch (ex) {
>            this._log.info("sendPings - ping " + ping.id + " not sent, saving to disk", ex);
> +          // Deletion pings must be saved to a special location.
> +          if (ping.type == PING_TYPE_DELETION) {

if (isDeletionPing(ping)) {
...
} else {
...

@@ +807,5 @@
>  
>      if (success && isPersisted) {
> +      if (TelemetryStorage.isDeletionPing(id)) {
> +        return TelemetryStorage.removeDeletionPing();
> +      }

I don't think we need to special-case that part - TelemetryStorage just looks it up by id and removes the ping under that path.

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +32,5 @@
>  // Compute the path of the pings archive on the first use.
>  const DATAREPORTING_DIR = "datareporting";
>  const PINGS_ARCHIVE_DIR = "archived";
>  const ABORTED_SESSION_FILE_NAME = "aborted-session-ping";
> +const DELETION_PING_FILE_NAME = "deletion-ping";

Nit: Maybe lets make it clearer what this is by calling it "pending-deletion-ping".

@@ +34,5 @@
>  const PINGS_ARCHIVE_DIR = "archived";
>  const ABORTED_SESSION_FILE_NAME = "aborted-session-ping";
> +const DELETION_PING_FILE_NAME = "deletion-ping";
> +
> +const PING_TYPE_DELETION = "deletion";

Do we need this here?

@@ +1022,5 @@
> +    // If we're saving a deletion ping as pending, we need to write it to a special
> +    // location.
> +    if (ping.type == PING_TYPE_DELETION) {
> +      return this.saveDeletionPing(ping).then(() => onSaved(gDeletionPingFilePath));
> +    }

Why do we need the changes here?

@@ +1124,5 @@
> +    // Explicitly load the deletion ping from its known path, if it's there.
> +    if (yield OS.File.exists(gDeletionPingFilePath)) {
> +      this._log.trace("_scanPendingPings - Adding pending deletion ping.");
> +      // We generate a temporary UUID and set the current date as the last modification
> +      // date for this ping.

So, you're describing "what" you're doing, while the "why" would be the interesting part.

@@ +1313,5 @@
> +        this._log.trace("removeDeletionPing - no such file");
> +      } catch (ex) {
> +        this._log.error("removeDeletionPing - error removing ping", ex)
> +      }
> +    }.bind(this)));

Task.async should take care of the bind()?

Comment 11

[Alessio Placitelli [:Dexter]]

Attachment: part 2 - Extend test coverage - v3

Comment 12

[Alessio Placitelli [:Dexter]]

(In reply to Georg Fritzsche [:gfritzsche] from comment #10)
> Comment on attachment 8631559 [details] [diff] [review]
> part 1 - Change the deletion ping logic - v2
> 
> Review of attachment 8631559 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: toolkit/components/telemetry/TelemetrySend.jsm
> @@ +398,5 @@
> >        let current = TelemetrySendImpl.getUnpersistedPings();
> >        this._log.trace("_doSendTask - pending: " + pending.length + ", current: " + current.length);
> > +      // Note that the two lists contain different data.
> > +      pending = pending.filter(pingInfo => (TelemetrySendImpl.canSend(pingInfo) ||
> > +                                            TelemetryStorage.isDeletionPing(pingInfo.id)));
> 
> Why does this still use canSend()?

I've changed that part a little, as you suggested over IRC, adding an outer |canSend| check wrapping this filter.
I think we still need to check the |current| list ping by ping, as we may have current deletion pings: we need to send them even if upload is disabled.

> @@ +807,5 @@
> >  
> >      if (success && isPersisted) {
> > +      if (TelemetryStorage.isDeletionPing(id)) {
> > +        return TelemetryStorage.removeDeletionPing();
> > +      }
> 
> I don't think we need to special-case that part - TelemetryStorage just
> looks it up by id and removes the ping under that path.

As discussed over IRC, this is needed in order to serialize the removal of the deletion ping.

> @@ +1313,5 @@
> > +        this._log.trace("removeDeletionPing - no such file");
> > +      } catch (ex) {
> > +        this._log.error("removeDeletionPing - error removing ping", ex)
> > +      }
> > +    }.bind(this)));
> 
> Task.async should take care of the bind()?

Apparently, in that context, Task.async does not handle that :(

Comment 13

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Change the deletion ping logic - v3

Comment 14

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8631653 [details] [diff] [review]
part 1 - Change the deletion ping logic - v3

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

r=me with the below addressed.

::: toolkit/components/telemetry/TelemetrySend.jsm
@@ +396,5 @@
>        // which can be send even when upload is disabled.
>        let pending = TelemetryStorage.getPendingPingList();
>        let current = TelemetrySendImpl.getUnpersistedPings();
>        this._log.trace("_doSendTask - pending: " + pending.length + ", current: " + current.length);
> +      // Note that the two lists contain different data.

"contain different kind of data. |pending| only holds ping info, while |current| holds actual ping data." ?

@@ +404,1 @@
>        current = current.filter(p => TelemetrySendImpl.canSend(p));

We can filter |current| explicitly next to |pending| above, using isDeletionPing().
We should be able to remove the ping argument from canSend() here.

@@ +730,5 @@
>            yield this._doPing(ping, ping.id, false);
>          } catch (ex) {
>            this._log.info("sendPings - ping " + ping.id + " not sent, saving to disk", ex);
> +          // Deletion pings must be saved to a special location.
> +          if (ping.type == PING_TYPE_DELETION) {

isDeletionPing(ping)?

@@ +813,1 @@
>        return TelemetryStorage.removePendingPing(id);

Hm, the way ping storage works now, we could remove the "isPersisted" juggling and just always call remove*Ping().
If its not persisted TelemetryStorage will just not do anything.

Want to file a phase 4 bug for that?

::: toolkit/components/telemetry/TelemetryStorage.jsm
@@ +1013,5 @@
> +       this._pendingPings.set(ping.id, {
> +         path: path,
> +         lastModificationDate: Policy.now().getTime(),
> +       });
> +       this._log.trace("savePendingPing - saved ping with id " + ping.id);

This section is only changed in indentation, unintentional?

@@ +1310,5 @@
> +  isDeletionPing: function(aPingId) {
> +    this._log.trace("isDeletionPing - id: " + aPingId);
> +    let pingInfo = this._pendingPings.get(aPingId);
> +    if (!pingInfo) {
> +      this._log.trace("isDeletionPing - ping not found");

This would be a bit noisy without adding real info, lets remove it.

Comment 15

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Change the deletion ping logic - v4

Comment 16

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Change the deletion ping logic - v4

Comment 17

[Alessio Placitelli [:Dexter]]

Attachment: part 1 - Change the deletion ping logic - v4

Comment 18

[Alessio Placitelli [:Dexter]]

(In reply to Georg Fritzsche [:gfritzsche] [away until july 22] from comment #14)
> @@ +404,1 @@
> >        current = current.filter(p => TelemetrySendImpl.canSend(p));
> 
> We can filter |current| explicitly next to |pending| above, using
> isDeletionPing().
> We should be able to remove the ping argument from canSend() here.

As discussed over IRC, removing the ping argument will come as a followup (bug 1187356). 

> @@ +813,1 @@
> >        return TelemetryStorage.removePendingPing(id);
> 
> Hm, the way ping storage works now, we could remove the "isPersisted"
> juggling and just always call remove*Ping().
> If its not persisted TelemetryStorage will just not do anything.
> 
> Want to file a phase 4 bug for that?

Filed bug 1187301.

Comment 19

[Alessio Placitelli [:Dexter]]

Try push: https://treeherder.mozilla.org/#/jobs?repo=try&revision=2b0c0d3db0c0

Comment 20

[Pulsebot]

https://hg.mozilla.org/integration/fx-team/rev/b44452a6fdac
https://hg.mozilla.org/integration/fx-team/rev/048f102c4dd8

Comment 21

[Alessio Placitelli [:Dexter]]

Treeherder  https://treeherder.mozilla.org/#/jobs?repo=fx-team&revision=048f102c4dd8

Comment 22

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/b44452a6fdac
https://hg.mozilla.org/mozilla-central/rev/048f102c4dd8

Comment 23

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8638583 [details] [diff] [review]
part 1 - Change the deletion ping logic - v4

Approval Request Comment
[Feature/regressing bug #]:
Telemetry Unification
[User impact if declined]:
This is a smaller fix for how we handle outgoing user data deletion requests,
which important for respecting user choice.
It is part of a mostly fixup & diagnostic uplift batch for 41: http://bit.ly/1LYhA16
[Describe test coverage new/current, TreeHerder]:
We have automated test-coverage, it baked on Nightly, we are tracking metrics for this via Telemetry.
[Risks and why]:
Low-risk, we haven't seen anything crop up on Nightly here. There is a small related issue here, bug 1191336, but not triggered by this exact bug AFAICT and it's a corner-cases without any actual bad results.
[String/UUID change made/needed]:
None.

Comment 24

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8631437 [details] [diff] [review]
part 2 - Extend test coverage - v2

Approval Request Comment
[Feature/regressing bug #]:
Telemetry Unification
[User impact if declined]:
This is a smaller fix for how we handle outgoing user data deletion requests,
which important for respecting user choice.
It is part of a mostly fixup & diagnostic uplift batch for 41: http://bit.ly/1LYhA16
[Describe test coverage new/current, TreeHerder]:
We have automated test-coverage, it baked on Nightly, we are tracking metrics for this via Telemetry.
[Risks and why]:
Low-risk, we haven't seen anything crop up on Nightly here. There is a small related issue here, bug 1191336, but not triggered by this exact bug AFAICT and it's a corner-cases without any actual bad results.
[String/UUID change made/needed]:
None.

Comment 25

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8638583 [details] [diff] [review]
part 1 - Change the deletion ping logic - v4

[Triage Comment]

Patch has been in m-c since 7/27 and telemetry code should not be disruptive. Approved for uplift to Beta41

Comment 26

[Georg Fritzsche [:gfritzsche]]

https://hg.mozilla.org/releases/mozilla-beta/rev/024ace4a8804
https://hg.mozilla.org/releases/mozilla-beta/rev/a4c95aa0bd9e

Comment 27

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8631437 [details] [diff] [review]
part 2 - Extend test coverage - v2

Just like with beta!

Comment 28

[Georg Fritzsche [:gfritzsche]]

This already was on 42 (which is Aurora now).
The beta approval above just missed approving the test patch too - i hadn't noticed that and already landed it, so there is no more work to do.

Comment 29

[Georg Fritzsche [:gfritzsche]]

Comment on attachment 8631437 [details] [diff] [review]
part 2 - Extend test coverage - v2

Approval Request Comment

Requesting per the above comment to have the flags match what we already landed.

Comment 30

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8631437 [details] [diff] [review]
part 2 - Extend test coverage - v2

Test only changed, Beta+