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