diff options
Diffstat (limited to 'js/src/gc/Statistics.h')
| -rw-r--r-- | js/src/gc/Statistics.h | 587 |
1 files changed, 587 insertions, 0 deletions
diff --git a/js/src/gc/Statistics.h b/js/src/gc/Statistics.h new file mode 100644 index 0000000000..f03bc2ea38 --- /dev/null +++ b/js/src/gc/Statistics.h @@ -0,0 +1,587 @@ +/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- + * vim: set ts=8 sts=2 et sw=2 tw=80: + * This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +#ifndef gc_Statistics_h +#define gc_Statistics_h + +#include "mozilla/Array.h" +#include "mozilla/Atomics.h" +#include "mozilla/EnumeratedArray.h" +#include "mozilla/Maybe.h" +#include "mozilla/TimeStamp.h" + +#include "jspubtd.h" +#include "NamespaceImports.h" + +#include "gc/GCEnum.h" +#include "js/AllocPolicy.h" +#include "js/GCAPI.h" +#include "js/SliceBudget.h" +#include "js/Vector.h" + +namespace js { + +class JS_PUBLIC_API Sprinter; +class JSONPrinter; + +namespace gcstats { + +// Phase data is generated by a script. If you need to add phases, edit +// js/src/gc/GenerateStatsPhases.py + +#include "gc/StatsPhasesGenerated.h" + +// Counts can be incremented with Statistics::count(). They're reset at the end +// of a Major GC. +enum Count { + COUNT_NEW_CHUNK, + COUNT_DESTROY_CHUNK, + COUNT_MINOR_GC, + + // Number of times a 'put' into a storebuffer overflowed, triggering a + // compaction + COUNT_STOREBUFFER_OVERFLOW, + + // Number of arenas relocated by compacting GC. + COUNT_ARENA_RELOCATED, + + // Number of cells marked during the marking phase. Excludes atoms marked when + // not collecting the atoms zone. + COUNT_CELLS_MARKED, + + // Number of times work was donated to a requesting thread during parallel + // marking. + COUNT_PARALLEL_MARK_INTERRUPTIONS, + + COUNT_LIMIT +}; + +// Stats can be set with Statistics::setStat(). They're not reset automatically. +enum Stat { + // Number of strings tenured. + STAT_STRINGS_TENURED, + + // Number of strings deduplicated. + STAT_STRINGS_DEDUPLICATED, + + // Number of BigInts tenured. + STAT_BIGINTS_TENURED, + + STAT_LIMIT +}; + +struct ZoneGCStats { + /* Number of zones collected in this GC. */ + size_t collectedZoneCount = 0; + + /* Total number of zones in the Runtime at the start of this GC. */ + size_t zoneCount = 0; + + /* Number of zones swept in this GC. */ + size_t sweptZoneCount = 0; + + /* Total number of compartments in all zones collected. */ + size_t collectedCompartmentCount = 0; + + /* Total number of compartments in the Runtime at the start of this GC. */ + size_t compartmentCount = 0; + + /* Total number of compartments swept by this GC. */ + size_t sweptCompartmentCount = 0; + + /* Total number of realms in the Runtime at the start of this GC. */ + size_t realmCount = 0; + + ZoneGCStats() = default; +}; + +struct Trigger { + size_t amount = 0; + size_t threshold = 0; +}; + +#define FOR_EACH_GC_PROFILE_TIME(_) \ + _(Total, "total", PhaseKind::NONE) \ + _(Background, "bgwrk", PhaseKind::NONE) \ + _(MinorForMajor, "evct4m", PhaseKind::EVICT_NURSERY_FOR_MAJOR_GC) \ + _(WaitBgThread, "waitBG", PhaseKind::WAIT_BACKGROUND_THREAD) \ + _(Prepare, "prep", PhaseKind::PREPARE) \ + _(Mark, "mark", PhaseKind::MARK) \ + _(Sweep, "sweep", PhaseKind::SWEEP) \ + _(Compact, "cmpct", PhaseKind::COMPACT) \ + _(Decommit, "dcmmt", PhaseKind::DECOMMIT) + +static const char* const MajorGCProfilePrefix = "MajorGC:"; +static const char* const MinorGCProfilePrefix = "MinorGC:"; + +const char* ExplainAbortReason(GCAbortReason reason); + +/* + * Struct for collecting timing statistics on a "phase tree". The tree is + * specified as a limited DAG, but the timings are collected for the whole tree + * that you would get by expanding out the DAG by duplicating subtrees rooted + * at nodes with multiple parents. + * + * During execution, a child phase can be activated multiple times, and the + * total time will be accumulated. (So for example, you can start and end + * PhaseKind::MARK_ROOTS multiple times before completing the parent phase.) + * + * Incremental GC is represented by recording separate timing results for each + * slice within the overall GC. + */ +struct Statistics { + template <typename T, size_t Length> + using Array = mozilla::Array<T, Length>; + + template <typename IndexType, IndexType SizeAsEnumValue, typename ValueType> + using EnumeratedArray = + mozilla::EnumeratedArray<IndexType, SizeAsEnumValue, ValueType>; + + using TimeDuration = mozilla::TimeDuration; + using TimeStamp = mozilla::TimeStamp; + + // Create types for tables of times, by phase and phase kind. + using PhaseTimes = EnumeratedArray<Phase, Phase::LIMIT, TimeDuration>; + using PhaseKindTimes = + EnumeratedArray<PhaseKind, PhaseKind::LIMIT, TimeDuration>; + + using PhaseTimeStamps = EnumeratedArray<Phase, Phase::LIMIT, TimeStamp>; + + [[nodiscard]] static bool initialize(); + + explicit Statistics(gc::GCRuntime* gc); + ~Statistics(); + + Statistics(const Statistics&) = delete; + Statistics& operator=(const Statistics&) = delete; + + void beginPhase(PhaseKind phaseKind); + void endPhase(PhaseKind phaseKind); + void recordParallelPhase(PhaseKind phaseKind, TimeDuration duration); + + // Occasionally, we may be in the middle of something that is tracked by + // this class, and we need to do something unusual (eg evict the nursery) + // that doesn't normally nest within the current phase. Suspend the + // currently tracked phase stack, at which time the caller is free to do + // other tracked operations. + // + // This also happens internally with the PhaseKind::MUTATOR "phase". While in + // this phase, any beginPhase will automatically suspend the non-GC phase, + // until that inner stack is complete, at which time it will automatically + // resume the non-GC phase. Explicit suspensions do not get auto-resumed. + void suspendPhases(PhaseKind suspension = PhaseKind::EXPLICIT_SUSPENSION); + + // Resume a suspended stack of phases. + void resumePhases(); + + void beginSlice(const ZoneGCStats& zoneStats, JS::GCOptions options, + const SliceBudget& budget, JS::GCReason reason, + bool budgetWasIncreased); + void endSlice(); + + [[nodiscard]] bool startTimingMutator(); + [[nodiscard]] bool stopTimingMutator(double& mutator_ms, double& gc_ms); + + // Note when we sweep a zone or compartment. + void sweptZone() { ++zoneStats.sweptZoneCount; } + void sweptCompartment() { ++zoneStats.sweptCompartmentCount; } + + void reset(GCAbortReason reason) { + MOZ_ASSERT(reason != GCAbortReason::None); + if (!aborted) { + slices_.back().resetReason = reason; + } + } + + void measureInitialHeapSize(); + + void nonincremental(GCAbortReason reason) { + MOZ_ASSERT(reason != GCAbortReason::None); + nonincrementalReason_ = reason; + log("Non-incremental reason: %s", nonincrementalReason()); + } + + bool nonincremental() const { + return nonincrementalReason_ != GCAbortReason::None; + } + + const char* nonincrementalReason() const { + return ExplainAbortReason(nonincrementalReason_); + } + + void count(Count s) { counts[s]++; } + void addCount(Count s, uint32_t count) { counts[s] += count; } + + uint32_t getCount(Count s) const { return uint32_t(counts[s]); } + + void setStat(Stat s, uint32_t value) { stats[s] = value; } + + uint32_t getStat(Stat s) const { return stats[s]; } + + void recordTrigger(size_t amount, size_t threshold) { + recordedTrigger = mozilla::Some(Trigger{amount, threshold}); + } + bool hasTrigger() const { return recordedTrigger.isSome(); } + + // tenured allocs don't include nursery evictions. + void setAllocsSinceMinorGCTenured(uint32_t allocs) { + tenuredAllocsSinceMinorGC = allocs; + } + + uint32_t allocsSinceMinorGCTenured() { return tenuredAllocsSinceMinorGC; } + + void beginNurseryCollection(); + void endNurseryCollection(); + + TimeStamp beginSCC(); + void endSCC(unsigned scc, TimeStamp start); + + UniqueChars formatCompactSliceMessage() const; + UniqueChars formatCompactSummaryMessage() const; + UniqueChars formatDetailedMessage() const; + + JS::GCSliceCallback setSliceCallback(JS::GCSliceCallback callback); + + TimeDuration clearMaxGCPauseAccumulator(); + TimeDuration getMaxGCPauseSinceClear(); + + PhaseKind currentPhaseKind() const; + + static const size_t MAX_SUSPENDED_PHASES = MAX_PHASE_NESTING * 3; + + struct SliceData { + SliceData(const SliceBudget& budget, mozilla::Maybe<Trigger> trigger, + JS::GCReason reason, TimeStamp start, size_t startFaults, + gc::State initialState); + + SliceBudget budget; + JS::GCReason reason = JS::GCReason::NO_REASON; + mozilla::Maybe<Trigger> trigger; + gc::State initialState = gc::State::NotActive; + gc::State finalState = gc::State::NotActive; + GCAbortReason resetReason = GCAbortReason::None; + TimeStamp start; + TimeStamp end; + size_t startFaults = 0; + size_t endFaults = 0; + PhaseTimes phaseTimes; + PhaseKindTimes totalParallelTimes; + PhaseKindTimes maxParallelTimes; + + TimeDuration duration() const; + bool wasReset() const { return resetReason != GCAbortReason::None; } + }; + + using SliceDataVector = Vector<SliceData, 8, SystemAllocPolicy>; + + const SliceDataVector& slices() const { return slices_; } + const SliceData& sliceAt(size_t index) const { return slices_[index]; } + + const SliceData* lastSlice() const { + if (slices_.length() == 0) { + return nullptr; + } + + return &slices_.back(); + } + + TimeStamp start() const { return slices_[0].start; } + + TimeStamp end() const { return slices_.back().end; } + + TimeStamp creationTime() const { return creationTime_; } + + TimeDuration totalGCTime() const { return totalGCTime_; } + size_t initialCollectedBytes() const { return preCollectedHeapBytes; } + + // File to write profiling information to, either stderr or file specified + // with JS_GC_PROFILE_FILE. + FILE* profileFile() const { return gcProfileFile; } + + // Occasionally print header lines for profiling information. + void maybePrintProfileHeaders(); + + // Print header line for profile times. + void printProfileHeader(); + + // Print total profile times on shutdown. + void printTotalProfileTimes(); + + // These JSON strings are used by the firefox profiler to display the GC + // markers. + + // Return JSON for a whole major GC + UniqueChars renderJsonMessage() const; + + // Return JSON for the timings of just the given slice. + UniqueChars renderJsonSlice(size_t sliceNum) const; + + // Return JSON for the previous nursery collection. + UniqueChars renderNurseryJson() const; + +#ifdef DEBUG + // Print a logging message. + void log(const char* fmt, ...); +#else + void log(const char* fmt, ...){}; +#endif + + private: + gc::GCRuntime* const gc; + + /* File used for MOZ_GCTIMER output. */ + FILE* gcTimerFile; + + /* File used for JS_GC_DEBUG output. */ + FILE* gcDebugFile; + + /* File used for JS_GC_PROFILE output. */ + FILE* gcProfileFile; + + ZoneGCStats zoneStats; + + JS::GCOptions gcOptions = JS::GCOptions::Normal; + + GCAbortReason nonincrementalReason_; + + SliceDataVector slices_; + + /* Most recent time when the given phase started. */ + PhaseTimeStamps phaseStartTimes; + +#ifdef DEBUG + /* Most recent time when the given phase ended. */ + PhaseTimeStamps phaseEndTimes; +#endif + + TimeStamp creationTime_; + + /* Bookkeeping for GC timings when timingMutator is true */ + TimeStamp timedGCStart; + TimeDuration timedGCTime; + + /* Total main thread time in a given phase for this GC. */ + PhaseTimes phaseTimes; + + /* Total main thread time for this GC. */ + TimeDuration totalGCTime_; + + /* Number of events of this type for this GC. */ + EnumeratedArray<Count, COUNT_LIMIT, + mozilla::Atomic<uint32_t, mozilla::ReleaseAcquire>> + counts; + + /* Other GC statistics. */ + EnumeratedArray<Stat, STAT_LIMIT, uint32_t> stats; + + /* + * These events cannot be kept in the above array, we need to take their + * address. + */ + uint32_t tenuredAllocsSinceMinorGC; + + /* Total GC heap size before and after the GC ran. */ + size_t preTotalHeapBytes; + size_t postTotalHeapBytes; + + /* GC heap size for collected zones before GC ran. */ + size_t preCollectedHeapBytes; + + /* + * If a GC slice was triggered by exceeding some threshold, record the + * threshold and the value that exceeded it. This happens before the slice + * starts so this is recorded here first and then transferred to SliceData. + */ + mozilla::Maybe<Trigger> recordedTrigger; + + /* GC numbers as of the beginning of the collection. */ + uint64_t startingMinorGCNumber; + uint64_t startingMajorGCNumber; + uint64_t startingSliceNumber; + + /* Records the maximum GC pause in an API-controlled interval. */ + mutable TimeDuration maxPauseInInterval; + + /* Phases that are currently on stack. */ + Vector<Phase, MAX_PHASE_NESTING, SystemAllocPolicy> phaseStack; + + /* + * Certain phases can interrupt the phase stack, eg callback phases. When + * this happens, we move the suspended phases over to a sepearate list, + * terminated by a dummy PhaseKind::SUSPENSION phase (so that we can nest + * suspensions by suspending multiple stacks with a PhaseKind::SUSPENSION in + * between). + */ + Vector<Phase, MAX_SUSPENDED_PHASES, SystemAllocPolicy> suspendedPhases; + + /* Sweep times for SCCs of compartments. */ + Vector<TimeDuration, 0, SystemAllocPolicy> sccTimes; + + TimeDuration timeSinceLastGC; + + JS::GCSliceCallback sliceCallback; + + /* + * True if we saw an OOM while allocating slices or we saw an impossible + * timestamp. The statistics for this GC will be invalid. + */ + bool aborted; + + /* Profiling data. */ + + enum class ProfileKey { +#define DEFINE_PROFILE_KEY(name, _1, _2) name, + FOR_EACH_GC_PROFILE_TIME(DEFINE_PROFILE_KEY) +#undef DEFINE_PROFILE_KEY + KeyCount + }; + + using ProfileDurations = + EnumeratedArray<ProfileKey, ProfileKey::KeyCount, TimeDuration>; + + bool enableProfiling_ = false; + bool profileWorkers_ = false; + TimeDuration profileThreshold_; + ProfileDurations totalTimes_; + uint64_t sliceCount_; + + char formatBuffer_[32]; + static constexpr int FormatBufferLength = sizeof(formatBuffer_); + + JSContext* context(); + + Phase currentPhase() const; + Phase lookupChildPhase(PhaseKind phaseKind) const; + + void beginGC(JS::GCOptions options, const TimeStamp& currentTime); + void endGC(); + + void sendGCTelemetry(); + void sendSliceTelemetry(const SliceData& slice); + + TimeDuration sumTotalParallelTime(PhaseKind phaseKind) const; + + void recordPhaseBegin(Phase phase); + void recordPhaseEnd(Phase phase); + + void gcDuration(TimeDuration* total, TimeDuration* maxPause) const; + void sccDurations(TimeDuration* total, TimeDuration* maxPause) const; + void printStats(); + + template <typename Fn> + void reportLongestPhaseInMajorGC(PhaseKind longest, Fn reportFn); + + UniqueChars formatCompactSlicePhaseTimes(const PhaseTimes& phaseTimes) const; + + UniqueChars formatDetailedDescription() const; + UniqueChars formatDetailedSliceDescription(unsigned i, + const SliceData& slice) const; + UniqueChars formatDetailedPhaseTimes(const PhaseTimes& phaseTimes) const; + UniqueChars formatDetailedTotals() const; + + void formatJsonDescription(JSONPrinter&) const; + void formatJsonSliceDescription(unsigned i, const SliceData& slice, + JSONPrinter&) const; + void formatJsonPhaseTimes(const PhaseTimes& phaseTimes, JSONPrinter&) const; + void formatJsonSlice(size_t sliceNum, JSONPrinter&) const; + + double computeMMU(TimeDuration window) const; + + void printSliceProfile(); + ProfileDurations getProfileTimes(const SliceData& slice) const; + void updateTotalProfileTimes(const ProfileDurations& times); + const char* formatGCStates(const SliceData& slice); + const char* formatGCFlags(const SliceData& slice); + const char* formatBudget(const SliceData& slice); + const char* formatTotalSlices(); + static void printProfileTimes(const ProfileDurations& times, + Sprinter& sprinter); +}; + +struct MOZ_RAII AutoGCSlice { + AutoGCSlice(Statistics& stats, const ZoneGCStats& zoneStats, + JS::GCOptions options, const SliceBudget& budget, + JS::GCReason reason, bool budgetWasIncreased) + : stats(stats) { + stats.beginSlice(zoneStats, options, budget, reason, budgetWasIncreased); + } + ~AutoGCSlice() { stats.endSlice(); } + + Statistics& stats; +}; + +struct MOZ_RAII AutoPhase { + AutoPhase(Statistics& stats, PhaseKind phaseKind) + : stats(stats), phaseKind(phaseKind), enabled(true) { + stats.beginPhase(phaseKind); + } + + AutoPhase(Statistics& stats, bool condition, PhaseKind phaseKind) + : stats(stats), phaseKind(phaseKind), enabled(condition) { + if (enabled) { + stats.beginPhase(phaseKind); + } + } + + ~AutoPhase() { + if (enabled) { + stats.endPhase(phaseKind); + } + } + + Statistics& stats; + PhaseKind phaseKind; + bool enabled; +}; + +struct MOZ_RAII AutoSCC { + AutoSCC(Statistics& stats, unsigned scc) : stats(stats), scc(scc) { + start = stats.beginSCC(); + } + ~AutoSCC() { stats.endSCC(scc, start); } + + Statistics& stats; + unsigned scc; + mozilla::TimeStamp start; +}; + +void ReadProfileEnv(const char* envName, const char* helpText, bool* enableOut, + bool* workersOut, mozilla::TimeDuration* thresholdOut); + +} /* namespace gcstats */ + +struct StringStats { + // number of strings that were deduplicated, and their sizes in characters + // and bytes + uint64_t deduplicatedStrings = 0; + uint64_t deduplicatedChars = 0; + uint64_t deduplicatedBytes = 0; + + // number of malloced bytes associated with tenured strings (the actual + // malloc will have happened when the strings were allocated in the nursery; + // the ownership of the bytes will be transferred to the tenured strings) + uint64_t tenuredBytes = 0; + + StringStats& operator+=(const StringStats& other) { + deduplicatedStrings += other.deduplicatedStrings; + deduplicatedChars += other.deduplicatedChars; + deduplicatedBytes += other.deduplicatedBytes; + tenuredBytes += other.tenuredBytes; + return *this; + } + + void noteTenured(size_t mallocBytes) { tenuredBytes += mallocBytes; } + + void noteDeduplicated(size_t numChars, size_t mallocBytes) { + deduplicatedStrings++; + deduplicatedChars += numChars; + deduplicatedBytes += mallocBytes; + } +}; + +} /* namespace js */ + +#endif /* gc_Statistics_h */ |