Bug 1165410 - Reimplement GC statistics JSON output formatter; r=sfink
authorTerrence Cole <terrence@mozilla.com>
Wed, 20 May 2015 09:14:29 -0700
changeset 245721 1a955124eccc9b5418713eae59b6dcca0ba21216
parent 245720 9aed76a4ee0be1967ec01bcb7ed4a761378975e9
child 245722 d551aa12ebb1c54f06e3f891174ccc137252f2de
push id28816
push userkwierso@gmail.com
push dateThu, 28 May 2015 00:03:18 +0000
treeherdermozilla-central@8707d35414f4 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerssfink
bugs1165410
milestone41.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 1165410 - Reimplement GC statistics JSON output formatter; r=sfink
js/src/gc/Statistics.cpp
js/src/gc/Statistics.h
js/src/jsgc.cpp
--- a/js/src/gc/Statistics.cpp
+++ b/js/src/gc/Statistics.cpp
@@ -81,17 +81,17 @@ class gcstats::StatisticsSerializer
         append(name, vfmt, va, units);
         va_end(va);
     }
 
     void appendDecimal(const char* name, const char* units, double d) {
         if (d < 0)
             d = 0;
         if (asJSON_)
-            appendNumber(name, "%d.%d", units, (int)d, (int)(d * 10.) % 10);
+            appendNumber(name, "%d.%03d", units, (int)d, (int)(d * 1000.) % 1000);
         else
             appendNumber(name, "%.1f", units, d);
     }
 
     void appendIfNonzeroMS(const char* name, double v) {
         if (asJSON_ || v >= 0.1)
             appendDecimal(name, "ms", v);
     }
@@ -562,29 +562,38 @@ Statistics::formatData(StatisticsSeriali
     ss.endObject();
 
     return !ss.isOOM();
 }
 
 typedef Vector<UniqueChars, 8, SystemAllocPolicy> FragmentVector;
 
 static UniqueChars
-Join(const FragmentVector& fragments) {
+Join(const FragmentVector& fragments, const char* separator = "") {
+    const size_t separatorLength = strlen(separator);
     size_t length = 0;
-    for (size_t i = 0; i < fragments.length(); ++i)
+    for (size_t i = 0; i < fragments.length(); ++i) {
         length += fragments[i] ? strlen(fragments[i].get()) : 0;
+        if (i < (fragments.length() - 1))
+            length += separatorLength;
+    }
 
     char* joined = js_pod_malloc<char>(length + 1);
     joined[length] = '\0';
 
     char* cursor = joined;
     for (size_t i = 0; i < fragments.length(); ++i) {
         if (fragments[i])
             strcpy(cursor, fragments[i].get());
         cursor += fragments[i] ? strlen(fragments[i].get()) : 0;
+        if (i < (fragments.length() - 1)) {
+            if (separatorLength)
+                strcpy(cursor, separator);
+            cursor += separatorLength;
+        }
     }
 
     return UniqueChars(joined);
 }
 
 static int64_t
 SumChildTimes(size_t phaseSlot, Phase phase, Statistics::PhaseTimeTable phaseTimes)
 {
@@ -750,32 +759,179 @@ Statistics::formatDetailedTotals()
     Max Pause: %.3fms\n\
 ";
     char buffer[1024];
     memset(buffer, 0, sizeof(buffer));
     JS_snprintf(buffer, sizeof(buffer), format, t(total), t(longest));
     return make_string_copy(buffer);
 }
 
+UniqueChars
+Statistics::formatJsonMessage(uint64_t timestamp)
+{
+    MOZ_ASSERT(!aborted);
+
+    FragmentVector fragments;
+
+    if (!fragments.append(make_string_copy("{")) ||
+        !fragments.append(formatJsonDescription(timestamp)) ||
+        !fragments.append(make_string_copy("\"slices\":[")))
+    {
+        return UniqueChars(nullptr);
+    }
+
+    for (unsigned i = 0; i < slices.length(); i++) {
+        if (!fragments.append(make_string_copy("{")) ||
+            !fragments.append(formatJsonSliceDescription(i, slices[i])) ||
+            !fragments.append(make_string_copy("\"times\":{")) ||
+            !fragments.append(formatJsonPhaseTimes(slices[i].phaseTimes)) ||
+            !fragments.append(make_string_copy("}}")) ||
+            (i < (slices.length() - 1) && !fragments.append(make_string_copy(","))))
+        {
+            return UniqueChars(nullptr);
+        }
+    }
+
+    if (!fragments.append(make_string_copy("],\"totals\":{")) ||
+        !fragments.append(formatJsonPhaseTimes(phaseTimes)) ||
+        !fragments.append(make_string_copy("}}")))
+    {
+        return UniqueChars(nullptr);
+    }
+
+    return Join(fragments);
+}
+
+UniqueChars
+Statistics::formatJsonDescription(uint64_t timestamp)
+{
+    int64_t total, longest;
+    gcDuration(&total, &longest);
+
+    int64_t sccTotal, sccLongest;
+    sccDurations(&sccTotal, &sccLongest);
+
+    double mmu20 = computeMMU(20 * PRMJ_USEC_PER_MSEC);
+    double mmu50 = computeMMU(50 * PRMJ_USEC_PER_MSEC);
+
+    const char *format =
+        "\"timestamp\":%llu,"
+        "\"max_pause\":%lu.%03lu,"
+        "\"total_time\":%lu.%03lu,"
+        "\"zones_collected\":%d,"
+        "\"total_zones\":%d,"
+        "\"total_compartments\":%d,"
+        "\"minor_gcs\":%d,"
+        "\"store_buffer_overflows\":%d,"
+        "\"mmu_20ms\":%d,"
+        "\"mmu_50ms\":%d,"
+        "\"scc_sweep_total\":%lu.%03lu,"
+        "\"scc_sweep_max_pause\":%lu.%03lu,"
+        "\"nonincremental_reason\":\"%s\","
+        "\"allocated\":%u,"
+        "\"added_chunks\":%d,"
+        "\"removed_chunks\":%d,";
+    char buffer[1024];
+    memset(buffer, 0, sizeof(buffer));
+    JS_snprintf(buffer, sizeof(buffer), format,
+                (unsigned long long)timestamp,
+                longest / 1000, longest % 1000,
+                total / 1000, total % 1000,
+                zoneStats.collectedZoneCount,
+                zoneStats.zoneCount,
+                zoneStats.compartmentCount,
+                counts[STAT_MINOR_GC],
+                counts[STAT_STOREBUFFER_OVERFLOW],
+                int(mmu20 * 100),
+                int(mmu50 * 100),
+                sccTotal / 1000, sccTotal % 1000,
+                sccLongest / 1000, sccLongest % 1000,
+                nonincrementalReason_ ? nonincrementalReason_ : "none",
+                unsigned(preBytes / 1024 / 1024),
+                counts[STAT_NEW_CHUNK],
+                counts[STAT_DESTROY_CHUNK]);
+    return make_string_copy(buffer);
+}
+
+UniqueChars
+Statistics::formatJsonSliceDescription(unsigned i, const SliceData& slice)
+{
+    int64_t duration = slices[i].duration();
+    int64_t when = slices[i].start - slices[0].start;
+    char budgetDescription[200];
+    slice.budget.describe(budgetDescription, sizeof(budgetDescription) - 1);
+    int64_t pageFaults = slices[i].endFaults - slices[i].startFaults;
+
+    const char* format =
+        "\"slice\":%d,"
+        "\"pause\":%lu.%03lu,"
+        "\"when\":%lu.%03lu,"
+        "\"reason\":\"%s\","
+        "\"budget\":\"%s\","
+        "\"page_faults\":%llu,"
+        "\"start_timestamp\":%llu,"
+        "\"end_timestamp\":%llu,";
+    char buffer[1024];
+    memset(buffer, 0, sizeof(buffer));
+    JS_snprintf(buffer, sizeof(buffer), format,
+                i,
+                duration / 1000, duration % 1000,
+                when / 1000, when % 1000,
+                ExplainReason(slices[i].reason),
+                budgetDescription,
+                pageFaults,
+                slices[i].start,
+                slices[i].end);
+    return make_string_copy(buffer);
+}
+
+UniqueChars
+FilterJsonKey(const char*const buffer)
+{
+    char* mut = strdup(buffer);
+    char* c = mut;
+    while (*c) {
+        if (!isalpha(*c))
+            *c = '_';
+        else if (isupper(*c))
+            *c = tolower(*c);
+        ++c;
+    }
+    return UniqueChars(mut);
+}
+
+UniqueChars
+Statistics::formatJsonPhaseTimes(PhaseTimeTable phaseTimes)
+{
+    FragmentVector fragments;
+    char buffer[128];
+    for (AllPhaseIterator iter(phaseTimes); !iter.done(); iter.advance()) {
+        Phase phase;
+        size_t dagSlot;
+        iter.get(&phase, &dagSlot);
+
+        UniqueChars name = FilterJsonKey(phases[phase].name);
+        int64_t ownTime = phaseTimes[dagSlot][phase];
+        JS_snprintf(buffer, sizeof(buffer), "\"%s\":%lu.%03lu",
+                    name.get(), ownTime / 1000, ownTime % 1000);
+
+        if (!fragments.append(make_string_copy(buffer)))
+            return UniqueChars(nullptr);
+    }
+    return Join(fragments, ",");
+}
+
 char16_t*
 Statistics::formatMessage()
 {
     StatisticsSerializer ss(StatisticsSerializer::AsText);
     formatData(ss, 0);
     return ss.finishJSString();
 }
 
-char16_t*
-Statistics::formatJSON(uint64_t timestamp)
-{
-    StatisticsSerializer ss(StatisticsSerializer::AsJSON);
-    formatData(ss, timestamp);
-    return ss.finishJSString();
-}
-
 Statistics::Statistics(JSRuntime* rt)
   : runtime(rt),
     startupTime(PRMJ_Now()),
     fp(nullptr),
     gcDepth(0),
     nonincrementalReason_(nullptr),
     timedGCStart(0),
     preBytes(0),
--- a/js/src/gc/Statistics.h
+++ b/js/src/gc/Statistics.h
@@ -182,17 +182,17 @@ struct Statistics
         MOZ_ASSERT(s < STAT_LIMIT);
         counts[s]++;
     }
 
     int64_t beginSCC();
     void endSCC(unsigned scc, int64_t start);
 
     char16_t* formatMessage();
-    char16_t* formatJSON(uint64_t timestamp);
+    UniqueChars formatJsonMessage(uint64_t timestamp);
     UniqueChars formatDetailedMessage();
 
     JS::GCSliceCallback setSliceCallback(JS::GCSliceCallback callback);
 
     int64_t clearMaxGCPauseAccumulator();
     int64_t getMaxGCPauseSinceClear();
 
     // Return the current phase, suppressing the synthetic PHASE_MUTATOR phase.
@@ -314,16 +314,20 @@ struct Statistics
     void printStats();
     bool formatData(StatisticsSerializer& ss, uint64_t timestamp);
 
     UniqueChars formatDetailedDescription();
     UniqueChars formatDetailedSliceDescription(unsigned i, const SliceData& slice);
     UniqueChars formatDetailedPhaseTimes(PhaseTimeTable phaseTimes);
     UniqueChars formatDetailedTotals();
 
+    UniqueChars formatJsonDescription(uint64_t timestamp);
+    UniqueChars formatJsonSliceDescription(unsigned i, const SliceData& slice);
+    UniqueChars formatJsonPhaseTimes(PhaseTimeTable phaseTimes);
+
     double computeMMU(int64_t resolution);
 };
 
 struct AutoGCSlice
 {
     AutoGCSlice(Statistics& stats, const ZoneGCStats& zoneStats, JSGCInvocationKind gckind,
                 SliceBudget budget, JS::gcreason::Reason reason
                 MOZ_GUARD_OBJECT_NOTIFIER_PARAM)
--- a/js/src/jsgc.cpp
+++ b/js/src/jsgc.cpp
@@ -7101,17 +7101,26 @@ JS::dbg::GarbageCollectionEvent::Ptr
 JS::GCDescription::toGCEvent(JSRuntime* rt) const
 {
     return JS::dbg::GarbageCollectionEvent::Create(rt, rt->gc.stats, rt->gc.majorGCCount());
 }
 
 char16_t*
 JS::GCDescription::formatJSON(JSRuntime* rt, uint64_t timestamp) const
 {
-    return rt->gc.stats.formatJSON(timestamp);
+    UniqueChars cstr = rt->gc.stats.formatJsonMessage(timestamp);
+
+    size_t nchars = strlen(cstr.get());
+    UniquePtr<char16_t, JS::FreePolicy> out(js_pod_malloc<char16_t>(nchars + 1));
+    if (!out)
+        return nullptr;
+    out.get()[nchars] = 0;
+
+    CopyAndInflateChars(out.get(), cstr.get(), nchars);
+    return out.release();
 }
 
 JS_PUBLIC_API(JS::GCSliceCallback)
 JS::SetGCSliceCallback(JSRuntime* rt, GCSliceCallback callback)
 {
     return rt->gc.setSliceCallback(callback);
 }