1545365 - Investigate negative durations for pre-account ping

Status: RESOLVED FIXED

(Toolkit :: Telemetry, task, P1)

Description

[Jan-Erik Rediger [:janerik]]

During validation of the early ecosystem ping ("pre-account" ping), I noted that we see negative durations in the pings.

The duration should be the time between 2 pings (or since session start). It should therefore never be negative. It is though.

We should try to find out what is happening and determine if it is a bug in our implementation of time accounting, invalid values we get from the OS or otherwise bogus data.

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

Bugbug thinks this bug is a task, but please change it back in case of error.

Comment 2

[Jan-Erik Rediger [:janerik]]

One thing to note: so far occurring on Windows only.

Comment 3

[Jan-Erik Rediger [:janerik]]

For the lack of any good answer, I'll at least document the current state:

That's the duration calculation in EcosystemPing.jsm.

let now = Policy.monotonicNow();
let duration = Math.round((now - this._lastSendTime) / 1000);
this._lastSendTime = now;

this._lastSendtime defaults to 0 at initialization.
monotonicNow is a bit misnamed and is a monotonic increasing count of milliseconds since process start.

monotonicNow is implemented as TimeStamp::NowLoRes() - TimeStamp::ProcessCreation() (see the implementation here).

For the duration becoming negative (and wee see values like -9466577789) one of these has to happen:

• We get a large now and store it into _lastSendTime. In the next round we get a small now and subtract the large value, resulting in a negative value
• We get a negative now and store it into _lastSendTime. In the next round we get a large now and subtract the large value, resulting in an even larger negative value

Possible next steps:

• We could do an analysis on the main ping and its session lengths to check if we see this or wait until we have IDs in the pre-account ping
• We could report lastSendTime and now as raw values in the ping to see what's happening

Comment 4

[Jan-Erik Rediger [:janerik]]

Attachment: Bug 1545365 - Track old and new send time to investigate negativ durations

Comment 5

[Jan-Erik Rediger [:janerik]]

Attaching a patch to get the old and new timestamps, so we might take a look and check what values we are actually seeing.
Next step would be to find someone responsible for TimeStamp and get them to help.

Comment 6

[Jan-Erik Rediger [:janerik]]

Attachment: data-review-request.txt

Comment 7

[Chris H-C :chutten]

Comment on attachment 9060898 [details]
data-review-request.txt

DATA COLLECTION REVIEW RESPONSE:

    Is there or will there be documentation that describes the schema for the ultimate data set available publicly, complete and accurate?

Yes. This collection is Telemetry so is documented in its definitions file [Scalars.yaml](https://hg.mozilla.org/mozilla-central/file/tip/toolkit/components/telemetry/Scalars.yaml) and the [Probe Dictionary](https://telemetry.mozilla.org/probe-dictionary/).

    Is there a control mechanism that allows the user to turn the data collection on and off?

Yes. This collection is Telemetry so can be controlled through Firefox's Preferences.

    If the request is for permanent data collection, is there someone who will monitor the data over time?

No. This collection will expire in Firefox 73.

    Using the category system of data types on the Mozilla wiki, what collection type of data do the requested measurements fall under?

Category 1, Technical.

    Is the data collection request for default-on or default-off?

Default on for pre-release channels only. (The code collecting this data is additionally restricted to only run on Nightly)

    Does the instrumentation include the addition of any new identifiers?

No.

    Is the data collection covered by the existing Firefox privacy notice?

Yes.

    Does there need to be a check-in in the future to determine whether to renew the data?

Yes. :janerik is responsible for renewing or removing the collection before it expires in Firefox 73.

---
Result: datareview+

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c15167713985
Track old and new send time to investigate negativ durations r=chutten

Comment 9

[Razvan Maries]

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