Bug 1271978 - Record js slow script notification delay for content in telemetry. r=billm

MozReview-Commit-ID: 9RUrqfwn7Wh

js/xpconnect/src/XPCJSRuntime.cpp

@@ -1365,6 +1365,8 @@ XPCJSRuntime::InterruptCallback(JSContext* cx)
     if (self->mSlowScriptCheckpoint.IsNull()) {
         self->mSlowScriptCheckpoint = TimeStamp::NowLoRes();
         self->mSlowScriptSecondHalf = false;
+        self->mSlowScriptActualWait = mozilla::TimeDuration();
+        self->mTimeoutAccumulated = false;
         return true;
     }
 
@@ -1386,6 +1388,8 @@ XPCJSRuntime::InterruptCallback(JSContext* cx)
     if (limit == 0 || duration.ToSeconds() < limit / 2.0)
         return true;
 
+    self->mSlowScriptActualWait += duration;
+
     // In order to guard against time changes or laptops going to sleep, we
     // don't trigger the slow script warning until (limit/2) seconds have
     // elapsed twice.
@@ -1431,6 +1435,13 @@ XPCJSRuntime::InterruptCallback(JSContext* cx)
         return false;
     }
 
+    // Accumulate slow script invokation delay.
+    if (!chrome && !self->mTimeoutAccumulated) {
+      uint32_t delay = uint32_t(self->mSlowScriptActualWait.ToMilliseconds() - (limit * 1000.0));
+      Telemetry::Accumulate(Telemetry::SLOW_SCRIPT_NOTIFY_DELAY, delay);
+      self->mTimeoutAccumulated = true;
+    }
+
     // Show the prompt to the user, and kill if requested.
     nsGlobalWindow::SlowScriptResponse response = win->ShowSlowScriptDialog();
     if (response == nsGlobalWindow::KillSlowScript)
@@ -3354,7 +3365,8 @@ XPCJSRuntime::XPCJSRuntime()
    mObjectHolderRoots(nullptr),
    mWatchdogManager(new WatchdogManager(this)),
    mAsyncSnowWhiteFreer(new AsyncFreeSnowWhite()),
-   mSlowScriptSecondHalf(false)
+   mSlowScriptSecondHalf(false),
+   mTimeoutAccumulated(false)
 {
 }
 
@@ -3689,6 +3701,8 @@ XPCJSRuntime::BeforeProcessTask(bool aMightBlock)
     // Start the slow script timer.
     mSlowScriptCheckpoint = mozilla::TimeStamp::NowLoRes();
     mSlowScriptSecondHalf = false;
+    mSlowScriptActualWait = mozilla::TimeDuration();
+    mTimeoutAccumulated = false;
 
     // As we may be entering a nested event loop, we need to
     // cancel any ongoing performance measurement.

js/xpconnect/src/xpcprivate.h

@@ -665,6 +665,9 @@ private:
     // (whichever comes later). We use it to determine whether the interrupt
     // callback needs to do anything.
     mozilla::TimeStamp mSlowScriptCheckpoint;
+    // Accumulates total time we actually waited for telemetry
+    mozilla::TimeDuration mSlowScriptActualWait;
+    bool mTimeoutAccumulated;
 
     friend class Watchdog;
     friend class AutoLockWatchdog;

toolkit/components/telemetry/Histograms.json

@@ -9381,6 +9381,15 @@
     "bug_numbers": [1251667],
     "description": "The number of pages that trigger slow script notices"
   },
+  "SLOW_SCRIPT_NOTIFY_DELAY": {
+    "alert_emails": ["perf-telemetry-alerts@mozilla.com"],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 60000,
+    "n_buckets": 50,
+    "bug_numbers": [1271978],
+    "description": "The difference between the js slow script timeout for content set in prefs and the actual time we waited before displaying the notification (msec)."
+  },
   "PLUGIN_HANG_NOTICE_COUNT": {
     "alert_emails": ["perf-telemetry-alerts@mozilla.com"],
     "expires_in_version": "never",