Bug 1580883 - Use TimeDuration for CycleCollectorStats members r=mccr8
authorJon Coppeard <jcoppeard@mozilla.com>
Wed, 18 Sep 2019 12:48:46 +0000
changeset 493792 94c4e9a25f1964c785e5153407b8c4a294ce2724
parent 493791 c23405648344eb475592ff35aa6f47163565edbf
child 493793 c44d5c2906e237cfc37c11bc4bcd0433a0caf12f
push id36589
push usernerli@mozilla.com
push dateWed, 18 Sep 2019 21:49:27 +0000
treeherdermozilla-central@21aff209f5a9 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersmccr8
bugs1580883
milestone71.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 1580883 - Use TimeDuration for CycleCollectorStats members r=mccr8 Differential Revision: https://phabricator.services.mozilla.com/D45697
dom/base/nsJSEnvironment.cpp
--- a/dom/base/nsJSEnvironment.cpp
+++ b/dom/base/nsJSEnvironment.cpp
@@ -1233,48 +1233,28 @@ static void FireForgetSkippable(uint32_t
 }
 
 MOZ_ALWAYS_INLINE
 static TimeDuration TimeBetween(TimeStamp start, TimeStamp end) {
   MOZ_ASSERT(end >= start);
   return end - start;
 }
 
-MOZ_ALWAYS_INLINE
-static uint32_t TimeBetweenInMillis(TimeStamp start, TimeStamp end) {
-  return uint32_t(TimeBetween(start, end).ToMilliseconds());
-}
-
 static TimeDuration TimeUntilNow(TimeStamp start) {
   if (start.IsNull()) {
     return TimeDuration();
   }
   return TimeBetween(start, TimeStamp::Now());
 }
 
-MOZ_ALWAYS_INLINE
-static uint32_t TimeUntilNowInMillis(TimeStamp start) {
-  return uint32_t(TimeUntilNow(start).ToMilliseconds());
-}
-
 struct CycleCollectorStats {
-  constexpr CycleCollectorStats()
-      : mMaxGCDuration(0),
-        mRanSyncForgetSkippable(false),
-        mSuspected(0),
-        mMaxSkippableDuration(0),
-        mMaxSliceTime(0),
-        mMaxSliceTimeSinceClear(0),
-        mTotalSliceTime(0),
-        mAnyLockedOut(false),
-        mFile(nullptr) {}
+  constexpr CycleCollectorStats() = default;
 
   void Init() {
     Clear();
-    mMaxSliceTimeSinceClear = 0;
 
     char* env = getenv("MOZ_CCTIMER");
     if (!env) {
       return;
     }
     if (strcmp(env, "none") == 0) {
       mFile = nullptr;
     } else if (strcmp(env, "stdout") == 0) {
@@ -1287,28 +1267,18 @@ struct CycleCollectorStats {
         MOZ_CRASH("Failed to open MOZ_CCTIMER log file.");
       }
     }
   }
 
   void Clear() {
     if (mFile && mFile != stdout && mFile != stderr) {
       fclose(mFile);
-      mFile = nullptr;
     }
-    mBeginSliceTime = TimeStamp();
-    mEndSliceTime = TimeStamp();
-    mBeginTime = TimeStamp();
-    mMaxGCDuration = 0;
-    mRanSyncForgetSkippable = false;
-    mSuspected = 0;
-    mMaxSkippableDuration = 0;
-    mMaxSliceTime = 0;
-    mTotalSliceTime = 0;
-    mAnyLockedOut = false;
+    *this = CycleCollectorStats();
   }
 
   void PrepareForCycleCollectionSlice(TimeStamp aDeadline = TimeStamp());
 
   void FinishCycleCollectionSlice() {
     if (mBeginSliceTime.IsNull()) {
       // We already called this method from EndCycleCollectionCallback for this
       // slice.
@@ -1330,17 +1300,17 @@ struct CycleCollectorStats {
       }
 
       uint32_t percent =
           uint32_t(idleDuration.ToSeconds() / duration.ToSeconds() * 100);
       Telemetry::Accumulate(Telemetry::CYCLE_COLLECTOR_SLICE_DURING_IDLE,
                             percent);
     }
 
-    uint32_t sliceTime = TimeBetweenInMillis(mBeginSliceTime, mEndSliceTime);
+    TimeDuration sliceTime = TimeBetween(mBeginSliceTime, mEndSliceTime);
     mMaxSliceTime = std::max(mMaxSliceTime, sliceTime);
     mMaxSliceTimeSinceClear = std::max(mMaxSliceTimeSinceClear, sliceTime);
     mTotalSliceTime += sliceTime;
     mBeginSliceTime = TimeStamp();
   }
 
   void RunForgetSkippable();
 
@@ -1349,76 +1319,76 @@ struct CycleCollectorStats {
 
   // Time the previous slice of the current CC ended.
   TimeStamp mEndSliceTime;
 
   // Time the current cycle collection began.
   TimeStamp mBeginTime;
 
   // The longest GC finishing duration for any slice of the current CC.
-  uint32_t mMaxGCDuration;
+  TimeDuration mMaxGCDuration;
 
   // True if we ran sync forget skippable in any slice of the current CC.
-  bool mRanSyncForgetSkippable;
+  bool mRanSyncForgetSkippable = false;
 
   // Number of suspected objects at the start of the current CC.
-  uint32_t mSuspected;
+  uint32_t mSuspected = 0;
 
   // The longest duration spent on sync forget skippable in any slice of the
   // current CC.
-  uint32_t mMaxSkippableDuration;
+  TimeDuration mMaxSkippableDuration;
 
   // The longest pause of any slice in the current CC.
-  uint32_t mMaxSliceTime;
+  TimeDuration mMaxSliceTime;
 
   // The longest slice time since ClearMaxCCSliceTime() was called.
-  uint32_t mMaxSliceTimeSinceClear;
+  TimeDuration mMaxSliceTimeSinceClear;
 
   // The total amount of time spent actually running the current CC.
-  uint32_t mTotalSliceTime;
+  TimeDuration mTotalSliceTime;
 
   // True if we were locked out by the GC in any slice of the current CC.
-  bool mAnyLockedOut;
+  bool mAnyLockedOut = false;
 
   // A file to dump CC activity to; set by MOZ_CCTIMER environment variable.
-  FILE* mFile;
+  FILE* mFile = nullptr;
 
   // In case CC slice was triggered during idle time, set to the end of the idle
   // period.
   TimeStamp mIdleDeadline;
 };
 
 CycleCollectorStats gCCStats;
 
 void CycleCollectorStats::PrepareForCycleCollectionSlice(TimeStamp aDeadline) {
   mBeginSliceTime = TimeStamp::Now();
   mIdleDeadline = aDeadline;
 
   // Before we begin the cycle collection, make sure there is no active GC.
   if (sCCLockedOut) {
     mAnyLockedOut = true;
     FinishAnyIncrementalGC();
-    uint32_t gcTime = TimeBetweenInMillis(mBeginSliceTime, TimeStamp::Now());
+    TimeDuration gcTime = TimeUntilNow(mBeginSliceTime);
     mMaxGCDuration = std::max(mMaxGCDuration, gcTime);
   }
 }
 
 void CycleCollectorStats::RunForgetSkippable() {
   // Run forgetSkippable synchronously to reduce the size of the CC graph. This
   // is particularly useful if we recently finished a GC.
   TimeStamp beginForgetSkippable = TimeStamp::Now();
   bool ranSyncForgetSkippable = false;
   while (sCleanupsSinceLastGC < kMajorForgetSkippableCalls) {
     FireForgetSkippable(nsCycleCollector_suspectedCount(), false, TimeStamp());
     ranSyncForgetSkippable = true;
   }
 
   if (ranSyncForgetSkippable) {
-    mMaxSkippableDuration = std::max(
-        mMaxSkippableDuration, TimeUntilNowInMillis(beginForgetSkippable));
+    mMaxSkippableDuration =
+        std::max(mMaxSkippableDuration, TimeUntilNow(beginForgetSkippable));
     mRanSyncForgetSkippable = true;
   }
 }
 
 // static
 void nsJSContext::CycleCollectNow(nsICycleCollectorListener* aListener) {
   if (!NS_IsMainThread()) {
     return;
@@ -1503,21 +1473,21 @@ void nsJSContext::RunCycleCollectorWorkS
 
   js::SliceBudget budget = js::SliceBudget(js::WorkBudget(aWorkBudget));
   nsCycleCollector_collectSlice(budget);
 
   gCCStats.FinishCycleCollectionSlice();
 }
 
 void nsJSContext::ClearMaxCCSliceTime() {
-  gCCStats.mMaxSliceTimeSinceClear = 0;
+  gCCStats.mMaxSliceTimeSinceClear = TimeDuration();
 }
 
 uint32_t nsJSContext::GetMaxCCSliceTimeSinceClear() {
-  return gCCStats.mMaxSliceTimeSinceClear;
+  return gCCStats.mMaxSliceTimeSinceClear.ToMilliseconds();
 }
 
 static bool ICCRunnerFired(TimeStamp aDeadline) {
   if (sDidShutdown) {
     return false;
   }
 
   // Ignore ICC timer fires during IGC. Running ICC during an IGC will cause us
@@ -1598,17 +1568,17 @@ void nsJSContext::EndCycleCollectionCall
   // Log information about the CC via telemetry, JSON and the console.
   Telemetry::Accumulate(Telemetry::CYCLE_COLLECTOR_FINISH_IGC,
                         gCCStats.mAnyLockedOut);
   Telemetry::Accumulate(Telemetry::CYCLE_COLLECTOR_SYNC_SKIPPABLE,
                         gCCStats.mRanSyncForgetSkippable);
   Telemetry::Accumulate(Telemetry::CYCLE_COLLECTOR_FULL,
                         ccNowDuration.ToMilliseconds());
   Telemetry::Accumulate(Telemetry::CYCLE_COLLECTOR_MAX_PAUSE,
-                        gCCStats.mMaxSliceTime);
+                        gCCStats.mMaxSliceTime.ToMilliseconds());
 
   if (!sLastCCEndTime.IsNull()) {
     TimeDuration timeBetween = TimeBetween(sLastCCEndTime, gCCStats.mBeginTime);
     Telemetry::Accumulate(Telemetry::CYCLE_COLLECTOR_TIME_BETWEEN,
                           timeBetween.ToSeconds());
   }
   sLastCCEndTime = endCCTimeStamp;
 
@@ -1626,55 +1596,56 @@ void nsJSContext::EndCycleCollectionCall
     }
 
     nsCString gcMsg;
     if (aResults.mForcedGC) {
       gcMsg.AssignLiteral(", forced a GC");
     }
 
     const char16_t* kFmt =
-        u"CC(T+%.1f)[%s-%i] max pause: %lums, total time: %lums, slices: %lu, "
+        u"CC(T+%.1f)[%s-%i] max pause: %.fms, total time: %.fms, slices: %lu, "
         u"suspected: %lu, visited: %lu RCed and %lu%s GCed, collected: %lu "
         u"RCed and %lu GCed (%lu|%lu|%lu waiting for GC)%s\n"
         u"ForgetSkippable %lu times before CC, min: %.f ms, max: %.f ms, avg: "
-        u"%.f ms, total: %.f ms, max sync: %lu ms, removed: %lu";
+        u"%.f ms, total: %.f ms, max sync: %.f ms, removed: %lu";
     nsString msg;
     nsTextFormatter::ssprintf(
         msg, kFmt, delta.ToMicroseconds() / PR_USEC_PER_SEC,
-        ProcessNameForCollectorLog(), getpid(), gCCStats.mMaxSliceTime,
-        gCCStats.mTotalSliceTime, aResults.mNumSlices, gCCStats.mSuspected,
-        aResults.mVisitedRefCounted, aResults.mVisitedGCed, mergeMsg.get(),
-        aResults.mFreedRefCounted, aResults.mFreedGCed, sCCollectedWaitingForGC,
-        sCCollectedZonesWaitingForGC, sLikelyShortLivingObjectsNeedingGC,
-        gcMsg.get(), sForgetSkippableBeforeCC,
-        sMinForgetSkippableTime.ToMilliseconds(),
+        ProcessNameForCollectorLog(), getpid(),
+        gCCStats.mMaxSliceTime.ToMilliseconds(),
+        gCCStats.mTotalSliceTime.ToMilliseconds(), aResults.mNumSlices,
+        gCCStats.mSuspected, aResults.mVisitedRefCounted, aResults.mVisitedGCed,
+        mergeMsg.get(), aResults.mFreedRefCounted, aResults.mFreedGCed,
+        sCCollectedWaitingForGC, sCCollectedZonesWaitingForGC,
+        sLikelyShortLivingObjectsNeedingGC, gcMsg.get(),
+        sForgetSkippableBeforeCC, sMinForgetSkippableTime.ToMilliseconds(),
         sMaxForgetSkippableTime.ToMilliseconds(),
         sTotalForgetSkippableTime.ToMilliseconds() / cleanups,
         sTotalForgetSkippableTime.ToMilliseconds(),
-        gCCStats.mMaxSkippableDuration, sRemovedPurples);
+        gCCStats.mMaxSkippableDuration.ToMilliseconds(), sRemovedPurples);
     if (StaticPrefs::javascript_options_mem_log()) {
       nsCOMPtr<nsIConsoleService> cs =
           do_GetService(NS_CONSOLESERVICE_CONTRACTID);
       if (cs) {
         cs->LogStringMessage(msg.get());
       }
     }
     if (gCCStats.mFile) {
       fprintf(gCCStats.mFile, "%s\n", NS_ConvertUTF16toUTF8(msg).get());
     }
   }
 
   if (StaticPrefs::javascript_options_mem_notify()) {
     const char16_t* kJSONFmt =
         u"{ \"timestamp\": %llu, "
         u"\"duration\": %.f, "
-        u"\"max_slice_pause\": %lu, "
-        u"\"total_slice_pause\": %lu, "
-        u"\"max_finish_gc_duration\": %lu, "
-        u"\"max_sync_skippable_duration\": %lu, "
+        u"\"max_slice_pause\": %.f, "
+        u"\"total_slice_pause\": %.f, "
+        u"\"max_finish_gc_duration\": %.f, "
+        u"\"max_sync_skippable_duration\": %.f, "
         u"\"suspected\": %lu, "
         u"\"visited\": { "
         u"\"RCed\": %lu, "
         u"\"GCed\": %lu }, "
         u"\"collected\": { "
         u"\"RCed\": %lu, "
         u"\"GCed\": %lu }, "
         u"\"waiting_for_gc\": %lu, "
@@ -1688,19 +1659,21 @@ void nsJSContext::EndCycleCollectionCall
         u"\"avg\": %.f, "
         u"\"total\": %.f, "
         u"\"removed\": %lu } "
         u"}";
 
     nsString json;
     nsTextFormatter::ssprintf(
         json, kJSONFmt, PR_Now(), ccNowDuration.ToMilliseconds(),
-        gCCStats.mMaxSliceTime, gCCStats.mTotalSliceTime,
-        gCCStats.mMaxGCDuration, gCCStats.mMaxSkippableDuration,
-        gCCStats.mSuspected, aResults.mVisitedRefCounted, aResults.mVisitedGCed,
+        gCCStats.mMaxSliceTime.ToMilliseconds(),
+        gCCStats.mTotalSliceTime.ToMilliseconds(),
+        gCCStats.mMaxGCDuration.ToMilliseconds(),
+        gCCStats.mMaxSkippableDuration.ToMilliseconds(), gCCStats.mSuspected,
+        aResults.mVisitedRefCounted, aResults.mVisitedGCed,
         aResults.mFreedRefCounted, aResults.mFreedGCed, sCCollectedWaitingForGC,
         sCCollectedZonesWaitingForGC, sLikelyShortLivingObjectsNeedingGC,
         aResults.mForcedGC, sForgetSkippableBeforeCC,
         sMinForgetSkippableTime.ToMilliseconds(),
         sMaxForgetSkippableTime.ToMilliseconds(),
         sTotalForgetSkippableTime.ToMilliseconds() / cleanups,
         sTotalForgetSkippableTime.ToMilliseconds(), sRemovedPurples);
     nsCOMPtr<nsIObserverService> observerService =