Closed Bug 1183192 Opened 9 years ago Closed 9 years ago

AsyncShutdown times out due to TelemetryController

Categories

(Toolkit :: Telemetry, defect, P1)

defect
Points:
1

Tracking

()

RESOLVED WORKSFORME
Iteration:
42.3 - Aug 10
Tracking Status
firefox42 --- affected

People

(Reporter: Dexter, Unassigned)

References

Details

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

The crash in [1] should be investigated: it could be either due to us failing to cancel outgoing ping requests (in |TelemetrySend._cancelOutgoingRequests|) or some ping gets submitted and races to trigger a sendtask again.

{
  "phase":"profile-before-change2",
  "conditions":[
    {
      "name":"TelemetryController: shutting down",
      "state":{
        "initialized":true,
        "initStarted":true,
        "haveDelayedInitTask":false,
        "shutdownBarrier":"Not started",
        "connectionsBarrier":"Not started",
        "sendModule":{
          "sendingEnabled":false,
          "pendingPingRequestCount":2,
          "pendingPingActivityCount":1,
          "unpersistedPingCount":0,
          "persistedPingCount":2,
          "schedulerState":{
            "shutdown":true,
            "hasSendTask":true,
            "sendsFailed":false,
            "sendTaskState":"wait on ping sends",
            "backoffDelay":60000
          }
        }
      },
      "filename":"resource://gre/modules/TelemetryController.jsm",
      "lineNumber":687,
      "stack":[
        "resource://gre/modules/TelemetryController.jsm:setupTelemetry:687",
        "resource://gre/modules/TelemetryController.jsm:Impl.observe:780",
        "resource://gre/modules/TelemetryController.jsm:this.TelemetryController<.observe:167",
        "resource://gre/components/TelemetryStartup.js:TelemetryStartup.prototype.observe:30",
        "null:null:0"
      ]
    }
  ]
}



[1] - https://crash-stats.mozilla.com/report/index/27da41a1-63c7-43dc-9687-060322150711
Blocks: 1120356
Whiteboard: [b5] [unifiedTelemetry] [uplift2]
This also seems related to bug 1173961.

Also, TelemetrySend [1] seems to use |task.then(clear, clear)| to clear the sending task when done. As we found out in a recent bug, this pattern proved to be ineffective. We should probably do as done in [2].

[1] - http://mxr.mozilla.org/mozilla-central/source/toolkit/components/telemetry/TelemetrySend.jsm#374
[2] - https://hg.mozilla.org/mozilla-central/annotate/e7e69cc8c07b/toolkit/components/telemetry/TelemetryStorage.jsm#l832
Note that we can find the AsyncShutdown timeout crashes here:
https://crash-stats.mozilla.com/search/?product=Firefox&release_channel=nightly&async_shutdown_timeout=sendModule&version=42.0a1&_facets=signature&_columns=date&_columns=signature&_columns=product&_columns=version&_columns=build_id&_columns=platform#crash-reports

Only 4 related to Telemetry shutdown showed up so far since bug 1181553 landed.
Of those, only one has an active send task - so far this doesn't seem to be a big issue.
moving to new milestone - [40b7], P2
Priority: -- → P2
Whiteboard: [b5] [unifiedTelemetry] [uplift2] → [40b7] [unifiedTelemetry] [uplift2]
Whiteboard: [40b7] [unifiedTelemetry] [uplift2] → [40b7] [unifiedTelemetry] [uplift3]
There were no reports in the last week with an active send task on Nightly, lets keep watching this for a bit.
Whiteboard: [40b7] [unifiedTelemetry] [uplift3] → [40b7] [unifiedTelemetry]
Iteration: --- → 42.3 - Aug 10
Whiteboard: [40b7] [unifiedTelemetry] → [unifiedTelemetry]
Blocks: 1122482
No longer blocks: 1120356
We should re-check if this is still an issue and, if that's the case, its volume.
Points: --- → 1
Priority: P2 → P1
Whiteboard: [unifiedTelemetry] → [unifiedTelemetry][measurement:client]
There are <=5 of these on any channel.
I'm willing to call these odd outliers until further evidence arrives.
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.