michael@0: /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*-
michael@0:  * vim: set ts=8 sts=4 et sw=4 tw=99:
michael@0:  * This Source Code Form is subject to the terms of the Mozilla Public
michael@0:  * License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0:  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
michael@0: 
michael@0: #include "gc/Statistics.h"
michael@0: 
michael@0: #include "mozilla/PodOperations.h"
michael@0: 
michael@0: #include <ctype.h>
michael@0: #include <stdarg.h>
michael@0: #include <stdio.h>
michael@0: 
michael@0: #include "jscrashreport.h"
michael@0: #include "jsprf.h"
michael@0: #include "jsutil.h"
michael@0: #include "prmjtime.h"
michael@0: 
michael@0: #include "gc/Memory.h"
michael@0: #include "vm/Runtime.h"
michael@0: 
michael@0: using namespace js;
michael@0: using namespace js::gcstats;
michael@0: 
michael@0: using mozilla::PodArrayZero;
michael@0: 
michael@0: /* Except for the first and last, slices of less than 42ms are not reported. */
michael@0: static const int64_t SLICE_MIN_REPORT_TIME = 42 * PRMJ_USEC_PER_MSEC;
michael@0: 
michael@0: class gcstats::StatisticsSerializer
michael@0: {
michael@0:     typedef Vector<char, 128, SystemAllocPolicy> CharBuffer;
michael@0:     CharBuffer buf_;
michael@0:     bool asJSON_;
michael@0:     bool needComma_;
michael@0:     bool oom_;
michael@0: 
michael@0:     static const int MaxFieldValueLength = 128;
michael@0: 
michael@0:   public:
michael@0:     enum Mode {
michael@0:         AsJSON = true,
michael@0:         AsText = false
michael@0:     };
michael@0: 
michael@0:     StatisticsSerializer(Mode asJSON)
michael@0:       : buf_(), asJSON_(asJSON), needComma_(false), oom_(false)
michael@0:     {}
michael@0: 
michael@0:     bool isJSON() { return asJSON_; }
michael@0: 
michael@0:     bool isOOM() { return oom_; }
michael@0: 
michael@0:     void endLine() {
michael@0:         if (!asJSON_) {
michael@0:             p("\n");
michael@0:             needComma_ = false;
michael@0:         }
michael@0:     }
michael@0: 
michael@0:     void extra(const char *str) {
michael@0:         if (!asJSON_) {
michael@0:             needComma_ = false;
michael@0:             p(str);
michael@0:         }
michael@0:     }
michael@0: 
michael@0:     void appendString(const char *name, const char *value) {
michael@0:         put(name, value, "", true);
michael@0:     }
michael@0: 
michael@0:     void appendNumber(const char *name, const char *vfmt, const char *units, ...) {
michael@0:         va_list va;
michael@0:         va_start(va, units);
michael@0:         append(name, vfmt, va, units);
michael@0:         va_end(va);
michael@0:     }
michael@0: 
michael@0:     void appendDecimal(const char *name, const char *units, double d) {
michael@0:         if (d < 0)
michael@0:             d = 0;
michael@0:         if (asJSON_)
michael@0:             appendNumber(name, "%d.%d", units, (int)d, (int)(d * 10.) % 10);
michael@0:         else
michael@0:             appendNumber(name, "%.1f", units, d);
michael@0:     }
michael@0: 
michael@0:     void appendIfNonzeroMS(const char *name, double v) {
michael@0:         if (asJSON_ || v >= 0.1)
michael@0:             appendDecimal(name, "ms", v);
michael@0:     }
michael@0: 
michael@0:     void beginObject(const char *name) {
michael@0:         if (needComma_)
michael@0:             pJSON(", ");
michael@0:         if (asJSON_ && name) {
michael@0:             putKey(name);
michael@0:             pJSON(": ");
michael@0:         }
michael@0:         pJSON("{");
michael@0:         needComma_ = false;
michael@0:     }
michael@0: 
michael@0:     void endObject() {
michael@0:         needComma_ = false;
michael@0:         pJSON("}");
michael@0:         needComma_ = true;
michael@0:     }
michael@0: 
michael@0:     void beginArray(const char *name) {
michael@0:         if (needComma_)
michael@0:             pJSON(", ");
michael@0:         if (asJSON_)
michael@0:             putKey(name);
michael@0:         pJSON(": [");
michael@0:         needComma_ = false;
michael@0:     }
michael@0: 
michael@0:     void endArray() {
michael@0:         needComma_ = false;
michael@0:         pJSON("]");
michael@0:         needComma_ = true;
michael@0:     }
michael@0: 
michael@0:     jschar *finishJSString() {
michael@0:         char *buf = finishCString();
michael@0:         if (!buf)
michael@0:             return nullptr;
michael@0: 
michael@0:         size_t nchars = strlen(buf);
michael@0:         jschar *out = js_pod_malloc<jschar>(nchars + 1);
michael@0:         if (!out) {
michael@0:             oom_ = true;
michael@0:             js_free(buf);
michael@0:             return nullptr;
michael@0:         }
michael@0: 
michael@0:         InflateStringToBuffer(buf, nchars, out);
michael@0:         js_free(buf);
michael@0: 
michael@0:         out[nchars] = 0;
michael@0:         return out;
michael@0:     }
michael@0: 
michael@0:     char *finishCString() {
michael@0:         if (oom_)
michael@0:             return nullptr;
michael@0: 
michael@0:         buf_.append('\0');
michael@0: 
michael@0:         char *buf = buf_.extractRawBuffer();
michael@0:         if (!buf)
michael@0:             oom_ = true;
michael@0: 
michael@0:         return buf;
michael@0:     }
michael@0: 
michael@0:   private:
michael@0:     void append(const char *name, const char *vfmt,
michael@0:                 va_list va, const char *units)
michael@0:     {
michael@0:         char val[MaxFieldValueLength];
michael@0:         JS_vsnprintf(val, MaxFieldValueLength, vfmt, va);
michael@0:         put(name, val, units, false);
michael@0:     }
michael@0: 
michael@0:     void p(const char *cstr) {
michael@0:         if (oom_)
michael@0:             return;
michael@0: 
michael@0:         if (!buf_.append(cstr, strlen(cstr)))
michael@0:             oom_ = true;
michael@0:     }
michael@0: 
michael@0:     void p(const char c) {
michael@0:         if (oom_)
michael@0:             return;
michael@0: 
michael@0:         if (!buf_.append(c))
michael@0:             oom_ = true;
michael@0:     }
michael@0: 
michael@0:     void pJSON(const char *str) {
michael@0:         if (asJSON_)
michael@0:             p(str);
michael@0:     }
michael@0: 
michael@0:     void put(const char *name, const char *val, const char *units, bool valueIsQuoted) {
michael@0:         if (needComma_)
michael@0:             p(", ");
michael@0:         needComma_ = true;
michael@0: 
michael@0:         putKey(name);
michael@0:         p(": ");
michael@0:         if (valueIsQuoted)
michael@0:             putQuoted(val);
michael@0:         else
michael@0:             p(val);
michael@0:         if (!asJSON_)
michael@0:             p(units);
michael@0:     }
michael@0: 
michael@0:     void putQuoted(const char *str) {
michael@0:         pJSON("\"");
michael@0:         p(str);
michael@0:         pJSON("\"");
michael@0:     }
michael@0: 
michael@0:     void putKey(const char *str) {
michael@0:         if (!asJSON_) {
michael@0:             p(str);
michael@0:             return;
michael@0:         }
michael@0: 
michael@0:         p("\"");
michael@0:         const char *c = str;
michael@0:         while (*c) {
michael@0:             if (*c == ' ' || *c == '\t')
michael@0:                 p('_');
michael@0:             else if (isupper(*c))
michael@0:                 p(tolower(*c));
michael@0:             else if (*c == '+')
michael@0:                 p("added_");
michael@0:             else if (*c == '-')
michael@0:                 p("removed_");
michael@0:             else if (*c != '(' && *c != ')')
michael@0:                 p(*c);
michael@0:             c++;
michael@0:         }
michael@0:         p("\"");
michael@0:     }
michael@0: };
michael@0: 
michael@0: /*
michael@0:  * If this fails, then you can either delete this assertion and allow all
michael@0:  * larger-numbered reasons to pile up in the last telemetry bucket, or switch
michael@0:  * to GC_REASON_3 and bump the max value.
michael@0:  */
michael@0: JS_STATIC_ASSERT(JS::gcreason::NUM_TELEMETRY_REASONS >= JS::gcreason::NUM_REASONS);
michael@0: 
michael@0: const char *
michael@0: js::gcstats::ExplainReason(JS::gcreason::Reason reason)
michael@0: {
michael@0:     switch (reason) {
michael@0: #define SWITCH_REASON(name)                     \
michael@0:         case JS::gcreason::name:                    \
michael@0:           return #name;
michael@0:         GCREASONS(SWITCH_REASON)
michael@0: 
michael@0:         default:
michael@0:           MOZ_ASSUME_UNREACHABLE("bad GC reason");
michael@0: #undef SWITCH_REASON
michael@0:     }
michael@0: }
michael@0: 
michael@0: static double
michael@0: t(int64_t t)
michael@0: {
michael@0:     return double(t) / PRMJ_USEC_PER_MSEC;
michael@0: }
michael@0: 
michael@0: struct PhaseInfo
michael@0: {
michael@0:     Phase index;
michael@0:     const char *name;
michael@0:     Phase parent;
michael@0: };
michael@0: 
michael@0: static const Phase PHASE_NO_PARENT = PHASE_LIMIT;
michael@0: 
michael@0: static const PhaseInfo phases[] = {
michael@0:     { PHASE_GC_BEGIN, "Begin Callback", PHASE_NO_PARENT },
michael@0:     { PHASE_WAIT_BACKGROUND_THREAD, "Wait Background Thread", PHASE_NO_PARENT },
michael@0:     { PHASE_MARK_DISCARD_CODE, "Mark Discard Code", PHASE_NO_PARENT },
michael@0:     { PHASE_PURGE, "Purge", PHASE_NO_PARENT },
michael@0:     { PHASE_MARK, "Mark", PHASE_NO_PARENT },
michael@0:     { PHASE_MARK_ROOTS, "Mark Roots", PHASE_MARK },
michael@0:     { PHASE_MARK_DELAYED, "Mark Delayed", PHASE_MARK },
michael@0:     { PHASE_SWEEP, "Sweep", PHASE_NO_PARENT },
michael@0:     { PHASE_SWEEP_MARK, "Mark During Sweeping", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_MARK_TYPES, "Mark Types During Sweeping", PHASE_SWEEP_MARK },
michael@0:     { PHASE_SWEEP_MARK_INCOMING_BLACK, "Mark Incoming Black Pointers", PHASE_SWEEP_MARK },
michael@0:     { PHASE_SWEEP_MARK_WEAK, "Mark Weak", PHASE_SWEEP_MARK },
michael@0:     { PHASE_SWEEP_MARK_INCOMING_GRAY, "Mark Incoming Gray Pointers", PHASE_SWEEP_MARK },
michael@0:     { PHASE_SWEEP_MARK_GRAY, "Mark Gray", PHASE_SWEEP_MARK },
michael@0:     { PHASE_SWEEP_MARK_GRAY_WEAK, "Mark Gray and Weak", PHASE_SWEEP_MARK },
michael@0:     { PHASE_FINALIZE_START, "Finalize Start Callback", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_ATOMS, "Sweep Atoms", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_COMPARTMENTS, "Sweep Compartments", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_DISCARD_CODE, "Sweep Discard Code", PHASE_SWEEP_COMPARTMENTS },
michael@0:     { PHASE_SWEEP_TABLES, "Sweep Tables", PHASE_SWEEP_COMPARTMENTS },
michael@0:     { PHASE_SWEEP_TABLES_WRAPPER, "Sweep Cross Compartment Wrappers", PHASE_SWEEP_TABLES },
michael@0:     { PHASE_SWEEP_TABLES_BASE_SHAPE, "Sweep Base Shapes", PHASE_SWEEP_TABLES },
michael@0:     { PHASE_SWEEP_TABLES_INITIAL_SHAPE, "Sweep Initial Shapes", PHASE_SWEEP_TABLES },
michael@0:     { PHASE_SWEEP_TABLES_TYPE_OBJECT, "Sweep Type Objects", PHASE_SWEEP_TABLES },
michael@0:     { PHASE_SWEEP_TABLES_BREAKPOINT, "Sweep Breakpoints", PHASE_SWEEP_TABLES },
michael@0:     { PHASE_SWEEP_TABLES_REGEXP, "Sweep Regexps", PHASE_SWEEP_TABLES },
michael@0:     { PHASE_DISCARD_ANALYSIS, "Discard Analysis", PHASE_SWEEP_COMPARTMENTS },
michael@0:     { PHASE_DISCARD_TI, "Discard TI", PHASE_DISCARD_ANALYSIS },
michael@0:     { PHASE_FREE_TI_ARENA, "Free TI Arena", PHASE_DISCARD_ANALYSIS },
michael@0:     { PHASE_SWEEP_TYPES, "Sweep Types", PHASE_DISCARD_ANALYSIS },
michael@0:     { PHASE_SWEEP_OBJECT, "Sweep Object", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_STRING, "Sweep String", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_SCRIPT, "Sweep Script", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_SHAPE, "Sweep Shape", PHASE_SWEEP },
michael@0:     { PHASE_SWEEP_JITCODE, "Sweep JIT code", PHASE_SWEEP },
michael@0:     { PHASE_FINALIZE_END, "Finalize End Callback", PHASE_SWEEP },
michael@0:     { PHASE_DESTROY, "Deallocate", PHASE_SWEEP },
michael@0:     { PHASE_GC_END, "End Callback", PHASE_NO_PARENT },
michael@0:     { PHASE_LIMIT, nullptr, PHASE_NO_PARENT }
michael@0: };
michael@0: 
michael@0: static void
michael@0: FormatPhaseTimes(StatisticsSerializer &ss, const char *name, int64_t *times)
michael@0: {
michael@0:     ss.beginObject(name);
michael@0:     for (unsigned i = 0; phases[i].name; i++)
michael@0:         ss.appendIfNonzeroMS(phases[i].name, t(times[phases[i].index]));
michael@0:     ss.endObject();
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::gcDuration(int64_t *total, int64_t *maxPause)
michael@0: {
michael@0:     *total = *maxPause = 0;
michael@0:     for (SliceData *slice = slices.begin(); slice != slices.end(); slice++) {
michael@0:         *total += slice->duration();
michael@0:         if (slice->duration() > *maxPause)
michael@0:             *maxPause = slice->duration();
michael@0:     }
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::sccDurations(int64_t *total, int64_t *maxPause)
michael@0: {
michael@0:     *total = *maxPause = 0;
michael@0:     for (size_t i = 0; i < sccTimes.length(); i++) {
michael@0:         *total += sccTimes[i];
michael@0:         *maxPause = Max(*maxPause, sccTimes[i]);
michael@0:     }
michael@0: }
michael@0: 
michael@0: bool
michael@0: Statistics::formatData(StatisticsSerializer &ss, uint64_t timestamp)
michael@0: {
michael@0:     int64_t total, longest;
michael@0:     gcDuration(&total, &longest);
michael@0: 
michael@0:     int64_t sccTotal, sccLongest;
michael@0:     sccDurations(&sccTotal, &sccLongest);
michael@0: 
michael@0:     double mmu20 = computeMMU(20 * PRMJ_USEC_PER_MSEC);
michael@0:     double mmu50 = computeMMU(50 * PRMJ_USEC_PER_MSEC);
michael@0: 
michael@0:     ss.beginObject(nullptr);
michael@0:     if (ss.isJSON())
michael@0:         ss.appendNumber("Timestamp", "%llu", "", (unsigned long long)timestamp);
michael@0:     if (slices.length() > 1 || ss.isJSON())
michael@0:         ss.appendDecimal("Max Pause", "ms", t(longest));
michael@0:     else
michael@0:         ss.appendString("Reason", ExplainReason(slices[0].reason));
michael@0:     ss.appendDecimal("Total Time", "ms", t(total));
michael@0:     ss.appendNumber("Zones Collected", "%d", "", collectedCount);
michael@0:     ss.appendNumber("Total Zones", "%d", "", zoneCount);
michael@0:     ss.appendNumber("Total Compartments", "%d", "", compartmentCount);
michael@0:     ss.appendNumber("Minor GCs", "%d", "", counts[STAT_MINOR_GC]);
michael@0:     ss.appendNumber("MMU (20ms)", "%d", "%", int(mmu20 * 100));
michael@0:     ss.appendNumber("MMU (50ms)", "%d", "%", int(mmu50 * 100));
michael@0:     ss.appendDecimal("SCC Sweep Total", "ms", t(sccTotal));
michael@0:     ss.appendDecimal("SCC Sweep Max Pause", "ms", t(sccLongest));
michael@0:     if (nonincrementalReason || ss.isJSON()) {
michael@0:         ss.appendString("Nonincremental Reason",
michael@0:                         nonincrementalReason ? nonincrementalReason : "none");
michael@0:     }
michael@0:     ss.appendNumber("Allocated", "%u", "MB", unsigned(preBytes / 1024 / 1024));
michael@0:     ss.appendNumber("+Chunks", "%d", "", counts[STAT_NEW_CHUNK]);
michael@0:     ss.appendNumber("-Chunks", "%d", "", counts[STAT_DESTROY_CHUNK]);
michael@0:     ss.endLine();
michael@0: 
michael@0:     if (slices.length() > 1 || ss.isJSON()) {
michael@0:         ss.beginArray("Slices");
michael@0:         for (size_t i = 0; i < slices.length(); i++) {
michael@0:             int64_t width = slices[i].duration();
michael@0:             if (i != 0 && i != slices.length() - 1 && width < SLICE_MIN_REPORT_TIME &&
michael@0:                 !slices[i].resetReason && !ss.isJSON())
michael@0:             {
michael@0:                 continue;
michael@0:             }
michael@0: 
michael@0:             ss.beginObject(nullptr);
michael@0:             ss.extra("    ");
michael@0:             ss.appendNumber("Slice", "%d", "", i);
michael@0:             ss.appendDecimal("Pause", "", t(width));
michael@0:             ss.extra(" (");
michael@0:             ss.appendDecimal("When", "ms", t(slices[i].start - slices[0].start));
michael@0:             ss.appendString("Reason", ExplainReason(slices[i].reason));
michael@0:             if (ss.isJSON()) {
michael@0:                 ss.appendDecimal("Page Faults", "",
michael@0:                                  double(slices[i].endFaults - slices[i].startFaults));
michael@0: 
michael@0:                 ss.appendNumber("Start Timestamp", "%llu", "", (unsigned long long)slices[i].start);
michael@0:                 ss.appendNumber("End Timestamp", "%llu", "", (unsigned long long)slices[i].end);
michael@0:             }
michael@0:             if (slices[i].resetReason)
michael@0:                 ss.appendString("Reset", slices[i].resetReason);
michael@0:             ss.extra("): ");
michael@0:             FormatPhaseTimes(ss, "Times", slices[i].phaseTimes);
michael@0:             ss.endLine();
michael@0:             ss.endObject();
michael@0:         }
michael@0:         ss.endArray();
michael@0:     }
michael@0:     ss.extra("    Totals: ");
michael@0:     FormatPhaseTimes(ss, "Totals", phaseTimes);
michael@0:     ss.endObject();
michael@0: 
michael@0:     return !ss.isOOM();
michael@0: }
michael@0: 
michael@0: jschar *
michael@0: Statistics::formatMessage()
michael@0: {
michael@0:     StatisticsSerializer ss(StatisticsSerializer::AsText);
michael@0:     formatData(ss, 0);
michael@0:     return ss.finishJSString();
michael@0: }
michael@0: 
michael@0: jschar *
michael@0: Statistics::formatJSON(uint64_t timestamp)
michael@0: {
michael@0:     StatisticsSerializer ss(StatisticsSerializer::AsJSON);
michael@0:     formatData(ss, timestamp);
michael@0:     return ss.finishJSString();
michael@0: }
michael@0: 
michael@0: Statistics::Statistics(JSRuntime *rt)
michael@0:   : runtime(rt),
michael@0:     startupTime(PRMJ_Now()),
michael@0:     fp(nullptr),
michael@0:     fullFormat(false),
michael@0:     gcDepth(0),
michael@0:     collectedCount(0),
michael@0:     zoneCount(0),
michael@0:     compartmentCount(0),
michael@0:     nonincrementalReason(nullptr),
michael@0:     preBytes(0),
michael@0:     phaseNestingDepth(0)
michael@0: {
michael@0:     PodArrayZero(phaseTotals);
michael@0:     PodArrayZero(counts);
michael@0: 
michael@0:     char *env = getenv("MOZ_GCTIMER");
michael@0:     if (!env || strcmp(env, "none") == 0) {
michael@0:         fp = nullptr;
michael@0:         return;
michael@0:     }
michael@0: 
michael@0:     if (strcmp(env, "stdout") == 0) {
michael@0:         fullFormat = false;
michael@0:         fp = stdout;
michael@0:     } else if (strcmp(env, "stderr") == 0) {
michael@0:         fullFormat = false;
michael@0:         fp = stderr;
michael@0:     } else {
michael@0:         fullFormat = true;
michael@0: 
michael@0:         fp = fopen(env, "a");
michael@0:         JS_ASSERT(fp);
michael@0:     }
michael@0: }
michael@0: 
michael@0: Statistics::~Statistics()
michael@0: {
michael@0:     if (fp) {
michael@0:         if (fullFormat) {
michael@0:             StatisticsSerializer ss(StatisticsSerializer::AsText);
michael@0:             FormatPhaseTimes(ss, "", phaseTotals);
michael@0:             char *msg = ss.finishCString();
michael@0:             if (msg) {
michael@0:                 fprintf(fp, "TOTALS\n%s\n\n-------\n", msg);
michael@0:                 js_free(msg);
michael@0:             }
michael@0:         }
michael@0: 
michael@0:         if (fp != stdout && fp != stderr)
michael@0:             fclose(fp);
michael@0:     }
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::printStats()
michael@0: {
michael@0:     if (fullFormat) {
michael@0:         StatisticsSerializer ss(StatisticsSerializer::AsText);
michael@0:         formatData(ss, 0);
michael@0:         char *msg = ss.finishCString();
michael@0:         if (msg) {
michael@0:             fprintf(fp, "GC(T+%.3fs) %s\n", t(slices[0].start - startupTime) / 1000.0, msg);
michael@0:             js_free(msg);
michael@0:         }
michael@0:     } else {
michael@0:         int64_t total, longest;
michael@0:         gcDuration(&total, &longest);
michael@0: 
michael@0:         fprintf(fp, "%f %f %f\n",
michael@0:                 t(total),
michael@0:                 t(phaseTimes[PHASE_MARK]),
michael@0:                 t(phaseTimes[PHASE_SWEEP]));
michael@0:     }
michael@0:     fflush(fp);
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::beginGC()
michael@0: {
michael@0:     PodArrayZero(phaseStartTimes);
michael@0:     PodArrayZero(phaseTimes);
michael@0: 
michael@0:     slices.clearAndFree();
michael@0:     sccTimes.clearAndFree();
michael@0:     nonincrementalReason = nullptr;
michael@0: 
michael@0:     preBytes = runtime->gcBytes;
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::endGC()
michael@0: {
michael@0:     crash::SnapshotGCStack();
michael@0: 
michael@0:     for (int i = 0; i < PHASE_LIMIT; i++)
michael@0:         phaseTotals[i] += phaseTimes[i];
michael@0: 
michael@0:     if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback) {
michael@0:         int64_t total, longest;
michael@0:         gcDuration(&total, &longest);
michael@0: 
michael@0:         int64_t sccTotal, sccLongest;
michael@0:         sccDurations(&sccTotal, &sccLongest);
michael@0: 
michael@0:         (*cb)(JS_TELEMETRY_GC_IS_COMPARTMENTAL, collectedCount == zoneCount ? 0 : 1);
michael@0:         (*cb)(JS_TELEMETRY_GC_MS, t(total));
michael@0:         (*cb)(JS_TELEMETRY_GC_MAX_PAUSE_MS, t(longest));
michael@0:         (*cb)(JS_TELEMETRY_GC_MARK_MS, t(phaseTimes[PHASE_MARK]));
michael@0:         (*cb)(JS_TELEMETRY_GC_SWEEP_MS, t(phaseTimes[PHASE_SWEEP]));
michael@0:         (*cb)(JS_TELEMETRY_GC_MARK_ROOTS_MS, t(phaseTimes[PHASE_MARK_ROOTS]));
michael@0:         (*cb)(JS_TELEMETRY_GC_MARK_GRAY_MS, t(phaseTimes[PHASE_SWEEP_MARK_GRAY]));
michael@0:         (*cb)(JS_TELEMETRY_GC_NON_INCREMENTAL, !!nonincrementalReason);
michael@0:         (*cb)(JS_TELEMETRY_GC_INCREMENTAL_DISABLED, !runtime->gcIncrementalEnabled);
michael@0:         (*cb)(JS_TELEMETRY_GC_SCC_SWEEP_TOTAL_MS, t(sccTotal));
michael@0:         (*cb)(JS_TELEMETRY_GC_SCC_SWEEP_MAX_PAUSE_MS, t(sccLongest));
michael@0: 
michael@0:         double mmu50 = computeMMU(50 * PRMJ_USEC_PER_MSEC);
michael@0:         (*cb)(JS_TELEMETRY_GC_MMU_50, mmu50 * 100);
michael@0:     }
michael@0: 
michael@0:     if (fp)
michael@0:         printStats();
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::beginSlice(int collectedCount, int zoneCount, int compartmentCount,
michael@0:                        JS::gcreason::Reason reason)
michael@0: {
michael@0:     this->collectedCount = collectedCount;
michael@0:     this->zoneCount = zoneCount;
michael@0:     this->compartmentCount = compartmentCount;
michael@0: 
michael@0:     bool first = runtime->gcIncrementalState == gc::NO_INCREMENTAL;
michael@0:     if (first)
michael@0:         beginGC();
michael@0: 
michael@0:     SliceData data(reason, PRMJ_Now(), gc::GetPageFaultCount());
michael@0:     (void) slices.append(data); /* Ignore any OOMs here. */
michael@0: 
michael@0:     if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback)
michael@0:         (*cb)(JS_TELEMETRY_GC_REASON, reason);
michael@0: 
michael@0:     // Slice callbacks should only fire for the outermost level
michael@0:     if (++gcDepth == 1) {
michael@0:         bool wasFullGC = collectedCount == zoneCount;
michael@0:         if (JS::GCSliceCallback cb = runtime->gcSliceCallback)
michael@0:             (*cb)(runtime, first ? JS::GC_CYCLE_BEGIN : JS::GC_SLICE_BEGIN,
michael@0:                   JS::GCDescription(!wasFullGC));
michael@0:     }
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::endSlice()
michael@0: {
michael@0:     slices.back().end = PRMJ_Now();
michael@0:     slices.back().endFaults = gc::GetPageFaultCount();
michael@0: 
michael@0:     if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback) {
michael@0:         (*cb)(JS_TELEMETRY_GC_SLICE_MS, t(slices.back().end - slices.back().start));
michael@0:         (*cb)(JS_TELEMETRY_GC_RESET, !!slices.back().resetReason);
michael@0:     }
michael@0: 
michael@0:     bool last = runtime->gcIncrementalState == gc::NO_INCREMENTAL;
michael@0:     if (last)
michael@0:         endGC();
michael@0: 
michael@0:     // Slice callbacks should only fire for the outermost level
michael@0:     if (--gcDepth == 0) {
michael@0:         bool wasFullGC = collectedCount == zoneCount;
michael@0:         if (JS::GCSliceCallback cb = runtime->gcSliceCallback)
michael@0:             (*cb)(runtime, last ? JS::GC_CYCLE_END : JS::GC_SLICE_END,
michael@0:                   JS::GCDescription(!wasFullGC));
michael@0:     }
michael@0: 
michael@0:     /* Do this after the slice callback since it uses these values. */
michael@0:     if (last)
michael@0:         PodArrayZero(counts);
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::beginPhase(Phase phase)
michael@0: {
michael@0:     /* Guard against re-entry */
michael@0:     JS_ASSERT(!phaseStartTimes[phase]);
michael@0: 
michael@0: #ifdef DEBUG
michael@0:     JS_ASSERT(phases[phase].index == phase);
michael@0:     Phase parent = phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : PHASE_NO_PARENT;
michael@0:     JS_ASSERT(phaseNestingDepth < MAX_NESTING);
michael@0:     JS_ASSERT_IF(gcDepth == 1, phases[phase].parent == parent);
michael@0:     phaseNesting[phaseNestingDepth] = phase;
michael@0:     phaseNestingDepth++;
michael@0: #endif
michael@0: 
michael@0:     phaseStartTimes[phase] = PRMJ_Now();
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::endPhase(Phase phase)
michael@0: {
michael@0:     phaseNestingDepth--;
michael@0: 
michael@0:     int64_t t = PRMJ_Now() - phaseStartTimes[phase];
michael@0:     slices.back().phaseTimes[phase] += t;
michael@0:     phaseTimes[phase] += t;
michael@0:     phaseStartTimes[phase] = 0;
michael@0: }
michael@0: 
michael@0: int64_t
michael@0: Statistics::beginSCC()
michael@0: {
michael@0:     return PRMJ_Now();
michael@0: }
michael@0: 
michael@0: void
michael@0: Statistics::endSCC(unsigned scc, int64_t start)
michael@0: {
michael@0:     if (scc >= sccTimes.length() && !sccTimes.resize(scc + 1))
michael@0:         return;
michael@0: 
michael@0:     sccTimes[scc] += PRMJ_Now() - start;
michael@0: }
michael@0: 
michael@0: /*
michael@0:  * MMU (minimum mutator utilization) is a measure of how much garbage collection
michael@0:  * is affecting the responsiveness of the system. MMU measurements are given
michael@0:  * with respect to a certain window size. If we report MMU(50ms) = 80%, then
michael@0:  * that means that, for any 50ms window of time, at least 80% of the window is
michael@0:  * devoted to the mutator. In other words, the GC is running for at most 20% of
michael@0:  * the window, or 10ms. The GC can run multiple slices during the 50ms window
michael@0:  * as long as the total time it spends is at most 10ms.
michael@0:  */
michael@0: double
michael@0: Statistics::computeMMU(int64_t window)
michael@0: {
michael@0:     JS_ASSERT(!slices.empty());
michael@0: 
michael@0:     int64_t gc = slices[0].end - slices[0].start;
michael@0:     int64_t gcMax = gc;
michael@0: 
michael@0:     if (gc >= window)
michael@0:         return 0.0;
michael@0: 
michael@0:     int startIndex = 0;
michael@0:     for (size_t endIndex = 1; endIndex < slices.length(); endIndex++) {
michael@0:         gc += slices[endIndex].end - slices[endIndex].start;
michael@0: 
michael@0:         while (slices[endIndex].end - slices[startIndex].end >= window) {
michael@0:             gc -= slices[startIndex].end - slices[startIndex].start;
michael@0:             startIndex++;
michael@0:         }
michael@0: 
michael@0:         int64_t cur = gc;
michael@0:         if (slices[endIndex].end - slices[startIndex].start > window)
michael@0:             cur -= (slices[endIndex].end - slices[startIndex].start - window);
michael@0:         if (cur > gcMax)
michael@0:             gcMax = cur;
michael@0:     }
michael@0: 
michael@0:     return double(window - gcMax) / window;
michael@0: }