Wed, 31 Dec 2014 06:09:35 +0100
Cloned upstream origin tor-browser at tor-browser-31.3.0esr-4.5-1-build1
revision ID fc1c9ff7c1b2defdbc039f12214767608f46423f for hacking purpose.
michael@0 | 1 | /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 4 -*- |
michael@0 | 2 | * vim: set ts=8 sts=4 et sw=4 tw=99: |
michael@0 | 3 | * This Source Code Form is subject to the terms of the Mozilla Public |
michael@0 | 4 | * License, v. 2.0. If a copy of the MPL was not distributed with this |
michael@0 | 5 | * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ |
michael@0 | 6 | |
michael@0 | 7 | #include "gc/Statistics.h" |
michael@0 | 8 | |
michael@0 | 9 | #include "mozilla/PodOperations.h" |
michael@0 | 10 | |
michael@0 | 11 | #include <ctype.h> |
michael@0 | 12 | #include <stdarg.h> |
michael@0 | 13 | #include <stdio.h> |
michael@0 | 14 | |
michael@0 | 15 | #include "jscrashreport.h" |
michael@0 | 16 | #include "jsprf.h" |
michael@0 | 17 | #include "jsutil.h" |
michael@0 | 18 | #include "prmjtime.h" |
michael@0 | 19 | |
michael@0 | 20 | #include "gc/Memory.h" |
michael@0 | 21 | #include "vm/Runtime.h" |
michael@0 | 22 | |
michael@0 | 23 | using namespace js; |
michael@0 | 24 | using namespace js::gcstats; |
michael@0 | 25 | |
michael@0 | 26 | using mozilla::PodArrayZero; |
michael@0 | 27 | |
michael@0 | 28 | /* Except for the first and last, slices of less than 42ms are not reported. */ |
michael@0 | 29 | static const int64_t SLICE_MIN_REPORT_TIME = 42 * PRMJ_USEC_PER_MSEC; |
michael@0 | 30 | |
michael@0 | 31 | class gcstats::StatisticsSerializer |
michael@0 | 32 | { |
michael@0 | 33 | typedef Vector<char, 128, SystemAllocPolicy> CharBuffer; |
michael@0 | 34 | CharBuffer buf_; |
michael@0 | 35 | bool asJSON_; |
michael@0 | 36 | bool needComma_; |
michael@0 | 37 | bool oom_; |
michael@0 | 38 | |
michael@0 | 39 | static const int MaxFieldValueLength = 128; |
michael@0 | 40 | |
michael@0 | 41 | public: |
michael@0 | 42 | enum Mode { |
michael@0 | 43 | AsJSON = true, |
michael@0 | 44 | AsText = false |
michael@0 | 45 | }; |
michael@0 | 46 | |
michael@0 | 47 | StatisticsSerializer(Mode asJSON) |
michael@0 | 48 | : buf_(), asJSON_(asJSON), needComma_(false), oom_(false) |
michael@0 | 49 | {} |
michael@0 | 50 | |
michael@0 | 51 | bool isJSON() { return asJSON_; } |
michael@0 | 52 | |
michael@0 | 53 | bool isOOM() { return oom_; } |
michael@0 | 54 | |
michael@0 | 55 | void endLine() { |
michael@0 | 56 | if (!asJSON_) { |
michael@0 | 57 | p("\n"); |
michael@0 | 58 | needComma_ = false; |
michael@0 | 59 | } |
michael@0 | 60 | } |
michael@0 | 61 | |
michael@0 | 62 | void extra(const char *str) { |
michael@0 | 63 | if (!asJSON_) { |
michael@0 | 64 | needComma_ = false; |
michael@0 | 65 | p(str); |
michael@0 | 66 | } |
michael@0 | 67 | } |
michael@0 | 68 | |
michael@0 | 69 | void appendString(const char *name, const char *value) { |
michael@0 | 70 | put(name, value, "", true); |
michael@0 | 71 | } |
michael@0 | 72 | |
michael@0 | 73 | void appendNumber(const char *name, const char *vfmt, const char *units, ...) { |
michael@0 | 74 | va_list va; |
michael@0 | 75 | va_start(va, units); |
michael@0 | 76 | append(name, vfmt, va, units); |
michael@0 | 77 | va_end(va); |
michael@0 | 78 | } |
michael@0 | 79 | |
michael@0 | 80 | void appendDecimal(const char *name, const char *units, double d) { |
michael@0 | 81 | if (d < 0) |
michael@0 | 82 | d = 0; |
michael@0 | 83 | if (asJSON_) |
michael@0 | 84 | appendNumber(name, "%d.%d", units, (int)d, (int)(d * 10.) % 10); |
michael@0 | 85 | else |
michael@0 | 86 | appendNumber(name, "%.1f", units, d); |
michael@0 | 87 | } |
michael@0 | 88 | |
michael@0 | 89 | void appendIfNonzeroMS(const char *name, double v) { |
michael@0 | 90 | if (asJSON_ || v >= 0.1) |
michael@0 | 91 | appendDecimal(name, "ms", v); |
michael@0 | 92 | } |
michael@0 | 93 | |
michael@0 | 94 | void beginObject(const char *name) { |
michael@0 | 95 | if (needComma_) |
michael@0 | 96 | pJSON(", "); |
michael@0 | 97 | if (asJSON_ && name) { |
michael@0 | 98 | putKey(name); |
michael@0 | 99 | pJSON(": "); |
michael@0 | 100 | } |
michael@0 | 101 | pJSON("{"); |
michael@0 | 102 | needComma_ = false; |
michael@0 | 103 | } |
michael@0 | 104 | |
michael@0 | 105 | void endObject() { |
michael@0 | 106 | needComma_ = false; |
michael@0 | 107 | pJSON("}"); |
michael@0 | 108 | needComma_ = true; |
michael@0 | 109 | } |
michael@0 | 110 | |
michael@0 | 111 | void beginArray(const char *name) { |
michael@0 | 112 | if (needComma_) |
michael@0 | 113 | pJSON(", "); |
michael@0 | 114 | if (asJSON_) |
michael@0 | 115 | putKey(name); |
michael@0 | 116 | pJSON(": ["); |
michael@0 | 117 | needComma_ = false; |
michael@0 | 118 | } |
michael@0 | 119 | |
michael@0 | 120 | void endArray() { |
michael@0 | 121 | needComma_ = false; |
michael@0 | 122 | pJSON("]"); |
michael@0 | 123 | needComma_ = true; |
michael@0 | 124 | } |
michael@0 | 125 | |
michael@0 | 126 | jschar *finishJSString() { |
michael@0 | 127 | char *buf = finishCString(); |
michael@0 | 128 | if (!buf) |
michael@0 | 129 | return nullptr; |
michael@0 | 130 | |
michael@0 | 131 | size_t nchars = strlen(buf); |
michael@0 | 132 | jschar *out = js_pod_malloc<jschar>(nchars + 1); |
michael@0 | 133 | if (!out) { |
michael@0 | 134 | oom_ = true; |
michael@0 | 135 | js_free(buf); |
michael@0 | 136 | return nullptr; |
michael@0 | 137 | } |
michael@0 | 138 | |
michael@0 | 139 | InflateStringToBuffer(buf, nchars, out); |
michael@0 | 140 | js_free(buf); |
michael@0 | 141 | |
michael@0 | 142 | out[nchars] = 0; |
michael@0 | 143 | return out; |
michael@0 | 144 | } |
michael@0 | 145 | |
michael@0 | 146 | char *finishCString() { |
michael@0 | 147 | if (oom_) |
michael@0 | 148 | return nullptr; |
michael@0 | 149 | |
michael@0 | 150 | buf_.append('\0'); |
michael@0 | 151 | |
michael@0 | 152 | char *buf = buf_.extractRawBuffer(); |
michael@0 | 153 | if (!buf) |
michael@0 | 154 | oom_ = true; |
michael@0 | 155 | |
michael@0 | 156 | return buf; |
michael@0 | 157 | } |
michael@0 | 158 | |
michael@0 | 159 | private: |
michael@0 | 160 | void append(const char *name, const char *vfmt, |
michael@0 | 161 | va_list va, const char *units) |
michael@0 | 162 | { |
michael@0 | 163 | char val[MaxFieldValueLength]; |
michael@0 | 164 | JS_vsnprintf(val, MaxFieldValueLength, vfmt, va); |
michael@0 | 165 | put(name, val, units, false); |
michael@0 | 166 | } |
michael@0 | 167 | |
michael@0 | 168 | void p(const char *cstr) { |
michael@0 | 169 | if (oom_) |
michael@0 | 170 | return; |
michael@0 | 171 | |
michael@0 | 172 | if (!buf_.append(cstr, strlen(cstr))) |
michael@0 | 173 | oom_ = true; |
michael@0 | 174 | } |
michael@0 | 175 | |
michael@0 | 176 | void p(const char c) { |
michael@0 | 177 | if (oom_) |
michael@0 | 178 | return; |
michael@0 | 179 | |
michael@0 | 180 | if (!buf_.append(c)) |
michael@0 | 181 | oom_ = true; |
michael@0 | 182 | } |
michael@0 | 183 | |
michael@0 | 184 | void pJSON(const char *str) { |
michael@0 | 185 | if (asJSON_) |
michael@0 | 186 | p(str); |
michael@0 | 187 | } |
michael@0 | 188 | |
michael@0 | 189 | void put(const char *name, const char *val, const char *units, bool valueIsQuoted) { |
michael@0 | 190 | if (needComma_) |
michael@0 | 191 | p(", "); |
michael@0 | 192 | needComma_ = true; |
michael@0 | 193 | |
michael@0 | 194 | putKey(name); |
michael@0 | 195 | p(": "); |
michael@0 | 196 | if (valueIsQuoted) |
michael@0 | 197 | putQuoted(val); |
michael@0 | 198 | else |
michael@0 | 199 | p(val); |
michael@0 | 200 | if (!asJSON_) |
michael@0 | 201 | p(units); |
michael@0 | 202 | } |
michael@0 | 203 | |
michael@0 | 204 | void putQuoted(const char *str) { |
michael@0 | 205 | pJSON("\""); |
michael@0 | 206 | p(str); |
michael@0 | 207 | pJSON("\""); |
michael@0 | 208 | } |
michael@0 | 209 | |
michael@0 | 210 | void putKey(const char *str) { |
michael@0 | 211 | if (!asJSON_) { |
michael@0 | 212 | p(str); |
michael@0 | 213 | return; |
michael@0 | 214 | } |
michael@0 | 215 | |
michael@0 | 216 | p("\""); |
michael@0 | 217 | const char *c = str; |
michael@0 | 218 | while (*c) { |
michael@0 | 219 | if (*c == ' ' || *c == '\t') |
michael@0 | 220 | p('_'); |
michael@0 | 221 | else if (isupper(*c)) |
michael@0 | 222 | p(tolower(*c)); |
michael@0 | 223 | else if (*c == '+') |
michael@0 | 224 | p("added_"); |
michael@0 | 225 | else if (*c == '-') |
michael@0 | 226 | p("removed_"); |
michael@0 | 227 | else if (*c != '(' && *c != ')') |
michael@0 | 228 | p(*c); |
michael@0 | 229 | c++; |
michael@0 | 230 | } |
michael@0 | 231 | p("\""); |
michael@0 | 232 | } |
michael@0 | 233 | }; |
michael@0 | 234 | |
michael@0 | 235 | /* |
michael@0 | 236 | * If this fails, then you can either delete this assertion and allow all |
michael@0 | 237 | * larger-numbered reasons to pile up in the last telemetry bucket, or switch |
michael@0 | 238 | * to GC_REASON_3 and bump the max value. |
michael@0 | 239 | */ |
michael@0 | 240 | JS_STATIC_ASSERT(JS::gcreason::NUM_TELEMETRY_REASONS >= JS::gcreason::NUM_REASONS); |
michael@0 | 241 | |
michael@0 | 242 | const char * |
michael@0 | 243 | js::gcstats::ExplainReason(JS::gcreason::Reason reason) |
michael@0 | 244 | { |
michael@0 | 245 | switch (reason) { |
michael@0 | 246 | #define SWITCH_REASON(name) \ |
michael@0 | 247 | case JS::gcreason::name: \ |
michael@0 | 248 | return #name; |
michael@0 | 249 | GCREASONS(SWITCH_REASON) |
michael@0 | 250 | |
michael@0 | 251 | default: |
michael@0 | 252 | MOZ_ASSUME_UNREACHABLE("bad GC reason"); |
michael@0 | 253 | #undef SWITCH_REASON |
michael@0 | 254 | } |
michael@0 | 255 | } |
michael@0 | 256 | |
michael@0 | 257 | static double |
michael@0 | 258 | t(int64_t t) |
michael@0 | 259 | { |
michael@0 | 260 | return double(t) / PRMJ_USEC_PER_MSEC; |
michael@0 | 261 | } |
michael@0 | 262 | |
michael@0 | 263 | struct PhaseInfo |
michael@0 | 264 | { |
michael@0 | 265 | Phase index; |
michael@0 | 266 | const char *name; |
michael@0 | 267 | Phase parent; |
michael@0 | 268 | }; |
michael@0 | 269 | |
michael@0 | 270 | static const Phase PHASE_NO_PARENT = PHASE_LIMIT; |
michael@0 | 271 | |
michael@0 | 272 | static const PhaseInfo phases[] = { |
michael@0 | 273 | { PHASE_GC_BEGIN, "Begin Callback", PHASE_NO_PARENT }, |
michael@0 | 274 | { PHASE_WAIT_BACKGROUND_THREAD, "Wait Background Thread", PHASE_NO_PARENT }, |
michael@0 | 275 | { PHASE_MARK_DISCARD_CODE, "Mark Discard Code", PHASE_NO_PARENT }, |
michael@0 | 276 | { PHASE_PURGE, "Purge", PHASE_NO_PARENT }, |
michael@0 | 277 | { PHASE_MARK, "Mark", PHASE_NO_PARENT }, |
michael@0 | 278 | { PHASE_MARK_ROOTS, "Mark Roots", PHASE_MARK }, |
michael@0 | 279 | { PHASE_MARK_DELAYED, "Mark Delayed", PHASE_MARK }, |
michael@0 | 280 | { PHASE_SWEEP, "Sweep", PHASE_NO_PARENT }, |
michael@0 | 281 | { PHASE_SWEEP_MARK, "Mark During Sweeping", PHASE_SWEEP }, |
michael@0 | 282 | { PHASE_SWEEP_MARK_TYPES, "Mark Types During Sweeping", PHASE_SWEEP_MARK }, |
michael@0 | 283 | { PHASE_SWEEP_MARK_INCOMING_BLACK, "Mark Incoming Black Pointers", PHASE_SWEEP_MARK }, |
michael@0 | 284 | { PHASE_SWEEP_MARK_WEAK, "Mark Weak", PHASE_SWEEP_MARK }, |
michael@0 | 285 | { PHASE_SWEEP_MARK_INCOMING_GRAY, "Mark Incoming Gray Pointers", PHASE_SWEEP_MARK }, |
michael@0 | 286 | { PHASE_SWEEP_MARK_GRAY, "Mark Gray", PHASE_SWEEP_MARK }, |
michael@0 | 287 | { PHASE_SWEEP_MARK_GRAY_WEAK, "Mark Gray and Weak", PHASE_SWEEP_MARK }, |
michael@0 | 288 | { PHASE_FINALIZE_START, "Finalize Start Callback", PHASE_SWEEP }, |
michael@0 | 289 | { PHASE_SWEEP_ATOMS, "Sweep Atoms", PHASE_SWEEP }, |
michael@0 | 290 | { PHASE_SWEEP_COMPARTMENTS, "Sweep Compartments", PHASE_SWEEP }, |
michael@0 | 291 | { PHASE_SWEEP_DISCARD_CODE, "Sweep Discard Code", PHASE_SWEEP_COMPARTMENTS }, |
michael@0 | 292 | { PHASE_SWEEP_TABLES, "Sweep Tables", PHASE_SWEEP_COMPARTMENTS }, |
michael@0 | 293 | { PHASE_SWEEP_TABLES_WRAPPER, "Sweep Cross Compartment Wrappers", PHASE_SWEEP_TABLES }, |
michael@0 | 294 | { PHASE_SWEEP_TABLES_BASE_SHAPE, "Sweep Base Shapes", PHASE_SWEEP_TABLES }, |
michael@0 | 295 | { PHASE_SWEEP_TABLES_INITIAL_SHAPE, "Sweep Initial Shapes", PHASE_SWEEP_TABLES }, |
michael@0 | 296 | { PHASE_SWEEP_TABLES_TYPE_OBJECT, "Sweep Type Objects", PHASE_SWEEP_TABLES }, |
michael@0 | 297 | { PHASE_SWEEP_TABLES_BREAKPOINT, "Sweep Breakpoints", PHASE_SWEEP_TABLES }, |
michael@0 | 298 | { PHASE_SWEEP_TABLES_REGEXP, "Sweep Regexps", PHASE_SWEEP_TABLES }, |
michael@0 | 299 | { PHASE_DISCARD_ANALYSIS, "Discard Analysis", PHASE_SWEEP_COMPARTMENTS }, |
michael@0 | 300 | { PHASE_DISCARD_TI, "Discard TI", PHASE_DISCARD_ANALYSIS }, |
michael@0 | 301 | { PHASE_FREE_TI_ARENA, "Free TI Arena", PHASE_DISCARD_ANALYSIS }, |
michael@0 | 302 | { PHASE_SWEEP_TYPES, "Sweep Types", PHASE_DISCARD_ANALYSIS }, |
michael@0 | 303 | { PHASE_SWEEP_OBJECT, "Sweep Object", PHASE_SWEEP }, |
michael@0 | 304 | { PHASE_SWEEP_STRING, "Sweep String", PHASE_SWEEP }, |
michael@0 | 305 | { PHASE_SWEEP_SCRIPT, "Sweep Script", PHASE_SWEEP }, |
michael@0 | 306 | { PHASE_SWEEP_SHAPE, "Sweep Shape", PHASE_SWEEP }, |
michael@0 | 307 | { PHASE_SWEEP_JITCODE, "Sweep JIT code", PHASE_SWEEP }, |
michael@0 | 308 | { PHASE_FINALIZE_END, "Finalize End Callback", PHASE_SWEEP }, |
michael@0 | 309 | { PHASE_DESTROY, "Deallocate", PHASE_SWEEP }, |
michael@0 | 310 | { PHASE_GC_END, "End Callback", PHASE_NO_PARENT }, |
michael@0 | 311 | { PHASE_LIMIT, nullptr, PHASE_NO_PARENT } |
michael@0 | 312 | }; |
michael@0 | 313 | |
michael@0 | 314 | static void |
michael@0 | 315 | FormatPhaseTimes(StatisticsSerializer &ss, const char *name, int64_t *times) |
michael@0 | 316 | { |
michael@0 | 317 | ss.beginObject(name); |
michael@0 | 318 | for (unsigned i = 0; phases[i].name; i++) |
michael@0 | 319 | ss.appendIfNonzeroMS(phases[i].name, t(times[phases[i].index])); |
michael@0 | 320 | ss.endObject(); |
michael@0 | 321 | } |
michael@0 | 322 | |
michael@0 | 323 | void |
michael@0 | 324 | Statistics::gcDuration(int64_t *total, int64_t *maxPause) |
michael@0 | 325 | { |
michael@0 | 326 | *total = *maxPause = 0; |
michael@0 | 327 | for (SliceData *slice = slices.begin(); slice != slices.end(); slice++) { |
michael@0 | 328 | *total += slice->duration(); |
michael@0 | 329 | if (slice->duration() > *maxPause) |
michael@0 | 330 | *maxPause = slice->duration(); |
michael@0 | 331 | } |
michael@0 | 332 | } |
michael@0 | 333 | |
michael@0 | 334 | void |
michael@0 | 335 | Statistics::sccDurations(int64_t *total, int64_t *maxPause) |
michael@0 | 336 | { |
michael@0 | 337 | *total = *maxPause = 0; |
michael@0 | 338 | for (size_t i = 0; i < sccTimes.length(); i++) { |
michael@0 | 339 | *total += sccTimes[i]; |
michael@0 | 340 | *maxPause = Max(*maxPause, sccTimes[i]); |
michael@0 | 341 | } |
michael@0 | 342 | } |
michael@0 | 343 | |
michael@0 | 344 | bool |
michael@0 | 345 | Statistics::formatData(StatisticsSerializer &ss, uint64_t timestamp) |
michael@0 | 346 | { |
michael@0 | 347 | int64_t total, longest; |
michael@0 | 348 | gcDuration(&total, &longest); |
michael@0 | 349 | |
michael@0 | 350 | int64_t sccTotal, sccLongest; |
michael@0 | 351 | sccDurations(&sccTotal, &sccLongest); |
michael@0 | 352 | |
michael@0 | 353 | double mmu20 = computeMMU(20 * PRMJ_USEC_PER_MSEC); |
michael@0 | 354 | double mmu50 = computeMMU(50 * PRMJ_USEC_PER_MSEC); |
michael@0 | 355 | |
michael@0 | 356 | ss.beginObject(nullptr); |
michael@0 | 357 | if (ss.isJSON()) |
michael@0 | 358 | ss.appendNumber("Timestamp", "%llu", "", (unsigned long long)timestamp); |
michael@0 | 359 | if (slices.length() > 1 || ss.isJSON()) |
michael@0 | 360 | ss.appendDecimal("Max Pause", "ms", t(longest)); |
michael@0 | 361 | else |
michael@0 | 362 | ss.appendString("Reason", ExplainReason(slices[0].reason)); |
michael@0 | 363 | ss.appendDecimal("Total Time", "ms", t(total)); |
michael@0 | 364 | ss.appendNumber("Zones Collected", "%d", "", collectedCount); |
michael@0 | 365 | ss.appendNumber("Total Zones", "%d", "", zoneCount); |
michael@0 | 366 | ss.appendNumber("Total Compartments", "%d", "", compartmentCount); |
michael@0 | 367 | ss.appendNumber("Minor GCs", "%d", "", counts[STAT_MINOR_GC]); |
michael@0 | 368 | ss.appendNumber("MMU (20ms)", "%d", "%", int(mmu20 * 100)); |
michael@0 | 369 | ss.appendNumber("MMU (50ms)", "%d", "%", int(mmu50 * 100)); |
michael@0 | 370 | ss.appendDecimal("SCC Sweep Total", "ms", t(sccTotal)); |
michael@0 | 371 | ss.appendDecimal("SCC Sweep Max Pause", "ms", t(sccLongest)); |
michael@0 | 372 | if (nonincrementalReason || ss.isJSON()) { |
michael@0 | 373 | ss.appendString("Nonincremental Reason", |
michael@0 | 374 | nonincrementalReason ? nonincrementalReason : "none"); |
michael@0 | 375 | } |
michael@0 | 376 | ss.appendNumber("Allocated", "%u", "MB", unsigned(preBytes / 1024 / 1024)); |
michael@0 | 377 | ss.appendNumber("+Chunks", "%d", "", counts[STAT_NEW_CHUNK]); |
michael@0 | 378 | ss.appendNumber("-Chunks", "%d", "", counts[STAT_DESTROY_CHUNK]); |
michael@0 | 379 | ss.endLine(); |
michael@0 | 380 | |
michael@0 | 381 | if (slices.length() > 1 || ss.isJSON()) { |
michael@0 | 382 | ss.beginArray("Slices"); |
michael@0 | 383 | for (size_t i = 0; i < slices.length(); i++) { |
michael@0 | 384 | int64_t width = slices[i].duration(); |
michael@0 | 385 | if (i != 0 && i != slices.length() - 1 && width < SLICE_MIN_REPORT_TIME && |
michael@0 | 386 | !slices[i].resetReason && !ss.isJSON()) |
michael@0 | 387 | { |
michael@0 | 388 | continue; |
michael@0 | 389 | } |
michael@0 | 390 | |
michael@0 | 391 | ss.beginObject(nullptr); |
michael@0 | 392 | ss.extra(" "); |
michael@0 | 393 | ss.appendNumber("Slice", "%d", "", i); |
michael@0 | 394 | ss.appendDecimal("Pause", "", t(width)); |
michael@0 | 395 | ss.extra(" ("); |
michael@0 | 396 | ss.appendDecimal("When", "ms", t(slices[i].start - slices[0].start)); |
michael@0 | 397 | ss.appendString("Reason", ExplainReason(slices[i].reason)); |
michael@0 | 398 | if (ss.isJSON()) { |
michael@0 | 399 | ss.appendDecimal("Page Faults", "", |
michael@0 | 400 | double(slices[i].endFaults - slices[i].startFaults)); |
michael@0 | 401 | |
michael@0 | 402 | ss.appendNumber("Start Timestamp", "%llu", "", (unsigned long long)slices[i].start); |
michael@0 | 403 | ss.appendNumber("End Timestamp", "%llu", "", (unsigned long long)slices[i].end); |
michael@0 | 404 | } |
michael@0 | 405 | if (slices[i].resetReason) |
michael@0 | 406 | ss.appendString("Reset", slices[i].resetReason); |
michael@0 | 407 | ss.extra("): "); |
michael@0 | 408 | FormatPhaseTimes(ss, "Times", slices[i].phaseTimes); |
michael@0 | 409 | ss.endLine(); |
michael@0 | 410 | ss.endObject(); |
michael@0 | 411 | } |
michael@0 | 412 | ss.endArray(); |
michael@0 | 413 | } |
michael@0 | 414 | ss.extra(" Totals: "); |
michael@0 | 415 | FormatPhaseTimes(ss, "Totals", phaseTimes); |
michael@0 | 416 | ss.endObject(); |
michael@0 | 417 | |
michael@0 | 418 | return !ss.isOOM(); |
michael@0 | 419 | } |
michael@0 | 420 | |
michael@0 | 421 | jschar * |
michael@0 | 422 | Statistics::formatMessage() |
michael@0 | 423 | { |
michael@0 | 424 | StatisticsSerializer ss(StatisticsSerializer::AsText); |
michael@0 | 425 | formatData(ss, 0); |
michael@0 | 426 | return ss.finishJSString(); |
michael@0 | 427 | } |
michael@0 | 428 | |
michael@0 | 429 | jschar * |
michael@0 | 430 | Statistics::formatJSON(uint64_t timestamp) |
michael@0 | 431 | { |
michael@0 | 432 | StatisticsSerializer ss(StatisticsSerializer::AsJSON); |
michael@0 | 433 | formatData(ss, timestamp); |
michael@0 | 434 | return ss.finishJSString(); |
michael@0 | 435 | } |
michael@0 | 436 | |
michael@0 | 437 | Statistics::Statistics(JSRuntime *rt) |
michael@0 | 438 | : runtime(rt), |
michael@0 | 439 | startupTime(PRMJ_Now()), |
michael@0 | 440 | fp(nullptr), |
michael@0 | 441 | fullFormat(false), |
michael@0 | 442 | gcDepth(0), |
michael@0 | 443 | collectedCount(0), |
michael@0 | 444 | zoneCount(0), |
michael@0 | 445 | compartmentCount(0), |
michael@0 | 446 | nonincrementalReason(nullptr), |
michael@0 | 447 | preBytes(0), |
michael@0 | 448 | phaseNestingDepth(0) |
michael@0 | 449 | { |
michael@0 | 450 | PodArrayZero(phaseTotals); |
michael@0 | 451 | PodArrayZero(counts); |
michael@0 | 452 | |
michael@0 | 453 | char *env = getenv("MOZ_GCTIMER"); |
michael@0 | 454 | if (!env || strcmp(env, "none") == 0) { |
michael@0 | 455 | fp = nullptr; |
michael@0 | 456 | return; |
michael@0 | 457 | } |
michael@0 | 458 | |
michael@0 | 459 | if (strcmp(env, "stdout") == 0) { |
michael@0 | 460 | fullFormat = false; |
michael@0 | 461 | fp = stdout; |
michael@0 | 462 | } else if (strcmp(env, "stderr") == 0) { |
michael@0 | 463 | fullFormat = false; |
michael@0 | 464 | fp = stderr; |
michael@0 | 465 | } else { |
michael@0 | 466 | fullFormat = true; |
michael@0 | 467 | |
michael@0 | 468 | fp = fopen(env, "a"); |
michael@0 | 469 | JS_ASSERT(fp); |
michael@0 | 470 | } |
michael@0 | 471 | } |
michael@0 | 472 | |
michael@0 | 473 | Statistics::~Statistics() |
michael@0 | 474 | { |
michael@0 | 475 | if (fp) { |
michael@0 | 476 | if (fullFormat) { |
michael@0 | 477 | StatisticsSerializer ss(StatisticsSerializer::AsText); |
michael@0 | 478 | FormatPhaseTimes(ss, "", phaseTotals); |
michael@0 | 479 | char *msg = ss.finishCString(); |
michael@0 | 480 | if (msg) { |
michael@0 | 481 | fprintf(fp, "TOTALS\n%s\n\n-------\n", msg); |
michael@0 | 482 | js_free(msg); |
michael@0 | 483 | } |
michael@0 | 484 | } |
michael@0 | 485 | |
michael@0 | 486 | if (fp != stdout && fp != stderr) |
michael@0 | 487 | fclose(fp); |
michael@0 | 488 | } |
michael@0 | 489 | } |
michael@0 | 490 | |
michael@0 | 491 | void |
michael@0 | 492 | Statistics::printStats() |
michael@0 | 493 | { |
michael@0 | 494 | if (fullFormat) { |
michael@0 | 495 | StatisticsSerializer ss(StatisticsSerializer::AsText); |
michael@0 | 496 | formatData(ss, 0); |
michael@0 | 497 | char *msg = ss.finishCString(); |
michael@0 | 498 | if (msg) { |
michael@0 | 499 | fprintf(fp, "GC(T+%.3fs) %s\n", t(slices[0].start - startupTime) / 1000.0, msg); |
michael@0 | 500 | js_free(msg); |
michael@0 | 501 | } |
michael@0 | 502 | } else { |
michael@0 | 503 | int64_t total, longest; |
michael@0 | 504 | gcDuration(&total, &longest); |
michael@0 | 505 | |
michael@0 | 506 | fprintf(fp, "%f %f %f\n", |
michael@0 | 507 | t(total), |
michael@0 | 508 | t(phaseTimes[PHASE_MARK]), |
michael@0 | 509 | t(phaseTimes[PHASE_SWEEP])); |
michael@0 | 510 | } |
michael@0 | 511 | fflush(fp); |
michael@0 | 512 | } |
michael@0 | 513 | |
michael@0 | 514 | void |
michael@0 | 515 | Statistics::beginGC() |
michael@0 | 516 | { |
michael@0 | 517 | PodArrayZero(phaseStartTimes); |
michael@0 | 518 | PodArrayZero(phaseTimes); |
michael@0 | 519 | |
michael@0 | 520 | slices.clearAndFree(); |
michael@0 | 521 | sccTimes.clearAndFree(); |
michael@0 | 522 | nonincrementalReason = nullptr; |
michael@0 | 523 | |
michael@0 | 524 | preBytes = runtime->gcBytes; |
michael@0 | 525 | } |
michael@0 | 526 | |
michael@0 | 527 | void |
michael@0 | 528 | Statistics::endGC() |
michael@0 | 529 | { |
michael@0 | 530 | crash::SnapshotGCStack(); |
michael@0 | 531 | |
michael@0 | 532 | for (int i = 0; i < PHASE_LIMIT; i++) |
michael@0 | 533 | phaseTotals[i] += phaseTimes[i]; |
michael@0 | 534 | |
michael@0 | 535 | if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback) { |
michael@0 | 536 | int64_t total, longest; |
michael@0 | 537 | gcDuration(&total, &longest); |
michael@0 | 538 | |
michael@0 | 539 | int64_t sccTotal, sccLongest; |
michael@0 | 540 | sccDurations(&sccTotal, &sccLongest); |
michael@0 | 541 | |
michael@0 | 542 | (*cb)(JS_TELEMETRY_GC_IS_COMPARTMENTAL, collectedCount == zoneCount ? 0 : 1); |
michael@0 | 543 | (*cb)(JS_TELEMETRY_GC_MS, t(total)); |
michael@0 | 544 | (*cb)(JS_TELEMETRY_GC_MAX_PAUSE_MS, t(longest)); |
michael@0 | 545 | (*cb)(JS_TELEMETRY_GC_MARK_MS, t(phaseTimes[PHASE_MARK])); |
michael@0 | 546 | (*cb)(JS_TELEMETRY_GC_SWEEP_MS, t(phaseTimes[PHASE_SWEEP])); |
michael@0 | 547 | (*cb)(JS_TELEMETRY_GC_MARK_ROOTS_MS, t(phaseTimes[PHASE_MARK_ROOTS])); |
michael@0 | 548 | (*cb)(JS_TELEMETRY_GC_MARK_GRAY_MS, t(phaseTimes[PHASE_SWEEP_MARK_GRAY])); |
michael@0 | 549 | (*cb)(JS_TELEMETRY_GC_NON_INCREMENTAL, !!nonincrementalReason); |
michael@0 | 550 | (*cb)(JS_TELEMETRY_GC_INCREMENTAL_DISABLED, !runtime->gcIncrementalEnabled); |
michael@0 | 551 | (*cb)(JS_TELEMETRY_GC_SCC_SWEEP_TOTAL_MS, t(sccTotal)); |
michael@0 | 552 | (*cb)(JS_TELEMETRY_GC_SCC_SWEEP_MAX_PAUSE_MS, t(sccLongest)); |
michael@0 | 553 | |
michael@0 | 554 | double mmu50 = computeMMU(50 * PRMJ_USEC_PER_MSEC); |
michael@0 | 555 | (*cb)(JS_TELEMETRY_GC_MMU_50, mmu50 * 100); |
michael@0 | 556 | } |
michael@0 | 557 | |
michael@0 | 558 | if (fp) |
michael@0 | 559 | printStats(); |
michael@0 | 560 | } |
michael@0 | 561 | |
michael@0 | 562 | void |
michael@0 | 563 | Statistics::beginSlice(int collectedCount, int zoneCount, int compartmentCount, |
michael@0 | 564 | JS::gcreason::Reason reason) |
michael@0 | 565 | { |
michael@0 | 566 | this->collectedCount = collectedCount; |
michael@0 | 567 | this->zoneCount = zoneCount; |
michael@0 | 568 | this->compartmentCount = compartmentCount; |
michael@0 | 569 | |
michael@0 | 570 | bool first = runtime->gcIncrementalState == gc::NO_INCREMENTAL; |
michael@0 | 571 | if (first) |
michael@0 | 572 | beginGC(); |
michael@0 | 573 | |
michael@0 | 574 | SliceData data(reason, PRMJ_Now(), gc::GetPageFaultCount()); |
michael@0 | 575 | (void) slices.append(data); /* Ignore any OOMs here. */ |
michael@0 | 576 | |
michael@0 | 577 | if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback) |
michael@0 | 578 | (*cb)(JS_TELEMETRY_GC_REASON, reason); |
michael@0 | 579 | |
michael@0 | 580 | // Slice callbacks should only fire for the outermost level |
michael@0 | 581 | if (++gcDepth == 1) { |
michael@0 | 582 | bool wasFullGC = collectedCount == zoneCount; |
michael@0 | 583 | if (JS::GCSliceCallback cb = runtime->gcSliceCallback) |
michael@0 | 584 | (*cb)(runtime, first ? JS::GC_CYCLE_BEGIN : JS::GC_SLICE_BEGIN, |
michael@0 | 585 | JS::GCDescription(!wasFullGC)); |
michael@0 | 586 | } |
michael@0 | 587 | } |
michael@0 | 588 | |
michael@0 | 589 | void |
michael@0 | 590 | Statistics::endSlice() |
michael@0 | 591 | { |
michael@0 | 592 | slices.back().end = PRMJ_Now(); |
michael@0 | 593 | slices.back().endFaults = gc::GetPageFaultCount(); |
michael@0 | 594 | |
michael@0 | 595 | if (JSAccumulateTelemetryDataCallback cb = runtime->telemetryCallback) { |
michael@0 | 596 | (*cb)(JS_TELEMETRY_GC_SLICE_MS, t(slices.back().end - slices.back().start)); |
michael@0 | 597 | (*cb)(JS_TELEMETRY_GC_RESET, !!slices.back().resetReason); |
michael@0 | 598 | } |
michael@0 | 599 | |
michael@0 | 600 | bool last = runtime->gcIncrementalState == gc::NO_INCREMENTAL; |
michael@0 | 601 | if (last) |
michael@0 | 602 | endGC(); |
michael@0 | 603 | |
michael@0 | 604 | // Slice callbacks should only fire for the outermost level |
michael@0 | 605 | if (--gcDepth == 0) { |
michael@0 | 606 | bool wasFullGC = collectedCount == zoneCount; |
michael@0 | 607 | if (JS::GCSliceCallback cb = runtime->gcSliceCallback) |
michael@0 | 608 | (*cb)(runtime, last ? JS::GC_CYCLE_END : JS::GC_SLICE_END, |
michael@0 | 609 | JS::GCDescription(!wasFullGC)); |
michael@0 | 610 | } |
michael@0 | 611 | |
michael@0 | 612 | /* Do this after the slice callback since it uses these values. */ |
michael@0 | 613 | if (last) |
michael@0 | 614 | PodArrayZero(counts); |
michael@0 | 615 | } |
michael@0 | 616 | |
michael@0 | 617 | void |
michael@0 | 618 | Statistics::beginPhase(Phase phase) |
michael@0 | 619 | { |
michael@0 | 620 | /* Guard against re-entry */ |
michael@0 | 621 | JS_ASSERT(!phaseStartTimes[phase]); |
michael@0 | 622 | |
michael@0 | 623 | #ifdef DEBUG |
michael@0 | 624 | JS_ASSERT(phases[phase].index == phase); |
michael@0 | 625 | Phase parent = phaseNestingDepth ? phaseNesting[phaseNestingDepth - 1] : PHASE_NO_PARENT; |
michael@0 | 626 | JS_ASSERT(phaseNestingDepth < MAX_NESTING); |
michael@0 | 627 | JS_ASSERT_IF(gcDepth == 1, phases[phase].parent == parent); |
michael@0 | 628 | phaseNesting[phaseNestingDepth] = phase; |
michael@0 | 629 | phaseNestingDepth++; |
michael@0 | 630 | #endif |
michael@0 | 631 | |
michael@0 | 632 | phaseStartTimes[phase] = PRMJ_Now(); |
michael@0 | 633 | } |
michael@0 | 634 | |
michael@0 | 635 | void |
michael@0 | 636 | Statistics::endPhase(Phase phase) |
michael@0 | 637 | { |
michael@0 | 638 | phaseNestingDepth--; |
michael@0 | 639 | |
michael@0 | 640 | int64_t t = PRMJ_Now() - phaseStartTimes[phase]; |
michael@0 | 641 | slices.back().phaseTimes[phase] += t; |
michael@0 | 642 | phaseTimes[phase] += t; |
michael@0 | 643 | phaseStartTimes[phase] = 0; |
michael@0 | 644 | } |
michael@0 | 645 | |
michael@0 | 646 | int64_t |
michael@0 | 647 | Statistics::beginSCC() |
michael@0 | 648 | { |
michael@0 | 649 | return PRMJ_Now(); |
michael@0 | 650 | } |
michael@0 | 651 | |
michael@0 | 652 | void |
michael@0 | 653 | Statistics::endSCC(unsigned scc, int64_t start) |
michael@0 | 654 | { |
michael@0 | 655 | if (scc >= sccTimes.length() && !sccTimes.resize(scc + 1)) |
michael@0 | 656 | return; |
michael@0 | 657 | |
michael@0 | 658 | sccTimes[scc] += PRMJ_Now() - start; |
michael@0 | 659 | } |
michael@0 | 660 | |
michael@0 | 661 | /* |
michael@0 | 662 | * MMU (minimum mutator utilization) is a measure of how much garbage collection |
michael@0 | 663 | * is affecting the responsiveness of the system. MMU measurements are given |
michael@0 | 664 | * with respect to a certain window size. If we report MMU(50ms) = 80%, then |
michael@0 | 665 | * that means that, for any 50ms window of time, at least 80% of the window is |
michael@0 | 666 | * devoted to the mutator. In other words, the GC is running for at most 20% of |
michael@0 | 667 | * the window, or 10ms. The GC can run multiple slices during the 50ms window |
michael@0 | 668 | * as long as the total time it spends is at most 10ms. |
michael@0 | 669 | */ |
michael@0 | 670 | double |
michael@0 | 671 | Statistics::computeMMU(int64_t window) |
michael@0 | 672 | { |
michael@0 | 673 | JS_ASSERT(!slices.empty()); |
michael@0 | 674 | |
michael@0 | 675 | int64_t gc = slices[0].end - slices[0].start; |
michael@0 | 676 | int64_t gcMax = gc; |
michael@0 | 677 | |
michael@0 | 678 | if (gc >= window) |
michael@0 | 679 | return 0.0; |
michael@0 | 680 | |
michael@0 | 681 | int startIndex = 0; |
michael@0 | 682 | for (size_t endIndex = 1; endIndex < slices.length(); endIndex++) { |
michael@0 | 683 | gc += slices[endIndex].end - slices[endIndex].start; |
michael@0 | 684 | |
michael@0 | 685 | while (slices[endIndex].end - slices[startIndex].end >= window) { |
michael@0 | 686 | gc -= slices[startIndex].end - slices[startIndex].start; |
michael@0 | 687 | startIndex++; |
michael@0 | 688 | } |
michael@0 | 689 | |
michael@0 | 690 | int64_t cur = gc; |
michael@0 | 691 | if (slices[endIndex].end - slices[startIndex].start > window) |
michael@0 | 692 | cur -= (slices[endIndex].end - slices[startIndex].start - window); |
michael@0 | 693 | if (cur > gcMax) |
michael@0 | 694 | gcMax = cur; |
michael@0 | 695 | } |
michael@0 | 696 | |
michael@0 | 697 | return double(window - gcMax) / window; |
michael@0 | 698 | } |