Line data Source code
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 : #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/PodOperations.h"
16 :
17 : #include "jsalloc.h"
18 : #include "jsgc.h"
19 : #include "jspubtd.h"
20 :
21 : #include "js/GCAPI.h"
22 : #include "js/Vector.h"
23 : #include "vm/JSONPrinter.h"
24 :
25 : using mozilla::Maybe;
26 :
27 : namespace js {
28 :
29 : class GCParallelTask;
30 :
31 : namespace gcstats {
32 :
33 : // Phase data is generated by a script. If you need to add phases, edit
34 : // js/src/gc/GenerateStatsPhases.py
35 :
36 : #include "gc/StatsPhasesGenerated.h"
37 :
38 : enum Stat {
39 : STAT_NEW_CHUNK,
40 : STAT_DESTROY_CHUNK,
41 : STAT_MINOR_GC,
42 :
43 : // Number of times a 'put' into a storebuffer overflowed, triggering a
44 : // compaction
45 : STAT_STOREBUFFER_OVERFLOW,
46 :
47 : // Number of arenas relocated by compacting GC.
48 : STAT_ARENA_RELOCATED,
49 :
50 : STAT_LIMIT
51 : };
52 :
53 : struct ZoneGCStats
54 : {
55 : /* Number of zones collected in this GC. */
56 : int collectedZoneCount;
57 :
58 : /* Total number of zones in the Runtime at the start of this GC. */
59 : int zoneCount;
60 :
61 : /* Number of zones swept in this GC. */
62 : int sweptZoneCount;
63 :
64 : /* Total number of compartments in all zones collected. */
65 : int collectedCompartmentCount;
66 :
67 : /* Total number of compartments in the Runtime at the start of this GC. */
68 : int compartmentCount;
69 :
70 : /* Total number of compartments swept by this GC. */
71 : int sweptCompartmentCount;
72 :
73 6 : bool isCollectingAllZones() const { return collectedZoneCount == zoneCount; }
74 :
75 7 : ZoneGCStats()
76 7 : : collectedZoneCount(0), zoneCount(0), sweptZoneCount(0),
77 7 : collectedCompartmentCount(0), compartmentCount(0), sweptCompartmentCount(0)
78 7 : {}
79 : };
80 :
81 : #define FOR_EACH_GC_PROFILE_TIME(_) \
82 : _(BeginCallback, "bgnCB", PhaseKind::GC_BEGIN) \
83 : _(WaitBgThread, "waitBG", PhaseKind::WAIT_BACKGROUND_THREAD) \
84 : _(DiscardCode, "discrd", PhaseKind::MARK_DISCARD_CODE) \
85 : _(RelazifyFunc, "relzfy", PhaseKind::RELAZIFY_FUNCTIONS) \
86 : _(PurgeTables, "prgTbl", PhaseKind::PURGE_SHAPE_TABLES) \
87 : _(Purge, "purge", PhaseKind::PURGE) \
88 : _(Mark, "mark", PhaseKind::MARK) \
89 : _(Sweep, "sweep", PhaseKind::SWEEP) \
90 : _(Compact, "cmpct", PhaseKind::COMPACT) \
91 : _(EndCallback, "endCB", PhaseKind::GC_END) \
92 : _(Barriers, "brrier", PhaseKind::BARRIER)
93 :
94 : const char* ExplainAbortReason(gc::AbortReason reason);
95 : const char* ExplainInvocationKind(JSGCInvocationKind gckind);
96 :
97 : /*
98 : * Struct for collecting timing statistics on a "phase tree". The tree is
99 : * specified as a limited DAG, but the timings are collected for the whole tree
100 : * that you would get by expanding out the DAG by duplicating subtrees rooted
101 : * at nodes with multiple parents.
102 : *
103 : * During execution, a child phase can be activated multiple times, and the
104 : * total time will be accumulated. (So for example, you can start and end
105 : * PhaseKind::MARK_ROOTS multiple times before completing the parent phase.)
106 : *
107 : * Incremental GC is represented by recording separate timing results for each
108 : * slice within the overall GC.
109 : */
110 : struct Statistics
111 : {
112 : template <typename T, size_t Length>
113 : using Array = mozilla::Array<T, Length>;
114 :
115 : template <typename IndexType, IndexType SizeAsEnumValue, typename ValueType>
116 : using EnumeratedArray = mozilla::EnumeratedArray<IndexType, SizeAsEnumValue, ValueType>;
117 :
118 : using TimeDuration = mozilla::TimeDuration;
119 : using TimeStamp = mozilla::TimeStamp;
120 :
121 : // Create a convenient type for referring to tables of phase times.
122 : using PhaseTimeTable = EnumeratedArray<Phase, Phase::LIMIT, TimeDuration>;
123 :
124 : static MOZ_MUST_USE bool initialize();
125 :
126 : explicit Statistics(JSRuntime* rt);
127 : ~Statistics();
128 :
129 : Statistics(const Statistics&) = delete;
130 : Statistics& operator=(const Statistics&) = delete;
131 :
132 : void beginPhase(PhaseKind phaseKind);
133 : void endPhase(PhaseKind phaseKind);
134 : void endParallelPhase(PhaseKind phaseKind, const GCParallelTask* task);
135 : void recordParallelPhase(PhaseKind phaseKind, TimeDuration duration);
136 :
137 : // Occasionally, we may be in the middle of something that is tracked by
138 : // this class, and we need to do something unusual (eg evict the nursery)
139 : // that doesn't normally nest within the current phase. Suspend the
140 : // currently tracked phase stack, at which time the caller is free to do
141 : // other tracked operations.
142 : //
143 : // This also happens internally with the PhaseKind::MUTATOR "phase". While in
144 : // this phase, any beginPhase will automatically suspend the non-GC phase,
145 : // until that inner stack is complete, at which time it will automatically
146 : // resume the non-GC phase. Explicit suspensions do not get auto-resumed.
147 : void suspendPhases(PhaseKind suspension = PhaseKind::EXPLICIT_SUSPENSION);
148 :
149 : // Resume a suspended stack of phases.
150 : void resumePhases();
151 :
152 : void beginSlice(const ZoneGCStats& zoneStats, JSGCInvocationKind gckind,
153 : SliceBudget budget, JS::gcreason::Reason reason);
154 : void endSlice();
155 :
156 : MOZ_MUST_USE bool startTimingMutator();
157 : MOZ_MUST_USE bool stopTimingMutator(double& mutator_ms, double& gc_ms);
158 :
159 : // Note when we sweep a zone or compartment.
160 0 : void sweptZone() { ++zoneStats.sweptZoneCount; }
161 0 : void sweptCompartment() { ++zoneStats.sweptCompartmentCount; }
162 :
163 0 : void reset(gc::AbortReason reason) {
164 0 : MOZ_ASSERT(reason != gc::AbortReason::None);
165 0 : if (!aborted)
166 0 : slices_.back().resetReason = reason;
167 0 : }
168 :
169 0 : void nonincremental(gc::AbortReason reason) {
170 0 : MOZ_ASSERT(reason != gc::AbortReason::None);
171 0 : nonincrementalReason_ = reason;
172 0 : }
173 :
174 0 : bool nonincremental() const {
175 0 : return nonincrementalReason_ != gc::AbortReason::None;
176 : }
177 :
178 0 : const char* nonincrementalReason() const {
179 0 : return ExplainAbortReason(nonincrementalReason_);
180 : }
181 :
182 79 : void count(Stat s) {
183 79 : counts[s]++;
184 79 : }
185 :
186 0 : uint32_t getCount(Stat s) const {
187 0 : return uint32_t(counts[s]);
188 : }
189 :
190 0 : void recordTrigger(double amount, double threshold) {
191 0 : triggerAmount = amount;
192 0 : triggerThreshold = threshold;
193 0 : thresholdTriggered = true;
194 0 : }
195 :
196 : void beginNurseryCollection(JS::gcreason::Reason reason);
197 : void endNurseryCollection(JS::gcreason::Reason reason);
198 :
199 : TimeStamp beginSCC();
200 : void endSCC(unsigned scc, TimeStamp start);
201 :
202 : UniqueChars formatCompactSliceMessage() const;
203 : UniqueChars formatCompactSummaryMessage() const;
204 : UniqueChars formatDetailedMessage() const;
205 :
206 : JS::GCSliceCallback setSliceCallback(JS::GCSliceCallback callback);
207 : JS::GCNurseryCollectionCallback setNurseryCollectionCallback(
208 : JS::GCNurseryCollectionCallback callback);
209 :
210 : TimeDuration clearMaxGCPauseAccumulator();
211 : TimeDuration getMaxGCPauseSinceClear();
212 :
213 : PhaseKind currentPhaseKind() const;
214 :
215 : static const size_t MAX_SUSPENDED_PHASES = MAX_PHASE_NESTING * 3;
216 :
217 3 : struct SliceData {
218 3 : SliceData(SliceBudget budget, JS::gcreason::Reason reason,
219 : TimeStamp start, size_t startFaults, gc::State initialState)
220 3 : : budget(budget), reason(reason),
221 : initialState(initialState),
222 : finalState(gc::State::NotActive),
223 : resetReason(gc::AbortReason::None),
224 : start(start),
225 3 : startFaults(startFaults)
226 3 : {}
227 :
228 : SliceBudget budget;
229 : JS::gcreason::Reason reason;
230 : gc::State initialState, finalState;
231 : gc::AbortReason resetReason;
232 : TimeStamp start, end;
233 : size_t startFaults, endFaults;
234 : PhaseTimeTable phaseTimes;
235 : PhaseTimeTable parallelTimes;
236 :
237 0 : TimeDuration duration() const { return end - start; }
238 6 : bool wasReset() const { return resetReason != gc::AbortReason::None; }
239 : };
240 :
241 : typedef Vector<SliceData, 8, SystemAllocPolicy> SliceDataVector;
242 :
243 6 : const SliceDataVector& slices() const { return slices_; }
244 :
245 0 : TimeStamp start() const {
246 0 : return slices_[0].start;
247 : }
248 :
249 0 : TimeStamp end() const {
250 0 : return slices_.back().end;
251 : }
252 :
253 : // Occasionally print header lines for profiling information.
254 : void maybePrintProfileHeaders();
255 :
256 : // Print header line for profile times.
257 : void printProfileHeader();
258 :
259 : // Print total profile times on shutdown.
260 : void printTotalProfileTimes();
261 :
262 : // Return JSON for a whole major GC, optionally including detailed
263 : // per-slice data.
264 : UniqueChars renderJsonMessage(uint64_t timestamp, bool includeSlices = true) const;
265 :
266 : // Return JSON for the timings of just the given slice.
267 : UniqueChars renderJsonSlice(size_t sliceNum) const;
268 :
269 : // Return JSON for the previous nursery collection.
270 : UniqueChars renderNurseryJson(JSRuntime* rt) const;
271 :
272 : private:
273 : JSRuntime* runtime;
274 :
275 : /* File pointer used for MOZ_GCTIMER output. */
276 : FILE* fp;
277 :
278 : ZoneGCStats zoneStats;
279 :
280 : JSGCInvocationKind gckind;
281 :
282 : gc::AbortReason nonincrementalReason_;
283 :
284 : SliceDataVector slices_;
285 :
286 : /* Most recent time when the given phase started. */
287 : EnumeratedArray<Phase, Phase::LIMIT, TimeStamp> phaseStartTimes;
288 :
289 : /* Bookkeeping for GC timings when timingMutator is true */
290 : TimeStamp timedGCStart;
291 : TimeDuration timedGCTime;
292 :
293 : /* Total time in a given phase for this GC. */
294 : PhaseTimeTable phaseTimes;
295 : PhaseTimeTable parallelTimes;
296 :
297 : /* Number of events of this type for this GC. */
298 : EnumeratedArray<Stat,
299 : STAT_LIMIT,
300 : mozilla::Atomic<uint32_t, mozilla::ReleaseAcquire>> counts;
301 :
302 : /* Allocated space before the GC started. */
303 : size_t preBytes;
304 :
305 : /* If the GC was triggered by exceeding some threshold, record the
306 : * threshold and the value that exceeded it. */
307 : bool thresholdTriggered;
308 : double triggerAmount;
309 : double triggerThreshold;
310 :
311 : /* GC numbers as of the beginning of the collection. */
312 : uint64_t startingMinorGCNumber;
313 : uint64_t startingMajorGCNumber;
314 :
315 : /* Records the maximum GC pause in an API-controlled interval (in us). */
316 : mutable TimeDuration maxPauseInInterval;
317 :
318 : /* Phases that are currently on stack. */
319 : Vector<Phase, MAX_PHASE_NESTING, SystemAllocPolicy> phaseStack;
320 :
321 : /*
322 : * Certain phases can interrupt the phase stack, eg callback phases. When
323 : * this happens, we move the suspended phases over to a sepearate list,
324 : * terminated by a dummy PhaseKind::SUSPENSION phase (so that we can nest
325 : * suspensions by suspending multiple stacks with a PhaseKind::SUSPENSION in
326 : * between).
327 : */
328 : Vector<Phase, MAX_SUSPENDED_PHASES, SystemAllocPolicy> suspendedPhases;
329 :
330 : /* Sweep times for SCCs of compartments. */
331 : Vector<TimeDuration, 0, SystemAllocPolicy> sccTimes;
332 :
333 : JS::GCSliceCallback sliceCallback;
334 : JS::GCNurseryCollectionCallback nurseryCollectionCallback;
335 :
336 : /*
337 : * True if we saw an OOM while allocating slices or we saw an impossible
338 : * timestamp. The statistics for this GC will be invalid.
339 : */
340 : bool aborted;
341 :
342 : /* Profiling data. */
343 :
344 : enum class ProfileKey
345 : {
346 : Total,
347 : #define DEFINE_TIME_KEY(name, text, phase) \
348 : name,
349 : FOR_EACH_GC_PROFILE_TIME(DEFINE_TIME_KEY)
350 : #undef DEFINE_TIME_KEY
351 : KeyCount
352 : };
353 :
354 : using ProfileDurations = EnumeratedArray<ProfileKey, ProfileKey::KeyCount, TimeDuration>;
355 :
356 : TimeDuration profileThreshold_;
357 : bool enableProfiling_;
358 : ProfileDurations totalTimes_;
359 : uint64_t sliceCount_;
360 :
361 : Phase currentPhase() const;
362 : Phase lookupChildPhase(PhaseKind phaseKind) const;
363 :
364 : void beginGC(JSGCInvocationKind kind);
365 : void endGC();
366 :
367 : void recordPhaseBegin(Phase phase);
368 : void recordPhaseEnd(Phase phase);
369 :
370 : void gcDuration(TimeDuration* total, TimeDuration* maxPause) const;
371 : void sccDurations(TimeDuration* total, TimeDuration* maxPause) const;
372 : void printStats();
373 :
374 : void reportLongestPhase(const PhaseTimeTable& times, int telemetryId);
375 :
376 : UniqueChars formatCompactSlicePhaseTimes(const PhaseTimeTable& phaseTimes) const;
377 :
378 : UniqueChars formatDetailedDescription() const;
379 : UniqueChars formatDetailedSliceDescription(unsigned i, const SliceData& slice) const;
380 : UniqueChars formatDetailedPhaseTimes(const PhaseTimeTable& phaseTimes) const;
381 : UniqueChars formatDetailedTotals() const;
382 :
383 : void formatJsonDescription(uint64_t timestamp, JSONPrinter&) const;
384 : void formatJsonSliceDescription(unsigned i, const SliceData& slice, JSONPrinter&) const;
385 : void formatJsonPhaseTimes(const PhaseTimeTable& phaseTimes, JSONPrinter&) const;
386 : void formatJsonSlice(size_t sliceNum, JSONPrinter&) const;
387 :
388 : double computeMMU(TimeDuration resolution) const;
389 :
390 : void printSliceProfile();
391 : static void printProfileTimes(const ProfileDurations& times);
392 : };
393 :
394 : struct MOZ_RAII AutoGCSlice
395 : {
396 3 : AutoGCSlice(Statistics& stats, const ZoneGCStats& zoneStats, JSGCInvocationKind gckind,
397 : SliceBudget budget, JS::gcreason::Reason reason)
398 3 : : stats(stats)
399 : {
400 3 : stats.beginSlice(zoneStats, gckind, budget, reason);
401 3 : }
402 3 : ~AutoGCSlice() { stats.endSlice(); }
403 :
404 : Statistics& stats;
405 : };
406 :
407 : struct MOZ_RAII AutoPhase
408 : {
409 121 : AutoPhase(Statistics& stats, PhaseKind phaseKind)
410 121 : : stats(stats), phaseKind(phaseKind), enabled(true)
411 : {
412 121 : stats.beginPhase(phaseKind);
413 121 : }
414 :
415 0 : AutoPhase(Statistics& stats, bool condition, PhaseKind phaseKind)
416 0 : : stats(stats), phaseKind(phaseKind), enabled(condition)
417 : {
418 0 : if (enabled)
419 0 : stats.beginPhase(phaseKind);
420 0 : }
421 :
422 242 : ~AutoPhase() {
423 121 : if (enabled)
424 121 : stats.endPhase(phaseKind);
425 121 : }
426 :
427 : Statistics& stats;
428 : PhaseKind phaseKind;
429 : bool enabled;
430 : };
431 :
432 : struct MOZ_RAII AutoSCC
433 : {
434 0 : AutoSCC(Statistics& stats, unsigned scc)
435 0 : : stats(stats), scc(scc)
436 : {
437 0 : start = stats.beginSCC();
438 0 : }
439 0 : ~AutoSCC() {
440 0 : stats.endSCC(scc, start);
441 0 : }
442 :
443 : Statistics& stats;
444 : unsigned scc;
445 : mozilla::TimeStamp start;
446 : };
447 :
448 : } /* namespace gcstats */
449 : } /* namespace js */
450 :
451 : #endif /* gc_Statistics_h */
|
