tor-browser

Statistics.h (18730B)

---

/* -*- 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"
#include "vm/Logging.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 promoted.
 STAT_STRINGS_PROMOTED,

 // Number of strings deduplicated.
 STAT_STRINGS_DEDUPLICATED,

 // Number of BigInts promoted.
 STAT_BIGINTS_PROMOTED,

 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, typename ValueType, IndexType SizeAsEnumValue>
 using EnumeratedArray =
     mozilla::EnumeratedArray<IndexType, ValueType, size_t(SizeAsEnumValue)>;

 using TimeDuration = mozilla::TimeDuration;
 using TimeStamp = mozilla::TimeStamp;

 // Create types for tables of times, by phase and phase kind.
 using PhaseTimes = EnumeratedArray<Phase, TimeDuration, Phase::LIMIT>;
 using PhaseKindTimes =
     EnumeratedArray<PhaseKind, TimeDuration, PhaseKind::LIMIT>;

 using PhaseTimeStamps = EnumeratedArray<Phase, TimeStamp, Phase::LIMIT>;

 [[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 JS::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 measureInitialHeapSizes();

 void nonincremental(GCAbortReason reason) {
   MOZ_ASSERT(reason != GCAbortReason::None);
   nonincrementalReason_ = reason;
   JS_LOG(gc, Info, "non-incremental for 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 JS::SliceBudget& budget, mozilla::Maybe<Trigger> trigger,
             JS::GCReason reason, TimeStamp start, size_t startFaults,
             gc::State initialState);

   JS::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 preCollectedGCHeapBytes; }

 // 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;

 bool bufferAllocStatsEnabled() const { return enableBufferAllocStats_; }

private:
 gc::GCRuntime* const gc;

 /* File used for MOZ_GCTIMER output. */
 FILE* gcTimerFile;

 /* 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, mozilla::Atomic<uint32_t, mozilla::ReleaseAcquire>,
                 COUNT_LIMIT>
     counts;

 /* Other GC statistics. */
 EnumeratedArray<Stat, uint32_t, STAT_LIMIT> 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 preTotalGCHeapBytes;
 size_t postTotalGCHeapBytes;

 /* GC heap size for collected zones before GC ran. */
 size_t preCollectedGCHeapBytes;

 /* Total malloc heap size before and after the GC ran. */
 size_t preTotalMallocHeapBytes;
 size_t postTotalMallocHeapBytes;

 /*
  * 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, TimeDuration, ProfileKey::KeyCount>;

 bool enableProfiling_ = false;
 bool profileWorkers_ = false;
 bool enableBufferAllocStats_ = 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 GleanFn>
 void reportLongestPhaseInMajorGC(PhaseKind longest, GleanFn gleanReportFn);

 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();

 size_t getMallocHeapSize();

 void getBufferedAllocatorStats(Zone* zone, size_t& mediumChunks,
                                size_t& mediumTenuredChunks,
                                size_t& largeNurseryAllocs,
                                size_t& largeTenuredAllocs);

 static void printProfileTimes(const ProfileDurations& times,
                               Sprinter& sprinter);
};

struct MOZ_RAII AutoGCSlice {
 AutoGCSlice(Statistics& stats, const ZoneGCStats& zoneStats,
             JS::GCOptions options, const JS::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 */