818274 - [Shutdown] Telemetry takes ~10ms on shutdown

Status: RESOLVED WORKSFORME

(Toolkit :: Telemetry, defect)

Description

[Benoit Girard (:BenWa)]

Startup report:
https://people.mozilla.com/~bgirard/startup_report/report.html#TelemetryPing.js

This currently list 10 shutdown profiles sorted from longest to shortest time spent in TelemetryPing.js recorded on my system. Click on the profile will preview the profile + highlight the function.

Comment 1

[Benoit Girard (:BenWa)]

This will only occur if we have telemetry on but it's pretty slow and causes main thread IO:
http://mxr.mozilla.org/mozilla-central/ident?i=savePingToFile

Comment 2

[Lawrence Mandel [:lmandel] (use needinfo)]

Benoit - In discussing this issue with Nathan, he raised a good question about the importance of this bug given that the amount of time spent on Telemetry at shutdown seems to be an order of magnitude less than other large offenders. Can you comment on the relative importance of fixing this bug for the shutdown project so that we can properly prioritize it wrt other Telemetry work?

Comment 3

[Benoit Girard (:BenWa)]

The average shutdown is about 1 second and decreasing part of this shutdown project. It will not be fixed by exit(0) project. It's big enough to care about since it accounts for about 1% of the time and growing. I think the real question is how big is the telemetry population? If it's small then we have bigger shutdown problems.

Comment 4

[Lawrence Mandel [:lmandel] (use needinfo)]

(In reply to Benoit Girard (:BenWa) from comment #3)
> The average shutdown is about 1 second and decreasing part of this shutdown
> project. It will not be fixed by exit(0) project. It's big enough to care
> about since it accounts for about 1% of the time and growing. I think the
> real question is how big is the telemetry population? If it's small then we
> have bigger shutdown problems.

Current Telemetry population measurements show <1% on Release and Beta. Aurora and Nightly should be ~100% now.

Nathan - Can you share your thoughts on how to remove/reduce the Telemetry shutdown time?

Comment 5

[Nathan Froyd [:froydnj]]

Possibilities, in no particular order:

- Make the writes async.  While we might have to wait for the write to complete (and thus async writes would be no better than sync writes in such a scenario), it's also possible that we'd overlap the writing (happening off-thread) with other shutdown work (happening on the main thread).  And that would be a good thing.

- Port writes to OS.File.  I don't know whether OS.File is actually faster than what we have now, though.

- gzip the telemetry data before sending it to disk.  Here we're betting that the time spent compressing would be compensated for by spending less time doing disk I/O.

- Other things that I haven't thought of in a few minutes of consideration.

Comment 6

[Benoit Girard (:BenWa)]

(In reply to Lawrence Mandel [:lmandel] from comment #4)
> Current Telemetry population measurements show <1% on Release and Beta.

Given <1% I vote we keep this bug open but don't staff it for now.

Comment 7

[Vladan Djeric (:vladan)]

Also see bug 838889, Marco Castelluccio refactored the saving of Telemetry pings to use OS.File

Comment 8

[Alessio Placitelli [:Dexter]]

We heavily refactored the Telemetry core and TelemetryPing does not exist anymore. Additionally, we measured the shutdown duration for 57 and it looks like this is no longer relevant. See bug 1343282.