1.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000
1.2 +++ b/js/src/gc/Statistics.cpp Wed Dec 31 06:09:35 2014 +0100
1.3 @@ -0,0 +1,698 @@
1.4 +/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*-
1.5 + * vim: set ts=8 sts=4 et sw=4 tw=99:
1.6 + * This Source Code Form is subject to the terms of the Mozilla Public
1.7 + * License, v. 2.0. If a copy of the MPL was not distributed with this
1.8 + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
1.9 +
1.10 +#include "gc/Statistics.h"
1.11 +
1.12 +#include "mozilla/PodOperations.h"
1.13 +
1.14 +#include <ctype.h>
1.15 +#include <stdarg.h>
1.16 +#include <stdio.h>
1.17 +
1.18 +#include "jscrashreport.h"
1.19 +#include "jsprf.h"
1.20 +#include "jsutil.h"
1.21 +#include "prmjtime.h"
1.22 +
1.23 +#include "gc/Memory.h"
1.24 +#include "vm/Runtime.h"
1.25 +
1.26 +using namespace js;
1.27 +using namespace js::gcstats;
1.28 +
1.29 +using mozilla::PodArrayZero;
1.30 +
1.31 +/* Except for the first and last, slices of less than 42ms are not reported. */
1.32 +static const int64_t SLICE_MIN_REPORT_TIME = 42 * PRMJ_USEC_PER_MSEC;
1.33 +
1.34 +class gcstats::StatisticsSerializer
1.35 +{
1.36 + typedef Vector<char, 128, SystemAllocPolicy> CharBuffer;
1.37 + CharBuffer buf_;
1.38 + bool asJSON_;
1.39 + bool needComma_;
1.40 + bool oom_;
1.41 +
1.42 + static const int MaxFieldValueLength = 128;
1.43 +
1.44 + public:
1.45 + enum Mode {
1.46 + AsJSON = true,
1.47 + AsText = false
1.48 + };
1.49 +
1.50 + StatisticsSerializer(Mode asJSON)
1.51 + : buf_(), asJSON_(asJSON), needComma_(false), oom_(false)
1.52 + {}
1.53 +
1.54 + bool isJSON() { return asJSON_; }
1.55 +
1.56 + bool isOOM() { return oom_; }
1.57 +
1.58 + void endLine() {
1.59 + if (!asJSON_) {
1.60 + p("\n");
1.61 + needComma_ = false;
1.62 + }
1.63 + }
1.64 +
1.65 + void extra(const char *str) {
1.66 + if (!asJSON_) {
1.67 + needComma_ = false;
1.68 + p(str);
1.69 + }
1.70 + }
1.71 +
1.72 + void appendString(const char *name, const char *value) {
1.73 + put(name, value, "", true);
1.74 + }
1.75 +
1.76 + void appendNumber(const char *name, const char *vfmt, const char *units, ...) {
1.77 + va_list va;
1.78 + va_start(va, units);
1.79 + append(name, vfmt, va, units);
1.80 + va_end(va);
1.81 + }
1.82 +
1.83 + void appendDecimal(const char *name, const char *units, double d) {
1.84 + if (d < 0)
1.85 + d = 0;
1.86 + if (asJSON_)
1.87 + appendNumber(name, "%d.%d", units, (int)d, (int)(d * 10.) % 10);
1.88 + else
1.89 + appendNumber(name, "%.1f", units, d);
1.90 + }
1.91 +
1.92 + void appendIfNonzeroMS(const char *name, double v) {
1.93 + if (asJSON_ || v >= 0.1)
1.94 + appendDecimal(name, "ms", v);
1.95 + }
1.96 +
1.97 + void beginObject(const char *name) {
1.98 + if (needComma_)
1.99 + pJSON(", ");
1.100 + if (asJSON_ && name) {
1.101 + putKey(name);
1.102 + pJSON(": ");
1.103 + }
1.104 + pJSON("{");
1.105 + needComma_ = false;
1.106 + }
1.107 +
1.108 + void endObject() {
1.109 + needComma_ = false;
1.110 + pJSON("}");
1.111 + needComma_ = true;
1.112 + }
1.113 +
1.114 + void beginArray(const char *name) {
1.115 + if (needComma_)
1.116 + pJSON(", ");
1.117 + if (asJSON_)
1.118 + putKey(name);
1.119 + pJSON(": [");
1.120 + needComma_ = false;
1.121 + }
1.122 +
1.123 + void endArray() {
1.124 + needComma_ = false;
1.125 + pJSON("]");
1.126 + needComma_ = true;
1.127 + }
1.128 +
1.129 + jschar *finishJSString() {
1.130 + char *buf = finishCString();
1.131 + if (!buf)
1.132 + return nullptr;
1.133 +
1.134 + size_t nchars = strlen(buf);
1.135 + jschar *out = js_pod_malloc<jschar>(nchars + 1);
1.136 + if (!out) {
1.137 + oom_ = true;
1.138 + js_free(buf);
1.139 + return nullptr;
1.140 + }
1.141 +
1.142 + InflateStringToBuffer(buf, nchars, out);
1.143 + js_free(buf);
1.144 +
1.145 + out[nchars] = 0;
1.146 + return out;
1.147 + }
1.148 +
1.149 + char *finishCString() {
1.150 + if (oom_)
1.151 + return nullptr;
1.152 +
1.153 + buf_.append('\0');
1.154 +
1.155 + char *buf = buf_.extractRawBuffer();
1.156 + if (!buf)
1.157 + oom_ = true;
1.158 +
1.159 + return buf;
1.160 + }
1.161 +
1.162 + private:
1.163 + void append(const char *name, const char *vfmt,
1.164 + va_list va, const char *units)
1.165 + {
1.166 + char val[MaxFieldValueLength];
1.167 + JS_vsnprintf(val, MaxFieldValueLength, vfmt, va);
1.168 + put(name, val, units, false);
1.169 + }
1.170 +
1.171 + void p(const char *cstr) {
1.172 + if (oom_)
1.173 + return;
1.174 +
1.175 + if (!buf_.append(cstr, strlen(cstr)))
1.176 + oom_ = true;
1.177 + }
1.178 +
1.179 + void p(const char c) {
1.180 + if (oom_)
1.181 + return;
1.182 +
1.183 + if (!buf_.append(c))
1.184 + oom_ = true;
1.185 + }
1.186 +
1.187 + void pJSON(const char *str) {
1.188 + if (asJSON_)
1.189 + p(str);
1.190 + }
1.191 +
1.192 + void put(const char *name, const char *val, const char *units, bool valueIsQuoted) {
1.193 + if (needComma_)
1.194 + p(", ");
1.195 + needComma_ = true;
1.196 +
1.197 + putKey(name);
1.198 + p(": ");
1.199 + if (valueIsQuoted)
1.200 + putQuoted(val);
1.201 + else
1.202 + p(val);
1.203 + if (!asJSON_)
1.204 + p(units);
1.205 + }
1.206 +
1.207 + void putQuoted(const char *str) {
1.208 + pJSON("\"");
1.209 + p(str);
1.210 + pJSON("\"");
1.211 + }
1.212 +
1.213 + void putKey(const char *str) {
1.214 + if (!asJSON_) {
1.215 + p(str);
1.216 + return;
1.217 + }
1.218 +
1.219 + p("\"");
1.220 + const char *c = str;
1.221 + while (*c) {
1.222 + if (*c == ' ' || *c == '\t')
1.223 + p('_');
1.224 + else if (isupper(*c))
1.225 + p(tolower(*c));
1.226 + else if (*c == '+')
1.227 + p("added_");
1.228 + else if (*c == '-')
1.229 + p("removed_");
1.230 + else if (*c != '(' && *c != ')')
1.231 + p(*c);
1.232 + c++;
1.233 + }
1.234 + p("\"");
1.235 + }
1.236 +};
1.237 +
1.238 +/*
1.239 + * If this fails, then you can either delete this assertion and allow all
1.240 + * larger-numbered reasons to pile up in the last telemetry bucket, or switch
1.241 + * to GC_REASON_3 and bump the max value.
1.242 + */
1.243 +JS_STATIC_ASSERT(JS::gcreason::NUM_TELEMETRY_REASONS >= JS::gcreason::NUM_REASONS);
1.244 +
1.245 +const char *
1.246 +js::gcstats::ExplainReason(JS::gcreason::Reason reason)
1.247 +{
1.248 + switch (reason) {
1.249 +#define SWITCH_REASON(name) \
1.250 + case JS::gcreason::name: \
1.251 + return #name;
1.252 + GCREASONS(SWITCH_REASON)
1.253 +
1.254 + default:
1.255 + MOZ_ASSUME_UNREACHABLE("bad GC reason");
1.256 +#undef SWITCH_REASON
1.257 + }
1.258 +}
1.259 +
1.260 +static double
1.261 +t(int64_t t)
1.262 +{
1.263 + return double(t) / PRMJ_USEC_PER_MSEC;
1.264 +}
1.265 +
1.266 +struct PhaseInfo
1.267 +{
1.268 + Phase index;
1.269 + const char *name;
1.270 + Phase parent;
1.271 +};
1.272 +
1.273 +static const Phase PHASE_NO_PARENT = PHASE_LIMIT;
1.274 +
1.275 +static const PhaseInfo phases[] = {
1.276 + { PHASE_GC_BEGIN, "Begin Callback", PHASE_NO_PARENT },
1.277 + { PHASE_WAIT_BACKGROUND_THREAD, "Wait Background Thread", PHASE_NO_PARENT },
1.278 + { PHASE_MARK_DISCARD_CODE, "Mark Discard Code", PHASE_NO_PARENT },
1.279 + { PHASE_PURGE, "Purge", PHASE_NO_PARENT },
1.280 + { PHASE_MARK, "Mark", PHASE_NO_PARENT },
1.281 + { PHASE_MARK_ROOTS, "Mark Roots", PHASE_MARK },
1.282 + { PHASE_MARK_DELAYED, "Mark Delayed", PHASE_MARK },
1.283 + { PHASE_SWEEP, "Sweep", PHASE_NO_PARENT },
1.284 + { PHASE_SWEEP_MARK, "Mark During Sweeping", PHASE_SWEEP },
1.285 + { PHASE_SWEEP_MARK_TYPES, "Mark Types During Sweeping", PHASE_SWEEP_MARK },
1.286 + { PHASE_SWEEP_MARK_INCOMING_BLACK, "Mark Incoming Black Pointers", PHASE_SWEEP_MARK },
1.287 + { PHASE_SWEEP_MARK_WEAK, "Mark Weak", PHASE_SWEEP_MARK },
1.288 + { PHASE_SWEEP_MARK_INCOMING_GRAY, "Mark Incoming Gray Pointers", PHASE_SWEEP_MARK },
1.289 + { PHASE_SWEEP_MARK_GRAY, "Mark Gray", PHASE_SWEEP_MARK },
1.290 + { PHASE_SWEEP_MARK_GRAY_WEAK, "Mark Gray and Weak", PHASE_SWEEP_MARK },
1.291 + { PHASE_FINALIZE_START, "Finalize Start Callback", PHASE_SWEEP },
1.292 + { PHASE_SWEEP_ATOMS, "Sweep Atoms", PHASE_SWEEP },
1.293 + { PHASE_SWEEP_COMPARTMENTS, "Sweep Compartments", PHASE_SWEEP },
1.294 + { PHASE_SWEEP_DISCARD_CODE, "Sweep Discard Code", PHASE_SWEEP_COMPARTMENTS },
1.295 + { PHASE_SWEEP_TABLES, "Sweep Tables", PHASE_SWEEP_COMPARTMENTS },
1.296 + { PHASE_SWEEP_TABLES_WRAPPER, "Sweep Cross Compartment Wrappers", PHASE_SWEEP_TABLES },
1.297 + { PHASE_SWEEP_TABLES_BASE_SHAPE, "Sweep Base Shapes", PHASE_SWEEP_TABLES },
1.298 + { PHASE_SWEEP_TABLES_INITIAL_SHAPE, "Sweep Initial Shapes", PHASE_SWEEP_TABLES },
1.299 + { PHASE_SWEEP_TABLES_TYPE_OBJECT, "Sweep Type Objects", PHASE_SWEEP_TABLES },
1.300 + { PHASE_SWEEP_TABLES_BREAKPOINT, "Sweep Breakpoints", PHASE_SWEEP_TABLES },
1.301 + { PHASE_SWEEP_TABLES_REGEXP, "Sweep Regexps", PHASE_SWEEP_TABLES },
1.302 + { PHASE_DISCARD_ANALYSIS, "Discard Analysis", PHASE_SWEEP_COMPARTMENTS },
1.303 + { PHASE_DISCARD_TI, "Discard TI", PHASE_DISCARD_ANALYSIS },
1.304 + { PHASE_FREE_TI_ARENA, "Free TI Arena", PHASE_DISCARD_ANALYSIS },
1.305 + { PHASE_SWEEP_TYPES, "Sweep Types", PHASE_DISCARD_ANALYSIS },
1.306 + { PHASE_SWEEP_OBJECT, "Sweep Object", PHASE_SWEEP },
1.307 + { PHASE_SWEEP_STRING, "Sweep String", PHASE_SWEEP },
1.308 + { PHASE_SWEEP_SCRIPT, "Sweep Script", PHASE_SWEEP },
1.309 + { PHASE_SWEEP_SHAPE, "Sweep Shape", PHASE_SWEEP },
1.310 + { PHASE_SWEEP_JITCODE, "Sweep JIT code", PHASE_SWEEP },
1.311 + { PHASE_FINALIZE_END, "Finalize End Callback", PHASE_SWEEP },
1.312 + { PHASE_DESTROY, "Deallocate", PHASE_SWEEP },
1.313 + { PHASE_GC_END, "End Callback", PHASE_NO_PARENT },
1.314 + { PHASE_LIMIT, nullptr, PHASE_NO_PARENT }
1.315 +};
1.316 +
1.317 +static void
1.318 +FormatPhaseTimes(StatisticsSerializer &ss, const char *name, int64_t *times)
1.319 +{
1.320 + ss.beginObject(name);
1.321 + for (unsigned i = 0; phases[i].name; i++)
1.322 + ss.appendIfNonzeroMS(phases[i].name, t(times[phases[i].index]));
1.323 + ss.endObject();
1.324 +}
1.325 +
1.326 +void
1.327 +Statistics::gcDuration(int64_t *total, int64_t *maxPause)
1.328 +{
1.329 + *total = *maxPause = 0;
1.330 + for (SliceData *slice = slices.begin(); slice != slices.end(); slice++) {
1.331 + *total += slice->duration();
1.332 + if (slice->duration() > *maxPause)
1.333 + *maxPause = slice->duration();
1.334 + }
1.335 +}
1.336 +
1.337 +void
1.338 +Statistics::sccDurations(int64_t *total, int64_t *maxPause)
1.339 +{
1.340 + *total = *maxPause = 0;
1.341 + for (size_t i = 0; i < sccTimes.length(); i++) {
1.342 + *total += sccTimes[i];
1.343 + *maxPause = Max(*maxPause, sccTimes[i]);
1.344 + }
1.345 +}
1.346 +
1.347 +bool
1.348 +Statistics::formatData(StatisticsSerializer &ss, uint64_t timestamp)
1.349 +{
1.350 + int64_t total, longest;
1.351 + gcDuration(&total, &longest);
1.352 +
1.353 + int64_t sccTotal, sccLongest;
1.354 + sccDurations(&sccTotal, &sccLongest);
1.355 +
1.356 + double mmu20 = computeMMU(20 * PRMJ_USEC_PER_MSEC);
1.357 + double mmu50 = computeMMU(50 * PRMJ_USEC_PER_MSEC);
1.358 +
1.359 + ss.beginObject(nullptr);
1.360 + if (ss.isJSON())
1.361 + ss.appendNumber("Timestamp", "%llu", "", (unsigned long long)timestamp);
1.362 + if (slices.length() > 1 || ss.isJSON())
1.363 + ss.appendDecimal("Max Pause", "ms", t(longest));
1.364 + else
1.365 + ss.appendString("Reason", ExplainReason(slices[0].reason));
1.366 + ss.appendDecimal("Total Time", "ms", t(total));
1.367 + ss.appendNumber("Zones Collected", "%d", "", collectedCount);
1.368 + ss.appendNumber("Total Zones", "%d", "", zoneCount);
1.369 + ss.appendNumber("Total Compartments", "%d", "", compartmentCount);
1.370 + ss.appendNumber("Minor GCs", "%d", "", counts[STAT_MINOR_GC]);
1.371 + ss.appendNumber("MMU (20ms)", "%d", "%", int(mmu20 * 100));
1.372 + ss.appendNumber("MMU (50ms)", "%d", "%", int(mmu50 * 100));
1.373 + ss.appendDecimal("SCC Sweep Total", "ms", t(sccTotal));
1.374 + ss.appendDecimal("SCC Sweep Max Pause", "ms", t(sccLongest));
1.375 + if (nonincrementalReason || ss.isJSON()) {
1.376 + ss.appendString("Nonincremental Reason",
1.377 + nonincrementalReason ? nonincrementalReason : "none");
1.378 + }
1.379 + ss.appendNumber("Allocated", "%u", "MB", unsigned(preBytes / 1024 / 1024));
1.380 + ss.appendNumber("+Chunks", "%d", "", counts[STAT_NEW_CHUNK]);
1.381 + ss.appendNumber("-Chunks", "%d", "", counts[STAT_DESTROY_CHUNK]);
1.382 + ss.endLine();
1.383 +
1.384 + if (slices.length() > 1 || ss.isJSON()) {
1.385 + ss.beginArray("Slices");
1.386 + for (size_t i = 0; i < slices.length(); i++) {
1.387 + int64_t width = slices[i].duration();
1.388 + if (i != 0 && i != slices.length() - 1 && width < SLICE_MIN_REPORT_TIME &&
1.389 + !slices[i].resetReason && !ss.isJSON())
1.390 + {
1.391 + continue;
1.392 + }
1.393 +
1.394 + ss.beginObject(nullptr);
1.395 + ss.extra(" ");
1.396 + ss.appendNumber("Slice", "%d", "", i);
1.397 + ss.appendDecimal("Pause", "", t(width));
1.398 + ss.extra(" (");
1.399 + ss.appendDecimal("When", "ms", t(slices[i].start - slices[0].start));
1.400 + ss.appendString("Reason", ExplainReason(slices[i].reason));
1.401 + if (ss.isJSON()) {
1.402 + ss.appendDecimal("Page Faults", "",
1.403 + double(slices[i].endFaults - slices[i].startFaults));
1.404 +
1.405 + ss.appendNumber("Start Timestamp", "%llu", "", (unsigned long long)slices[i].start);
1.406 + ss.appendNumber("End Timestamp", "%llu", "", (unsigned long long)slices[i].end);
1.407 + }
1.408 + if (slices[i].resetReason)
1.409 + ss.appendString("Reset", slices[i].resetReason);
1.410 + ss.extra("): ");
1.411 + FormatPhaseTimes(ss, "Times", slices[i].phaseTimes);
1.412 + ss.endLine();
1.413 + ss.endObject();
1.414 + }
1.415 + ss.endArray();
1.416 + }
1.417 + ss.extra(" Totals: ");
1.418 + FormatPhaseTimes(ss, "Totals", phaseTimes);
1.419 + ss.endObject();
1.420 +
1.421 + return !ss.isOOM();
1.422 +}
1.423 +
1.424 +jschar *
1.425 +Statistics::formatMessage()
1.426 +{
1.427 + StatisticsSerializer ss(StatisticsSerializer::AsText);
1.428 + formatData(ss, 0);
1.429 + return ss.finishJSString();
1.430 +}
1.431 +
1.432 +jschar *
1.433 +Statistics::formatJSON(uint64_t timestamp)
1.434 +{
1.435 + StatisticsSerializer ss(StatisticsSerializer::AsJSON);
1.436 + formatData(ss, timestamp);
1.437 + return ss.finishJSString();
1.438 +}
1.439 +
1.440 +Statistics::Statistics(JSRuntime *rt)
1.441 + : runtime(rt),
1.442 + startupTime(PRMJ_Now()),
1.443 + fp(nullptr),
1.444 + fullFormat(false),
1.445 + gcDepth(0),
1.446 + collectedCount(0),
1.447 + zoneCount(0),
1.448 + compartmentCount(0),
1.449 + nonincrementalReason(nullptr),
1.450 + preBytes(0),
1.451 + phaseNestingDepth(0)
1.452 +{
1.453 + PodArrayZero(phaseTotals);
1.454 + PodArrayZero(counts);
1.455 +
1.456 + char *env = getenv("MOZ_GCTIMER");
1.457 + if (!env || strcmp(env, "none") == 0) {
1.458 + fp = nullptr;
1.459 + return;
1.460 + }
1.461 +
1.462 + if (strcmp(env, "stdout") == 0) {
1.463 + fullFormat = false;
1.464 + fp = stdout;
1.465 + } else if (strcmp(env, "stderr") == 0) {
1.466 + fullFormat = false;
1.467 + fp = stderr;
1.468 + } else {
1.469 + fullFormat = true;
1.470 +
1.471 + fp = fopen(env, "a");
1.472 + JS_ASSERT(fp);
1.473 + }
1.474 +}
1.475 +
1.476 +Statistics::~Statistics()
1.477 +{
1.478 + if (fp) {
1.479 + if (fullFormat) {
1.480 + StatisticsSerializer ss(StatisticsSerializer::AsText);
1.481 + FormatPhaseTimes(ss, "", phaseTotals);
1.482 + char *msg = ss.finishCString();
1.483 + if (msg) {
1.484 + fprintf(fp, "TOTALS\n%s\n\n-------\n", msg);
1.485 + js_free(msg);
1.486 + }
1.487 + }
1.488 +
1.489 + if (fp != stdout && fp != stderr)
1.490 + fclose(fp);
1.491 + }
1.492 +}
1.493 +
1.494 +void
1.495 +Statistics::printStats()
1.496 +{
1.497 + if (fullFormat) {
1.498 + StatisticsSerializer ss(StatisticsSerializer::AsText);
1.499 + formatData(ss, 0);
1.500 + char *msg = ss.finishCString();
1.501 + if (msg) {
1.502 + fprintf(fp, "GC(T+%.3fs) %s\n", t(slices[0].start - startupTime) / 1000.0, msg);
1.503 + js_free(msg);
1.504 + }
1.505 + } else {
1.506 + int64_t total, longest;
1.507 + gcDuration(&total, &longest);
1.508 +
1.509 + fprintf(fp, "%f %f %f\n",
1.510 + t(total),
1.511 + t(phaseTimes[PHASE_MARK]),
1.512 + t(phaseTimes[PHASE_SWEEP]));
1.513 + }
1.514 + fflush(fp);
1.515 +}
1.516 +
1.517 +void
1.518 +Statistics::beginGC()
1.519 +{
1.520 + PodArrayZero(phaseStartTimes);
1.521 + PodArrayZero(phaseTimes);
1.522 +
1.523 + slices.clearAndFree();
1.524 + sccTimes.clearAndFree();
1.525 + nonincrementalReason = nullptr;
1.526 +
1.527 + preBytes = runtime->gcBytes;
1.528 +}
1.529 +
1.530 +void
1.531 +Statistics::endGC()
1.532 +{
1.533 + crash::SnapshotGCStack();
1.534 +
1.535 + for (int i = 0; i < PHASE_LIMIT; i++)
1.536 + phaseTotals[i] += phaseTimes[i];
1.537 +
1.538 + if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback) {
1.539 + int64_t total, longest;
1.540 + gcDuration(&total, &longest);
1.541 +
1.542 + int64_t sccTotal, sccLongest;
1.543 + sccDurations(&sccTotal, &sccLongest);
1.544 +
1.545 + (*cb)(JS_TELEMETRY_GC_IS_COMPARTMENTAL, collectedCount == zoneCount ? 0 : 1);
1.546 + (*cb)(JS_TELEMETRY_GC_MS, t(total));
1.547 + (*cb)(JS_TELEMETRY_GC_MAX_PAUSE_MS, t(longest));
1.548 + (*cb)(JS_TELEMETRY_GC_MARK_MS, t(phaseTimes[PHASE_MARK]));
1.549 + (*cb)(JS_TELEMETRY_GC_SWEEP_MS, t(phaseTimes[PHASE_SWEEP]));
1.550 + (*cb)(JS_TELEMETRY_GC_MARK_ROOTS_MS, t(phaseTimes[PHASE_MARK_ROOTS]));
1.551 + (*cb)(JS_TELEMETRY_GC_MARK_GRAY_MS, t(phaseTimes[PHASE_SWEEP_MARK_GRAY]));
1.552 + (*cb)(JS_TELEMETRY_GC_NON_INCREMENTAL, !!nonincrementalReason);
1.553 + (*cb)(JS_TELEMETRY_GC_INCREMENTAL_DISABLED, !runtime->gcIncrementalEnabled);
1.554 + (*cb)(JS_TELEMETRY_GC_SCC_SWEEP_TOTAL_MS, t(sccTotal));
1.555 + (*cb)(JS_TELEMETRY_GC_SCC_SWEEP_MAX_PAUSE_MS, t(sccLongest));
1.556 +
1.557 + double mmu50 = computeMMU(50 * PRMJ_USEC_PER_MSEC);
1.558 + (*cb)(JS_TELEMETRY_GC_MMU_50, mmu50 * 100);
1.559 + }
1.560 +
1.561 + if (fp)
1.562 + printStats();
1.563 +}
1.564 +
1.565 +void
1.566 +Statistics::beginSlice(int collectedCount, int zoneCount, int compartmentCount,
1.567 + JS::gcreason::Reason reason)
1.568 +{
1.569 + this->collectedCount = collectedCount;
1.570 + this->zoneCount = zoneCount;
1.571 + this->compartmentCount = compartmentCount;
1.572 +
1.573 + bool first = runtime->gcIncrementalState == gc::NO_INCREMENTAL;
1.574 + if (first)
1.575 + beginGC();
1.576 +
1.577 + SliceData data(reason, PRMJ_Now(), gc::GetPageFaultCount());
1.578 + (void) slices.append(data); /* Ignore any OOMs here. */
1.579 +
1.580 + if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback)
1.581 + (*cb)(JS_TELEMETRY_GC_REASON, reason);
1.582 +
1.583 + // Slice callbacks should only fire for the outermost level
1.584 + if (++gcDepth == 1) {
1.585 + bool wasFullGC = collectedCount == zoneCount;
1.586 + if (JS::GCSliceCallback cb = runtime->gcSliceCallback)
1.587 + (*cb)(runtime, first ? JS::GC_CYCLE_BEGIN : JS::GC_SLICE_BEGIN,
1.588 + JS::GCDescription(!wasFullGC));
1.589 + }
1.590 +}
1.591 +
1.592 +void
1.593 +Statistics::endSlice()
1.594 +{
1.595 + slices.back().end = PRMJ_Now();
1.596 + slices.back().endFaults = gc::GetPageFaultCount();
1.597 +
1.598 + if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback) {
1.599 + (*cb)(JS_TELEMETRY_GC_SLICE_MS, t(slices.back().end - slices.back().start));
1.600 + (*cb)(JS_TELEMETRY_GC_RESET, !!slices.back().resetReason);
1.601 + }
1.602 +
1.603 + bool last = runtime->gcIncrementalState == gc::NO_INCREMENTAL;
1.604 + if (last)
1.605 + endGC();
1.606 +
1.607 + // Slice callbacks should only fire for the outermost level
1.608 + if (--gcDepth == 0) {
1.609 + bool wasFullGC = collectedCount == zoneCount;
1.610 + if (JS::GCSliceCallback cb = runtime->gcSliceCallback)
1.611 + (*cb)(runtime, last ? JS::GC_CYCLE_END : JS::GC_SLICE_END,
1.612 + JS::GCDescription(!wasFullGC));
1.613 + }
1.614 +
1.615 + /* Do this after the slice callback since it uses these values. */
1.616 + if (last)
1.617 + PodArrayZero(counts);
1.618 +}
1.619 +
1.620 +void
1.621 +Statistics::beginPhase(Phase phase)
1.622 +{
1.623 + /* Guard against re-entry */
1.624 + JS_ASSERT(!phaseStartTimes[phase]);
1.625 +
1.626 +#ifdef DEBUG
1.627 + JS_ASSERT(phases[phase].index == phase);
1.628 + Phase parent = phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : PHASE_NO_PARENT;
1.629 + JS_ASSERT(phaseNestingDepth < MAX_NESTING);
1.630 + JS_ASSERT_IF(gcDepth == 1, phases[phase].parent == parent);
1.631 + phaseNesting[phaseNestingDepth] = phase;
1.632 + phaseNestingDepth++;
1.633 +#endif
1.634 +
1.635 + phaseStartTimes[phase] = PRMJ_Now();
1.636 +}
1.637 +
1.638 +void
1.639 +Statistics::endPhase(Phase phase)
1.640 +{
1.641 + phaseNestingDepth--;
1.642 +
1.643 + int64_t t = PRMJ_Now() - phaseStartTimes[phase];
1.644 + slices.back().phaseTimes[phase] += t;
1.645 + phaseTimes[phase] += t;
1.646 + phaseStartTimes[phase] = 0;
1.647 +}
1.648 +
1.649 +int64_t
1.650 +Statistics::beginSCC()
1.651 +{
1.652 + return PRMJ_Now();
1.653 +}
1.654 +
1.655 +void
1.656 +Statistics::endSCC(unsigned scc, int64_t start)
1.657 +{
1.658 + if (scc >= sccTimes.length() && !sccTimes.resize(scc + 1))
1.659 + return;
1.660 +
1.661 + sccTimes[scc] += PRMJ_Now() - start;
1.662 +}
1.663 +
1.664 +/*
1.665 + * MMU (minimum mutator utilization) is a measure of how much garbage collection
1.666 + * is affecting the responsiveness of the system. MMU measurements are given
1.667 + * with respect to a certain window size. If we report MMU(50ms) = 80%, then
1.668 + * that means that, for any 50ms window of time, at least 80% of the window is
1.669 + * devoted to the mutator. In other words, the GC is running for at most 20% of
1.670 + * the window, or 10ms. The GC can run multiple slices during the 50ms window
1.671 + * as long as the total time it spends is at most 10ms.
1.672 + */
1.673 +double
1.674 +Statistics::computeMMU(int64_t window)
1.675 +{
1.676 + JS_ASSERT(!slices.empty());
1.677 +
1.678 + int64_t gc = slices[0].end - slices[0].start;
1.679 + int64_t gcMax = gc;
1.680 +
1.681 + if (gc >= window)
1.682 + return 0.0;
1.683 +
1.684 + int startIndex = 0;
1.685 + for (size_t endIndex = 1; endIndex < slices.length(); endIndex++) {
1.686 + gc += slices[endIndex].end - slices[endIndex].start;
1.687 +
1.688 + while (slices[endIndex].end - slices[startIndex].end >= window) {
1.689 + gc -= slices[startIndex].end - slices[startIndex].start;
1.690 + startIndex++;
1.691 + }
1.692 +
1.693 + int64_t cur = gc;
1.694 + if (slices[endIndex].end - slices[startIndex].start > window)
1.695 + cur -= (slices[endIndex].end - slices[startIndex].start - window);
1.696 + if (cur > gcMax)
1.697 + gcMax = cur;
1.698 + }
1.699 +
1.700 + return double(window - gcMax) / window;
1.701 +}
