Bug 1652613 - correct hang duration event measuring for slow script hangs, r=mccr8
authorGijs Kruitbosch <gijskruitbosch@gmail.com>
Fri, 24 Jul 2020 00:01:53 +0000
changeset 541856 77c85c1ef3f00843f7daffd43591df738e9aedaa
parent 541855 35d658861d6eb9ab153137480aef105db20fbdd6
child 541857 6e90fed2ff8ac39ca8af803c1906c634682e53ae
push id37633
push userccoroiu@mozilla.com
push dateFri, 24 Jul 2020 09:32:06 +0000
treeherdermozilla-central@141543043270 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersmccr8
bugs1652613
milestone80.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1652613 - correct hang duration event measuring for slow script hangs, r=mccr8 The hang duration numbers were bogus. It seems that the code in XPCJSContext::InterruptCallback establishes the duration by continuously comparing 'now' with the last timestamp in mSlowScriptCheckpoint - but it stops writing to the latter after the second time the interrupt callback fires. So if the slow script runtime limit is N, the timer fires every N/2 seconds, but we increment the duration by N the third time it fires, 1.5N the fourth time, 2N the fifth time, etc. This patch fixes the issue by always resetting the timestamp against which we compare when establishing the duration and incrementing mSlowScriptActualWait. Differential Revision: https://phabricator.services.mozilla.com/D84660
js/xpconnect/src/XPCJSContext.cpp
--- a/js/xpconnect/src/XPCJSContext.cpp
+++ b/js/xpconnect/src/XPCJSContext.cpp
@@ -614,17 +614,18 @@ bool XPCJSContext::InterruptCallback(JSC
   // has finished bootstrapping. Avoid crashing in nsContentUtils below.
   if (!nsContentUtils::IsInitialized()) {
     return true;
   }
 
   // This is at least the second interrupt callback we've received since
   // returning to the event loop. See how long it's been, and what the limit
   // is.
-  TimeDuration duration = TimeStamp::NowLoRes() - self->mSlowScriptCheckpoint;
+  TimeStamp now = TimeStamp::NowLoRes();
+  TimeDuration duration = now - self->mSlowScriptCheckpoint;
   int32_t limit;
 
   nsString addonId;
   const char* prefName;
 
   auto principal = BasePrincipal::Cast(nsContentUtils::SubjectPrincipal(cx));
   bool chrome = principal->Is<SystemPrincipal>();
   if (chrome) {
@@ -639,23 +640,23 @@ bool XPCJSContext::InterruptCallback(JSC
     limit = Preferences::GetInt(prefName, 10);
   }
 
   // If there's no limit, or we're within the limit, let it go.
   if (limit == 0 || duration.ToSeconds() < limit / 2.0) {
     return true;
   }
 
+  self->mSlowScriptCheckpoint = now;
   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.
   if (!self->mSlowScriptSecondHalf) {
-    self->mSlowScriptCheckpoint = TimeStamp::NowLoRes();
     self->mSlowScriptSecondHalf = true;
     return true;
   }
 
   //
   // This has gone on long enough! Time to take action. ;-)
   //
 
@@ -730,17 +731,17 @@ bool XPCJSContext::InterruptCallback(JSC
       return false;
     }
 
     obs->NotifyObservers(supports, "kill-content-script-sandbox", nullptr);
     return false;
   }
 
   // The user chose to continue the script. Reset the timer, and disable this
-  // machinery with a pref of the user opted out of future slow-script dialogs.
+  // machinery with a pref if the user opted out of future slow-script dialogs.
   if (response != nsGlobalWindowInner::ContinueSlowScriptAndKeepNotifying) {
     self->mSlowScriptCheckpoint = TimeStamp::NowLoRes();
   }
 
   if (response == nsGlobalWindowInner::AlwaysContinueSlowScript) {
     Preferences::SetInt(prefName, 0);
   }