Bug 957370 - Make 'total time' measure total time actually running the CC. r=smaug

dom/base/nsJSEnvironment.cpp

@@ -2003,6 +2003,7 @@ struct CycleCollectorStats
     mSuspected = 0;
     mMaxSkippableDuration = 0;
     mMaxSliceTime = 0;
+    mTotalSliceTime = 0;
     mAnyLockedOut = false;
     mExtraForgetSkippableCalls = 0;
   }
@@ -2013,6 +2014,7 @@ struct CycleCollectorStats
   {
     uint32_t sliceTime = TimeUntilNow(mBeginSliceTime);
     mMaxSliceTime = std::max(mMaxSliceTime, sliceTime);
+    mTotalSliceTime += sliceTime;
     MOZ_ASSERT(mExtraForgetSkippableCalls == 0, "Forget to reset extra forget skippable calls?");
   }
 
@@ -2040,6 +2042,9 @@ struct CycleCollectorStats
   // The longest pause of any slice in the current CC.
   uint32_t mMaxSliceTime;
 
+  // The total amount of time spent actually running the current CC.
+  uint32_t mTotalSliceTime;
+
   // True if we were locked out by the GC in any slice of the current CC.
   bool mAnyLockedOut;
 
@@ -2257,7 +2262,8 @@ nsJSContext::EndCycleCollectionCallback(CycleCollectorResults &aResults)
       MOZ_UTF16("ForgetSkippable %lu times before CC, min: %lu ms, max: %lu ms, avg: %lu ms, total: %lu ms, max sync: %lu ms, removed: %lu"));
     nsString msg;
     msg.Adopt(nsTextFormatter::smprintf(kFmt.get(), double(delta) / PR_USEC_PER_SEC,
-                                        gCCStats.mMaxSliceTime, ccNowDuration, gCCStats.mSuspected,
+                                        gCCStats.mMaxSliceTime, gCCStats.mTotalSliceTime,
+                                        gCCStats.mSuspected,
                                         aResults.mVisitedRefCounted, aResults.mVisitedGCed, mergeMsg.get(),
                                         aResults.mFreedRefCounted, aResults.mFreedGCed,
                                         sCCollectedWaitingForGC, sLikelyShortLivingObjectsNeedingGC,
@@ -2281,6 +2287,7 @@ nsJSContext::EndCycleCollectionCallback(CycleCollectorResults &aResults)
        MOZ_UTF16("{ \"timestamp\": %llu, ")
          MOZ_UTF16("\"duration\": %llu, ")
          MOZ_UTF16("\"max_slice_pause\": %llu, ")
+         MOZ_UTF16("\"total_slice_pause\": %llu, ")
          MOZ_UTF16("\"max_finish_gc_duration\": %llu, ")
          MOZ_UTF16("\"max_sync_skippable_duration\": %llu, ")
          MOZ_UTF16("\"suspected\": %lu, ")
@@ -2303,7 +2310,9 @@ nsJSContext::EndCycleCollectionCallback(CycleCollectorResults &aResults)
        MOZ_UTF16("}"));
     nsString json;
     json.Adopt(nsTextFormatter::smprintf(kJSONFmt.get(), endCCTime, ccNowDuration,
-                                         gCCStats.mMaxSliceTime, gCCStats.mMaxGCDuration,
+                                         gCCStats.mMaxSliceTime,
+                                         gCCStats.mTotalSliceTime,
+                                         gCCStats.mMaxGCDuration,
                                          gCCStats.mMaxSkippableDuration,
                                          gCCStats.mSuspected,
                                          aResults.mVisitedRefCounted, aResults.mVisitedGCed,