1 /* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- 2 * vim: set ts=8 sts=2 et sw=2 tw=80: 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 #ifndef gc_Statistics_h 8 #define gc_Statistics_h 9 10 #include "mozilla/Array.h" 11 #include "mozilla/Atomics.h" 12 #include "mozilla/EnumeratedArray.h" 13 #include "mozilla/IntegerRange.h" 14 #include "mozilla/Maybe.h" 15 #include "mozilla/TimeStamp.h" 16 17 #include "jspubtd.h" 18 #include "NamespaceImports.h" 19 20 #include "gc/GCEnum.h" 21 #include "js/AllocPolicy.h" 22 #include "js/GCAPI.h" 23 #include "js/SliceBudget.h" 24 #include "js/UniquePtr.h" 25 #include "js/Vector.h" 26 #include "vm/JSONPrinter.h" 27 28 namespace js { 29 namespace gcstats { 30 31 // Phase data is generated by a script. If you need to add phases, edit 32 // js/src/gc/GenerateStatsPhases.py 33 34 #include "gc/StatsPhasesGenerated.h" 35 36 // Counts can be incremented with Statistics::count(). They're reset at the end 37 // of a Major GC. 38 enum Count { 39 COUNT_NEW_CHUNK, 40 COUNT_DESTROY_CHUNK, 41 COUNT_MINOR_GC, 42 43 // Number of times a 'put' into a storebuffer overflowed, triggering a 44 // compaction 45 COUNT_STOREBUFFER_OVERFLOW, 46 47 // Number of arenas relocated by compacting GC. 48 COUNT_ARENA_RELOCATED, 49 50 COUNT_LIMIT 51 }; 52 53 // Stats can be set with Statistics::setStat(). They're not reset automatically. 54 enum Stat { 55 // Number of strings tenured. 56 STAT_STRINGS_TENURED, 57 58 // Number of strings deduplicated. 59 STAT_STRINGS_DEDUPLICATED, 60 61 // Number of realms that had nursery strings disabled due to large numbers 62 // being tenured. 63 STAT_NURSERY_STRING_REALMS_DISABLED, 64 65 // Number of BigInts tenured. 66 STAT_BIGINTS_TENURED, 67 68 // Number of realms that had nursery BigInts disabled due to large numbers 69 // being tenured. 70 STAT_NURSERY_BIGINT_REALMS_DISABLED, 71 72 STAT_LIMIT 73 }; 74 75 struct ZoneGCStats { 76 /* Number of zones collected in this GC. */ 77 int collectedZoneCount = 0; 78 79 /* Total number of zones in the Runtime at the start of this GC. */ 80 int zoneCount = 0; 81 82 /* Number of zones swept in this GC. */ 83 int sweptZoneCount = 0; 84 85 /* Total number of compartments in all zones collected. */ 86 int collectedCompartmentCount = 0; 87 88 /* Total number of compartments in the Runtime at the start of this GC. */ 89 int compartmentCount = 0; 90 91 /* Total number of compartments swept by this GC. */ 92 int sweptCompartmentCount = 0; 93 isFullCollectionZoneGCStats94 bool isFullCollection() const { return collectedZoneCount == zoneCount; } 95 96 ZoneGCStats() = default; 97 }; 98 99 struct Trigger { 100 size_t amount = 0; 101 size_t threshold = 0; 102 }; 103 104 #define FOR_EACH_GC_PROFILE_TIME(_) \ 105 _(BeginCallback, "bgnCB", PhaseKind::GC_BEGIN) \ 106 _(MinorForMajor, "evct4m", PhaseKind::EVICT_NURSERY_FOR_MAJOR_GC) \ 107 _(WaitBgThread, "waitBG", PhaseKind::WAIT_BACKGROUND_THREAD) \ 108 _(Prepare, "prep", PhaseKind::PREPARE) \ 109 _(Mark, "mark", PhaseKind::MARK) \ 110 _(Sweep, "sweep", PhaseKind::SWEEP) \ 111 _(Compact, "cmpct", PhaseKind::COMPACT) \ 112 _(EndCallback, "endCB", PhaseKind::GC_END) \ 113 _(MinorGC, "minor", PhaseKind::MINOR_GC) \ 114 _(EvictNursery, "evict", PhaseKind::EVICT_NURSERY) 115 116 const char* ExplainAbortReason(GCAbortReason reason); 117 118 /* 119 * Struct for collecting timing statistics on a "phase tree". The tree is 120 * specified as a limited DAG, but the timings are collected for the whole tree 121 * that you would get by expanding out the DAG by duplicating subtrees rooted 122 * at nodes with multiple parents. 123 * 124 * During execution, a child phase can be activated multiple times, and the 125 * total time will be accumulated. (So for example, you can start and end 126 * PhaseKind::MARK_ROOTS multiple times before completing the parent phase.) 127 * 128 * Incremental GC is represented by recording separate timing results for each 129 * slice within the overall GC. 130 */ 131 struct Statistics { 132 template <typename T, size_t Length> 133 using Array = mozilla::Array<T, Length>; 134 135 template <typename IndexType, IndexType SizeAsEnumValue, typename ValueType> 136 using EnumeratedArray = 137 mozilla::EnumeratedArray<IndexType, SizeAsEnumValue, ValueType>; 138 139 using TimeDuration = mozilla::TimeDuration; 140 using TimeStamp = mozilla::TimeStamp; 141 142 // Create types for tables of times, by phase and phase kind. 143 using PhaseTimes = EnumeratedArray<Phase, Phase::LIMIT, TimeDuration>; 144 using PhaseKindTimes = 145 EnumeratedArray<PhaseKind, PhaseKind::LIMIT, TimeDuration>; 146 147 using PhaseTimeStamps = EnumeratedArray<Phase, Phase::LIMIT, TimeStamp>; 148 149 [[nodiscard]] static bool initialize(); 150 151 explicit Statistics(gc::GCRuntime* gc); 152 ~Statistics(); 153 154 Statistics(const Statistics&) = delete; 155 Statistics& operator=(const Statistics&) = delete; 156 157 void beginPhase(PhaseKind phaseKind); 158 void endPhase(PhaseKind phaseKind); 159 void recordParallelPhase(PhaseKind phaseKind, TimeDuration duration); 160 161 // Occasionally, we may be in the middle of something that is tracked by 162 // this class, and we need to do something unusual (eg evict the nursery) 163 // that doesn't normally nest within the current phase. Suspend the 164 // currently tracked phase stack, at which time the caller is free to do 165 // other tracked operations. 166 // 167 // This also happens internally with the PhaseKind::MUTATOR "phase". While in 168 // this phase, any beginPhase will automatically suspend the non-GC phase, 169 // until that inner stack is complete, at which time it will automatically 170 // resume the non-GC phase. Explicit suspensions do not get auto-resumed. 171 void suspendPhases(PhaseKind suspension = PhaseKind::EXPLICIT_SUSPENSION); 172 173 // Resume a suspended stack of phases. 174 void resumePhases(); 175 176 void beginSlice(const ZoneGCStats& zoneStats, JS::GCOptions options, 177 const SliceBudget& budget, JS::GCReason reason, 178 bool budgetWasIncreased); 179 void endSlice(); 180 181 [[nodiscard]] bool startTimingMutator(); 182 [[nodiscard]] bool stopTimingMutator(double& mutator_ms, double& gc_ms); 183 184 // Note when we sweep a zone or compartment. sweptZoneStatistics185 void sweptZone() { ++zoneStats.sweptZoneCount; } sweptCompartmentStatistics186 void sweptCompartment() { ++zoneStats.sweptCompartmentCount; } 187 resetStatistics188 void reset(GCAbortReason reason) { 189 MOZ_ASSERT(reason != GCAbortReason::None); 190 if (!aborted) { 191 slices_.back().resetReason = reason; 192 } 193 } 194 195 void measureInitialHeapSize(); 196 void adoptHeapSizeDuringIncrementalGC(Zone* mergedZone); 197 nonincrementalStatistics198 void nonincremental(GCAbortReason reason) { 199 MOZ_ASSERT(reason != GCAbortReason::None); 200 nonincrementalReason_ = reason; 201 log("Non-incremental reason: %s", nonincrementalReason()); 202 } 203 nonincrementalStatistics204 bool nonincremental() const { 205 return nonincrementalReason_ != GCAbortReason::None; 206 } 207 nonincrementalReasonStatistics208 const char* nonincrementalReason() const { 209 return ExplainAbortReason(nonincrementalReason_); 210 } 211 countStatistics212 void count(Count s) { counts[s]++; } 213 getCountStatistics214 uint32_t getCount(Count s) const { return uint32_t(counts[s]); } 215 setStatStatistics216 void setStat(Stat s, uint32_t value) { stats[s] = value; } 217 getStatStatistics218 uint32_t getStat(Stat s) const { return stats[s]; } 219 recordTriggerStatistics220 void recordTrigger(size_t amount, size_t threshold) { 221 recordedTrigger = mozilla::Some(Trigger{amount, threshold}); 222 } hasTriggerStatistics223 bool hasTrigger() const { return recordedTrigger.isSome(); } 224 noteNurseryAllocStatistics225 void noteNurseryAlloc() { allocsSinceMinorGC.nursery++; } 226 227 // tenured allocs don't include nursery evictions. setAllocsSinceMinorGCTenuredStatistics228 void setAllocsSinceMinorGCTenured(uint32_t allocs) { 229 allocsSinceMinorGC.tenured = allocs; 230 } 231 allocsSinceMinorGCNurseryStatistics232 uint32_t allocsSinceMinorGCNursery() { return allocsSinceMinorGC.nursery; } 233 allocsSinceMinorGCTenuredStatistics234 uint32_t allocsSinceMinorGCTenured() { return allocsSinceMinorGC.tenured; } 235 addressOfAllocsSinceMinorGCNurseryStatistics236 uint32_t* addressOfAllocsSinceMinorGCNursery() { 237 return &allocsSinceMinorGC.nursery; 238 } 239 240 void beginNurseryCollection(JS::GCReason reason); 241 void endNurseryCollection(JS::GCReason reason); 242 243 TimeStamp beginSCC(); 244 void endSCC(unsigned scc, TimeStamp start); 245 246 UniqueChars formatCompactSliceMessage() const; 247 UniqueChars formatCompactSummaryMessage() const; 248 UniqueChars formatDetailedMessage() const; 249 250 JS::GCSliceCallback setSliceCallback(JS::GCSliceCallback callback); 251 JS::GCNurseryCollectionCallback setNurseryCollectionCallback( 252 JS::GCNurseryCollectionCallback callback); 253 254 TimeDuration clearMaxGCPauseAccumulator(); 255 TimeDuration getMaxGCPauseSinceClear(); 256 257 PhaseKind currentPhaseKind() const; 258 259 static const size_t MAX_SUSPENDED_PHASES = MAX_PHASE_NESTING * 3; 260 261 struct SliceData { 262 SliceData(const SliceBudget& budget, mozilla::Maybe<Trigger> trigger, 263 JS::GCReason reason, TimeStamp start, size_t startFaults, 264 gc::State initialState); 265 266 SliceBudget budget; 267 JS::GCReason reason = JS::GCReason::NO_REASON; 268 mozilla::Maybe<Trigger> trigger; 269 gc::State initialState = gc::State::NotActive; 270 gc::State finalState = gc::State::NotActive; 271 GCAbortReason resetReason = GCAbortReason::None; 272 TimeStamp start; 273 TimeStamp end; 274 size_t startFaults = 0; 275 size_t endFaults = 0; 276 PhaseTimes phaseTimes; 277 PhaseKindTimes totalParallelTimes; 278 PhaseKindTimes maxParallelTimes; 279 durationStatistics::SliceData280 TimeDuration duration() const { return end - start; } wasResetStatistics::SliceData281 bool wasReset() const { return resetReason != GCAbortReason::None; } 282 }; 283 284 typedef Vector<SliceData, 8, SystemAllocPolicy> SliceDataVector; 285 slicesStatistics286 const SliceDataVector& slices() const { return slices_; } 287 startStatistics288 TimeStamp start() const { return slices_[0].start; } 289 endStatistics290 TimeStamp end() const { return slices_.back().end; } 291 creationTimeStatistics292 TimeStamp creationTime() const { return creationTime_; } 293 294 // File to write profiling information to, either stderr or file specified 295 // with JS_GC_PROFILE_FILE. profileFileStatistics296 FILE* profileFile() const { return gcProfileFile; } 297 298 // Occasionally print header lines for profiling information. 299 void maybePrintProfileHeaders(); 300 301 // Print header line for profile times. 302 void printProfileHeader(); 303 304 // Print total profile times on shutdown. 305 void printTotalProfileTimes(); 306 307 // These JSON strings are used by the firefox profiler to display the GC 308 // markers. 309 310 // Return JSON for a whole major GC 311 UniqueChars renderJsonMessage() const; 312 313 // Return JSON for the timings of just the given slice. 314 UniqueChars renderJsonSlice(size_t sliceNum) const; 315 316 // Return JSON for the previous nursery collection. 317 UniqueChars renderNurseryJson() const; 318 319 #ifdef DEBUG 320 // Print a logging message. 321 void log(const char* fmt, ...); 322 #else logStatistics323 void log(const char* fmt, ...){}; 324 #endif 325 326 private: 327 gc::GCRuntime* const gc; 328 329 /* File used for MOZ_GCTIMER output. */ 330 FILE* gcTimerFile; 331 332 /* File used for JS_GC_DEBUG output. */ 333 FILE* gcDebugFile; 334 335 /* File used for JS_GC_PROFILE output. */ 336 FILE* gcProfileFile; 337 338 ZoneGCStats zoneStats; 339 340 JS::GCOptions gcOptions; 341 342 GCAbortReason nonincrementalReason_; 343 344 SliceDataVector slices_; 345 346 /* Most recent time when the given phase started. */ 347 PhaseTimeStamps phaseStartTimes; 348 349 #ifdef DEBUG 350 /* Most recent time when the given phase ended. */ 351 PhaseTimeStamps phaseEndTimes; 352 #endif 353 354 TimeStamp creationTime_; 355 356 /* Bookkeeping for GC timings when timingMutator is true */ 357 TimeStamp timedGCStart; 358 TimeDuration timedGCTime; 359 360 /* Total time in a given phase for this GC. */ 361 PhaseTimes phaseTimes; 362 363 /* Total parallel time for a given phase kind for this GC. */ 364 PhaseKindTimes parallelTimes; 365 366 /* Number of events of this type for this GC. */ 367 EnumeratedArray<Count, COUNT_LIMIT, 368 mozilla::Atomic<uint32_t, mozilla::ReleaseAcquire>> 369 counts; 370 371 /* Other GC statistics. */ 372 EnumeratedArray<Stat, STAT_LIMIT, uint32_t> stats; 373 374 /* 375 * These events cannot be kept in the above array, we need to take their 376 * address. 377 */ 378 struct { 379 uint32_t nursery; 380 uint32_t tenured; 381 } allocsSinceMinorGC; 382 383 /* Total GC heap size before and after the GC ran. */ 384 size_t preTotalHeapBytes; 385 size_t postTotalHeapBytes; 386 387 /* GC heap size for collected zones before GC ran. */ 388 size_t preCollectedHeapBytes; 389 390 /* 391 * If a GC slice was triggered by exceeding some threshold, record the 392 * threshold and the value that exceeded it. This happens before the slice 393 * starts so this is recorded here first and then transferred to SliceData. 394 */ 395 mozilla::Maybe<Trigger> recordedTrigger; 396 397 /* GC numbers as of the beginning of the collection. */ 398 uint64_t startingMinorGCNumber; 399 uint64_t startingMajorGCNumber; 400 uint64_t startingSliceNumber; 401 402 /* Records the maximum GC pause in an API-controlled interval. */ 403 mutable TimeDuration maxPauseInInterval; 404 405 /* Phases that are currently on stack. */ 406 Vector<Phase, MAX_PHASE_NESTING, SystemAllocPolicy> phaseStack; 407 408 /* 409 * Certain phases can interrupt the phase stack, eg callback phases. When 410 * this happens, we move the suspended phases over to a sepearate list, 411 * terminated by a dummy PhaseKind::SUSPENSION phase (so that we can nest 412 * suspensions by suspending multiple stacks with a PhaseKind::SUSPENSION in 413 * between). 414 */ 415 Vector<Phase, MAX_SUSPENDED_PHASES, SystemAllocPolicy> suspendedPhases; 416 417 /* Sweep times for SCCs of compartments. */ 418 Vector<TimeDuration, 0, SystemAllocPolicy> sccTimes; 419 420 TimeDuration timeSinceLastGC; 421 422 JS::GCSliceCallback sliceCallback; 423 JS::GCNurseryCollectionCallback nurseryCollectionCallback; 424 425 /* 426 * True if we saw an OOM while allocating slices or we saw an impossible 427 * timestamp. The statistics for this GC will be invalid. 428 */ 429 bool aborted; 430 431 /* Profiling data. */ 432 433 enum class ProfileKey { 434 Total, 435 Background, 436 #define DEFINE_TIME_KEY(name, text, phase) name, 437 FOR_EACH_GC_PROFILE_TIME(DEFINE_TIME_KEY) 438 #undef DEFINE_TIME_KEY 439 KeyCount 440 }; 441 442 using ProfileDurations = 443 EnumeratedArray<ProfileKey, ProfileKey::KeyCount, TimeDuration>; 444 445 bool enableProfiling_; 446 bool profileWorkers_; 447 TimeDuration profileThreshold_; 448 ProfileDurations totalTimes_; 449 uint64_t sliceCount_; 450 451 JSContext* context(); 452 453 Phase currentPhase() const; 454 Phase lookupChildPhase(PhaseKind phaseKind) const; 455 456 void beginGC(JS::GCOptions options, const TimeStamp& currentTime); 457 void endGC(); 458 459 void sendGCTelemetry(); 460 void sendSliceTelemetry(const SliceData& slice); 461 462 void recordPhaseBegin(Phase phase); 463 void recordPhaseEnd(Phase phase); 464 465 void gcDuration(TimeDuration* total, TimeDuration* maxPause) const; 466 void sccDurations(TimeDuration* total, TimeDuration* maxPause) const; 467 void printStats(); 468 469 void reportLongestPhaseInMajorGC(PhaseKind longest, int telemetryId); 470 471 UniqueChars formatCompactSlicePhaseTimes(const PhaseTimes& phaseTimes) const; 472 473 UniqueChars formatDetailedDescription() const; 474 UniqueChars formatDetailedSliceDescription(unsigned i, 475 const SliceData& slice) const; 476 UniqueChars formatDetailedPhaseTimes(const PhaseTimes& phaseTimes) const; 477 UniqueChars formatDetailedTotals() const; 478 479 void formatJsonDescription(JSONPrinter&) const; 480 void formatJsonSliceDescription(unsigned i, const SliceData& slice, 481 JSONPrinter&) const; 482 void formatJsonPhaseTimes(const PhaseTimes& phaseTimes, JSONPrinter&) const; 483 void formatJsonSlice(size_t sliceNum, JSONPrinter&) const; 484 485 double computeMMU(TimeDuration resolution) const; 486 487 void printSliceProfile(); 488 void printProfileTimes(const ProfileDurations& times); 489 }; 490 491 struct MOZ_RAII AutoGCSlice { AutoGCSliceAutoGCSlice492 AutoGCSlice(Statistics& stats, const ZoneGCStats& zoneStats, 493 JS::GCOptions options, const SliceBudget& budget, 494 JS::GCReason reason, bool budgetWasIncreased) 495 : stats(stats) { 496 stats.beginSlice(zoneStats, options, budget, reason, budgetWasIncreased); 497 } ~AutoGCSliceAutoGCSlice498 ~AutoGCSlice() { stats.endSlice(); } 499 500 Statistics& stats; 501 }; 502 503 struct MOZ_RAII AutoPhase { AutoPhaseAutoPhase504 AutoPhase(Statistics& stats, PhaseKind phaseKind) 505 : stats(stats), phaseKind(phaseKind), enabled(true) { 506 stats.beginPhase(phaseKind); 507 } 508 AutoPhaseAutoPhase509 AutoPhase(Statistics& stats, bool condition, PhaseKind phaseKind) 510 : stats(stats), phaseKind(phaseKind), enabled(condition) { 511 if (enabled) { 512 stats.beginPhase(phaseKind); 513 } 514 } 515 ~AutoPhaseAutoPhase516 ~AutoPhase() { 517 if (enabled) { 518 stats.endPhase(phaseKind); 519 } 520 } 521 522 Statistics& stats; 523 PhaseKind phaseKind; 524 bool enabled; 525 }; 526 527 struct MOZ_RAII AutoSCC { AutoSCCAutoSCC528 AutoSCC(Statistics& stats, unsigned scc) : stats(stats), scc(scc) { 529 start = stats.beginSCC(); 530 } ~AutoSCCAutoSCC531 ~AutoSCC() { stats.endSCC(scc, start); } 532 533 Statistics& stats; 534 unsigned scc; 535 mozilla::TimeStamp start; 536 }; 537 538 void ReadProfileEnv(const char* envName, const char* helpText, bool* enableOut, 539 bool* workersOut, mozilla::TimeDuration* thresholdOut); 540 541 } /* namespace gcstats */ 542 543 struct StringStats { 544 // number of strings that were deduplicated, and their sizes in characters 545 // and bytes 546 uint64_t deduplicatedStrings = 0; 547 uint64_t deduplicatedChars = 0; 548 uint64_t deduplicatedBytes = 0; 549 550 // number of live nursery strings at the start of a nursery collection 551 uint64_t liveNurseryStrings = 0; 552 553 // number of new strings added to the tenured heap 554 uint64_t tenuredStrings = 0; 555 556 // Currently, liveNurseryStrings = tenuredStrings + deduplicatedStrings (but 557 // in the future we may do more transformation during tenuring, eg 558 // atomizing.) 559 560 // number of malloced bytes associated with tenured strings (the actual 561 // malloc will have happened when the strings were allocated in the nursery; 562 // the ownership of the bytes will be transferred to the tenured strings) 563 uint64_t tenuredBytes = 0; 564 565 StringStats& operator+=(const StringStats& other) { 566 deduplicatedStrings += other.deduplicatedStrings; 567 deduplicatedChars += other.deduplicatedChars; 568 deduplicatedBytes += other.deduplicatedBytes; 569 liveNurseryStrings += other.liveNurseryStrings; 570 tenuredStrings += other.tenuredStrings; 571 tenuredBytes += other.tenuredBytes; 572 return *this; 573 } 574 noteTenuredStringStats575 void noteTenured(size_t mallocBytes) { 576 liveNurseryStrings++; 577 tenuredStrings++; 578 tenuredBytes += mallocBytes; 579 } 580 noteDeduplicatedStringStats581 void noteDeduplicated(size_t numChars, size_t mallocBytes) { 582 liveNurseryStrings++; 583 deduplicatedStrings++; 584 deduplicatedChars += numChars; 585 deduplicatedBytes += mallocBytes; 586 } 587 }; 588 589 } /* namespace js */ 590 591 #endif /* gc_Statistics_h */ 592