Bug 1350470 - Add telemetry to diagnose why the SetConnectivity IPC message is so slow to run r=billm
MozReview-Commit-ID: Il4TGyYmsGI
--- a/browser/base/content/browser.js
+++ b/browser/base/content/browser.js
@@ -6145,22 +6145,29 @@ var BrowserOffline = {
return;
}
ioService.offline = !ioService.offline;
},
// nsIObserver
observe(aSubject, aTopic, aState) {
+ let time = Date.now();
if (aTopic != "network:offline-status-changed")
return;
// This notification is also received because of a loss in connectivity,
// which we ignore by updating the UI to the current value of io.offline
this._updateOfflineUI(Services.io.offline);
+
+ if (Services.appinfo.processType == Services.appinfo.PROCESS_TYPE_CONTENT) {
+ Services.telemetry
+ .getKeyedHistogramById("NETWORK_SENDCONNECTIVITY_TIME_MS")
+ .add("browser.js", Date.now() - time);
+ }
},
// BrowserOffline Implementation Methods
_canGoOffline() {
try {
var cancelGoOffline = Cc["@mozilla.org/supports-PRBool;1"].createInstance(Ci.nsISupportsPRBool);
Services.obs.notifyObservers(cancelGoOffline, "offline-requested", null);
--- a/netwerk/base/nsIOService.cpp
+++ b/netwerk/base/nsIOService.cpp
@@ -1158,22 +1158,26 @@ nsIOService::SetConnectivityInternal(boo
}
mConnectivity = aConnectivity;
// This is used for PR_Connect PR_Close telemetry so it is important that
// we have statistic about network change event even if we are offline.
mLastConnectivityChange = PR_IntervalNow();
if (mCaptivePortalService) {
+ mozilla::TimeStamp time = TimeStamp::Now();
if (aConnectivity && !xpc::AreNonLocalConnectionsDisabled()) {
// This will also trigger a captive portal check for the new network
static_cast<CaptivePortalService*>(mCaptivePortalService.get())->Start();
} else {
static_cast<CaptivePortalService*>(mCaptivePortalService.get())->Stop();
}
+ Telemetry::Accumulate(Telemetry::NETWORK_SENDCONNECTIVITY_TIME_MS,
+ NS_LITERAL_CSTRING("nsIOService.cpp"),
+ static_cast<uint32_t>((TimeStamp::Now() - time).ToMilliseconds()));
}
nsCOMPtr<nsIObserverService> observerService = services::GetObserverService();
if (!observerService) {
return NS_OK;
}
// This notification sends the connectivity to the child processes
if (XRE_IsParentProcess()) {
--- a/services/sync/modules/policies.js
+++ b/services/sync/modules/policies.js
@@ -136,19 +136,25 @@ SyncScheduler.prototype = {
switch (topic) {
case "weave:engine:score:updated":
if (Status.login == LOGIN_SUCCEEDED) {
Utils.namedTimer(this.calculateScore, SCORE_UPDATE_DELAY, this,
"_scoreTimer");
}
break;
case "network:offline-status-changed":
+ let time = Date.now();
// Whether online or offline, we'll reschedule syncs
this._log.trace("Network offline status change: " + data);
this.checkSyncStatus();
+ if (Services.appinfo.processType == Services.appinfo.PROCESS_TYPE_CONTENT) {
+ Services.telemetry
+ .getKeyedHistogramById("NETWORK_SENDCONNECTIVITY_TIME_MS")
+ .add("policies.js", Date.now() - time);
+ }
break;
case "weave:service:sync:start":
// Clear out any potentially pending syncs now that we're syncing
this.clearSyncTriggers();
// reset backoff info, if the server tells us to continue backing off,
// we'll handle that later
Status.resetBackoff();
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -3756,16 +3756,26 @@
"kind": "linear",
"low": 50,
"high": 1000,
"n_buckets": 10,
"description": "Result of nsSocketTransportService::ProbeMaxCount()",
"bug_numbers": [1260218],
"alert_emails": ["necko@mozilla.com"]
},
+ "NETWORK_SENDCONNECTIVITY_TIME_MS": {
+ "alert_emails": ["vgosu@mozilla.com"],
+ "bug_numbers": [1350470],
+ "expires_in_version": "56",
+ "kind": "exponential",
+ "high": 500,
+ "n_buckets": 20,
+ "keyed": true,
+ "description": "Measures the number of milliseconds we spend running code triggered by SendSetConnectivity. This probe is keyed on the name of the file running the code."
+ },
"FIND_PLUGINS": {
"alert_emails": ["perf-telemetry-alerts@mozilla.com"],
"expires_in_version": "never",
"kind": "exponential",
"high": 3000,
"n_buckets": 10,
"description": "Time spent scanning filesystem for plugins (ms)"
},
--- a/toolkit/mozapps/extensions/internal/XPIProvider.jsm
+++ b/toolkit/mozapps/extensions/internal/XPIProvider.jsm
@@ -6227,18 +6227,24 @@ class DownloadAddonInstall extends Addon
this.channel.cancel(Cr.NS_BINDING_ABORTED);
}
} else {
super.cancel();
}
}
observe(aSubject, aTopic, aData) {
+ let time = Date.now();
// Network is going offline
this.cancel();
+ if (Services.appinfo.processType == Services.appinfo.PROCESS_TYPE_CONTENT) {
+ Services.telemetry
+ .getKeyedHistogramById("NETWORK_SENDCONNECTIVITY_TIME_MS")
+ .add("XPIProvider.jsm", Date.now() - time);
+ }
}
/**
* Starts downloading the add-on's XPI file.
*/
startDownload() {
this.state = AddonManager.STATE_DOWNLOADING;
if (!AddonManagerPrivate.callInstallListeners("onDownloadStarted",
--- a/toolkit/mozapps/update/nsUpdateService.js
+++ b/toolkit/mozapps/update/nsUpdateService.js
@@ -1906,17 +1906,23 @@ UpdateService.prototype = {
APPID_TO_TOPIC[Services.appinfo.ID]);
}
// intentional fallthrough
case "test-post-update-processing":
// Clean up any extant updates
this._postUpdateProcessing();
break;
case "network:offline-status-changed":
+ let time = Date.now();
this._offlineStatusChanged(data);
+ if (Services.appinfo.processType == Services.appinfo.PROCESS_TYPE_CONTENT) {
+ Services.telemetry
+ .getKeyedHistogramById("NETWORK_SENDCONNECTIVITY_TIME_MS")
+ .add("nsUpdateService.js", Date.now() - time);
+ }
break;
case "nsPref:changed":
if (data == PREF_APP_UPDATE_LOG) {
gLogEnabled = getPref("getBoolPref", PREF_APP_UPDATE_LOG, false);
}
break;
case "profile-change-net-teardown": // fall thru
case "xpcom-shutdown":