path: root/js/src/gc/Statistics.h

/* -*- 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. */
  int collectedZoneCount = 0;

  /* Total number of zones in the Runtime at the start of this GC. */
  int zoneCount = 0;

  /* Number of zones swept in this GC. */
  int sweptZoneCount = 0;

  /* Total number of compartments in all zones collected. */
  int collectedCompartmentCount = 0;

  /* Total number of compartments in the Runtime at the start of this GC. */
  int compartmentCount = 0;

  /* Total number of compartments swept by this GC. */
  int sweptCompartmentCount = 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)                           \
  _(BeginCallback, "bgnCB", PhaseKind::GC_BEGIN)                    \
  _(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)                           \
  _(EndCallback, "endCB", PhaseKind::GC_END)                        \
  _(MinorGC, "minor", PhaseKind::MINOR_GC)                          \
  _(EvictNursery, "evict", PhaseKind::EVICT_NURSERY)

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(JS::GCReason reason);
  void endNurseryCollection(JS::GCReason reason);

  TimeStamp beginSCC();
  void endSCC(unsigned scc, TimeStamp start);

  UniqueChars formatCompactSliceMessage() const;
  UniqueChars formatCompactSummaryMessage() const;
  UniqueChars formatDetailedMessage() const;

  JS::GCSliceCallback setSliceCallback(JS::GCSliceCallback callback);
  JS::GCNurseryCollectionCallback setNurseryCollectionCallback(
      JS::GCNurseryCollectionCallback 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 { return end - start; }
    bool wasReset() const { return resetReason != GCAbortReason::None; }
  };

  typedef Vector<SliceData, 8, SystemAllocPolicy> SliceDataVector;

  const SliceDataVector& slices() const { return slices_; }

  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;

  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;
  JS::GCNurseryCollectionCallback nurseryCollectionCallback;

  /*
   * 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_;
  bool profileWorkers_;
  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 resolution) 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 bool 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 live nursery strings at the start of a nursery collection
  uint64_t liveNurseryStrings = 0;

  // number of new strings added to the tenured heap
  uint64_t tenuredStrings = 0;

  // Currently, liveNurseryStrings = tenuredStrings + deduplicatedStrings (but
  // in the future we may do more transformation during tenuring, eg
  // atomizing.)

  // 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;
    liveNurseryStrings += other.liveNurseryStrings;
    tenuredStrings += other.tenuredStrings;
    tenuredBytes += other.tenuredBytes;
    return *this;
  }

  void noteTenured(size_t mallocBytes) {
    liveNurseryStrings++;
    tenuredStrings++;
    tenuredBytes += mallocBytes;
  }

  void noteDeduplicated(size_t numChars, size_t mallocBytes) {
    liveNurseryStrings++;
    deduplicatedStrings++;
    deduplicatedChars += numChars;
    deduplicatedBytes += mallocBytes;
  }
};

} /* namespace js */

#endif /* gc_Statistics_h */