• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 // Copyright 2014 the V8 project authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4 
5 #ifndef V8_HEAP_GC_TRACER_H_
6 #define V8_HEAP_GC_TRACER_H_
7 
8 #include "src/base/compiler-specific.h"
9 #include "src/base/platform/platform.h"
10 #include "src/counters.h"
11 #include "src/globals.h"
12 
13 namespace v8 {
14 namespace internal {
15 
16 template <typename T>
17 class RingBuffer {
18  public:
RingBuffer()19   RingBuffer() { Reset(); }
20   static const int kSize = 10;
Push(const T & value)21   void Push(const T& value) {
22     if (count_ == kSize) {
23       elements_[start_++] = value;
24       if (start_ == kSize) start_ = 0;
25     } else {
26       DCHECK_EQ(start_, 0);
27       elements_[count_++] = value;
28     }
29   }
30 
Count()31   int Count() const { return count_; }
32 
33   template <typename Callback>
Sum(Callback callback,const T & initial)34   T Sum(Callback callback, const T& initial) const {
35     int j = start_ + count_ - 1;
36     if (j >= kSize) j -= kSize;
37     T result = initial;
38     for (int i = 0; i < count_; i++) {
39       result = callback(result, elements_[j]);
40       if (--j == -1) j += kSize;
41     }
42     return result;
43   }
44 
Reset()45   void Reset() { start_ = count_ = 0; }
46 
47  private:
48   T elements_[kSize];
49   int start_;
50   int count_;
51   DISALLOW_COPY_AND_ASSIGN(RingBuffer);
52 };
53 
54 typedef std::pair<uint64_t, double> BytesAndDuration;
55 
MakeBytesAndDuration(uint64_t bytes,double duration)56 inline BytesAndDuration MakeBytesAndDuration(uint64_t bytes, double duration) {
57   return std::make_pair(bytes, duration);
58 }
59 
60 enum ScavengeSpeedMode { kForAllObjects, kForSurvivedObjects };
61 
62 #define TRACER_SCOPES(F)                           \
63   F(EXTERNAL_WEAK_GLOBAL_HANDLES)                  \
64   F(MC_CLEAR)                                      \
65   F(MC_CLEAR_CODE_FLUSH)                           \
66   F(MC_CLEAR_DEPENDENT_CODE)                       \
67   F(MC_CLEAR_GLOBAL_HANDLES)                       \
68   F(MC_CLEAR_MAPS)                                 \
69   F(MC_CLEAR_SLOTS_BUFFER)                         \
70   F(MC_CLEAR_STORE_BUFFER)                         \
71   F(MC_CLEAR_STRING_TABLE)                         \
72   F(MC_CLEAR_WEAK_CELLS)                           \
73   F(MC_CLEAR_WEAK_COLLECTIONS)                     \
74   F(MC_CLEAR_WEAK_LISTS)                           \
75   F(MC_EVACUATE)                                   \
76   F(MC_EVACUATE_CANDIDATES)                        \
77   F(MC_EVACUATE_CLEAN_UP)                          \
78   F(MC_EVACUATE_COPY)                              \
79   F(MC_EVACUATE_UPDATE_POINTERS)                   \
80   F(MC_EVACUATE_UPDATE_POINTERS_TO_EVACUATED)      \
81   F(MC_EVACUATE_UPDATE_POINTERS_TO_NEW)            \
82   F(MC_EVACUATE_UPDATE_POINTERS_WEAK)              \
83   F(MC_EXTERNAL_EPILOGUE)                          \
84   F(MC_EXTERNAL_PROLOGUE)                          \
85   F(MC_FINISH)                                     \
86   F(MC_INCREMENTAL_FINALIZE)                       \
87   F(MC_INCREMENTAL_EXTERNAL_EPILOGUE)              \
88   F(MC_INCREMENTAL_EXTERNAL_PROLOGUE)              \
89   F(MC_MARK)                                       \
90   F(MC_MARK_FINISH_INCREMENTAL)                    \
91   F(MC_MARK_PREPARE_CODE_FLUSH)                    \
92   F(MC_MARK_ROOTS)                                 \
93   F(MC_MARK_WEAK_CLOSURE)                          \
94   F(MC_MARK_WEAK_CLOSURE_EPHEMERAL)                \
95   F(MC_MARK_WEAK_CLOSURE_WEAK_HANDLES)             \
96   F(MC_MARK_WEAK_CLOSURE_WEAK_ROOTS)               \
97   F(MC_MARK_WEAK_CLOSURE_HARMONY)                  \
98   F(MC_SWEEP)                                      \
99   F(MC_SWEEP_CODE)                                 \
100   F(MC_SWEEP_MAP)                                  \
101   F(MC_SWEEP_OLD)                                  \
102   F(SCAVENGER_CODE_FLUSH_CANDIDATES)               \
103   F(SCAVENGER_EXTERNAL_EPILOGUE)                   \
104   F(SCAVENGER_EXTERNAL_PROLOGUE)                   \
105   F(SCAVENGER_OBJECT_GROUPS)                       \
106   F(SCAVENGER_OLD_TO_NEW_POINTERS)                 \
107   F(SCAVENGER_ROOTS)                               \
108   F(SCAVENGER_SCAVENGE)                            \
109   F(SCAVENGER_SEMISPACE)                           \
110   F(SCAVENGER_WEAK)
111 
112 #define TRACE_GC(tracer, scope_id)                             \
113   GCTracer::Scope::ScopeId gc_tracer_scope_id(scope_id);       \
114   GCTracer::Scope gc_tracer_scope(tracer, gc_tracer_scope_id); \
115   TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("v8.gc"),             \
116                GCTracer::Scope::Name(gc_tracer_scope_id))
117 
118 // GCTracer collects and prints ONE line after each garbage collector
119 // invocation IFF --trace_gc is used.
120 // TODO(ernstm): Unit tests.
121 class GCTracer {
122  public:
123   class Scope {
124    public:
125     enum ScopeId {
126 #define DEFINE_SCOPE(scope) scope,
127       TRACER_SCOPES(DEFINE_SCOPE)
128 #undef DEFINE_SCOPE
129           NUMBER_OF_SCOPES
130     };
131 
132     Scope(GCTracer* tracer, ScopeId scope);
133     ~Scope();
134     static const char* Name(ScopeId id);
135 
136    private:
137     GCTracer* tracer_;
138     ScopeId scope_;
139     double start_time_;
140     RuntimeCallTimer timer_;
141 
142     DISALLOW_COPY_AND_ASSIGN(Scope);
143   };
144 
145 
146   class Event {
147    public:
148     enum Type {
149       SCAVENGER = 0,
150       MARK_COMPACTOR = 1,
151       INCREMENTAL_MARK_COMPACTOR = 2,
152       START = 3
153     };
154 
155     // Default constructor leaves the event uninitialized.
Event()156     Event() {}
157 
158     Event(Type type, const char* gc_reason, const char* collector_reason);
159 
160     // Returns a string describing the event type.
161     const char* TypeName(bool short_name) const;
162 
163     // Type of event
164     Type type;
165 
166     const char* gc_reason;
167     const char* collector_reason;
168 
169     // Timestamp set in the constructor.
170     double start_time;
171 
172     // Timestamp set in the destructor.
173     double end_time;
174 
175     // Memory reduction flag set.
176     bool reduce_memory;
177 
178     // Size of objects in heap set in constructor.
179     intptr_t start_object_size;
180 
181     // Size of objects in heap set in destructor.
182     intptr_t end_object_size;
183 
184     // Size of memory allocated from OS set in constructor.
185     intptr_t start_memory_size;
186 
187     // Size of memory allocated from OS set in destructor.
188     intptr_t end_memory_size;
189 
190     // Total amount of space either wasted or contained in one of free lists
191     // before the current GC.
192     intptr_t start_holes_size;
193 
194     // Total amount of space either wasted or contained in one of free lists
195     // after the current GC.
196     intptr_t end_holes_size;
197 
198     // Size of new space objects in constructor.
199     intptr_t new_space_object_size;
200     // Size of survived new space objects in desctructor.
201     intptr_t survived_new_space_object_size;
202 
203     // Number of incremental marking steps since creation of tracer.
204     // (value at start of event)
205     int cumulative_incremental_marking_steps;
206 
207     // Incremental marking steps since
208     // - last event for SCAVENGER events
209     // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
210     // events
211     int incremental_marking_steps;
212 
213     // Bytes marked since creation of tracer (value at start of event).
214     intptr_t cumulative_incremental_marking_bytes;
215 
216     // Bytes marked since
217     // - last event for SCAVENGER events
218     // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
219     // events
220     intptr_t incremental_marking_bytes;
221 
222     // Cumulative duration of incremental marking steps since creation of
223     // tracer. (value at start of event)
224     double cumulative_incremental_marking_duration;
225 
226     // Duration of incremental marking steps since
227     // - last event for SCAVENGER events
228     // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
229     // events
230     double incremental_marking_duration;
231 
232     // Cumulative pure duration of incremental marking steps since creation of
233     // tracer. (value at start of event)
234     double cumulative_pure_incremental_marking_duration;
235 
236     // Duration of pure incremental marking steps since
237     // - last event for SCAVENGER events
238     // - last INCREMENTAL_MARK_COMPACTOR event for INCREMENTAL_MARK_COMPACTOR
239     // events
240     double pure_incremental_marking_duration;
241 
242     // Longest incremental marking step since start of marking.
243     // (value at start of event)
244     double longest_incremental_marking_step;
245 
246     // Amounts of time spent in different scopes during GC.
247     double scopes[Scope::NUMBER_OF_SCOPES];
248   };
249 
250   static const int kThroughputTimeFrameMs = 5000;
251 
252   explicit GCTracer(Heap* heap);
253 
254   // Start collecting data.
255   void Start(GarbageCollector collector, const char* gc_reason,
256              const char* collector_reason);
257 
258   // Stop collecting data and print results.
259   void Stop(GarbageCollector collector);
260 
261   // Sample and accumulate bytes allocated since the last GC.
262   void SampleAllocation(double current_ms, size_t new_space_counter_bytes,
263                         size_t old_generation_counter_bytes);
264 
265   // Log the accumulated new space allocation bytes.
266   void AddAllocation(double current_ms);
267 
268   void AddContextDisposalTime(double time);
269 
270   void AddCompactionEvent(double duration, intptr_t live_bytes_compacted);
271 
272   void AddSurvivalRatio(double survival_ratio);
273 
274   // Log an incremental marking step.
275   void AddIncrementalMarkingStep(double duration, intptr_t bytes);
276 
277   void AddIncrementalMarkingFinalizationStep(double duration);
278 
279   // Log time spent in marking.
AddMarkingTime(double duration)280   void AddMarkingTime(double duration) {
281     cumulative_marking_duration_ += duration;
282   }
283 
284   // Time spent in marking.
cumulative_marking_duration()285   double cumulative_marking_duration() const {
286     return cumulative_marking_duration_;
287   }
288 
289   // Log time spent in sweeping on main thread.
AddSweepingTime(double duration)290   void AddSweepingTime(double duration) {
291     cumulative_sweeping_duration_ += duration;
292   }
293 
294   // Time spent in sweeping on main thread.
cumulative_sweeping_duration()295   double cumulative_sweeping_duration() const {
296     return cumulative_sweeping_duration_;
297   }
298 
299   // Compute the average incremental marking speed in bytes/millisecond.
300   // Returns 0 if no events have been recorded.
301   double IncrementalMarkingSpeedInBytesPerMillisecond() const;
302 
303   // Compute the average scavenge speed in bytes/millisecond.
304   // Returns 0 if no events have been recorded.
305   double ScavengeSpeedInBytesPerMillisecond(
306       ScavengeSpeedMode mode = kForAllObjects) const;
307 
308   // Compute the average compaction speed in bytes/millisecond.
309   // Returns 0 if not enough events have been recorded.
310   double CompactionSpeedInBytesPerMillisecond() const;
311 
312   // Compute the average mark-sweep speed in bytes/millisecond.
313   // Returns 0 if no events have been recorded.
314   double MarkCompactSpeedInBytesPerMillisecond() const;
315 
316   // Compute the average incremental mark-sweep finalize speed in
317   // bytes/millisecond.
318   // Returns 0 if no events have been recorded.
319   double FinalIncrementalMarkCompactSpeedInBytesPerMillisecond() const;
320 
321   // Compute the overall mark compact speed including incremental steps
322   // and the final mark-compact step.
323   double CombinedMarkCompactSpeedInBytesPerMillisecond();
324 
325   // Allocation throughput in the new space in bytes/millisecond.
326   // Returns 0 if no allocation events have been recorded.
327   double NewSpaceAllocationThroughputInBytesPerMillisecond(
328       double time_ms = 0) const;
329 
330   // Allocation throughput in the old generation in bytes/millisecond in the
331   // last time_ms milliseconds.
332   // Returns 0 if no allocation events have been recorded.
333   double OldGenerationAllocationThroughputInBytesPerMillisecond(
334       double time_ms = 0) const;
335 
336   // Allocation throughput in heap in bytes/millisecond in the last time_ms
337   // milliseconds.
338   // Returns 0 if no allocation events have been recorded.
339   double AllocationThroughputInBytesPerMillisecond(double time_ms) const;
340 
341   // Allocation throughput in heap in bytes/milliseconds in the last
342   // kThroughputTimeFrameMs seconds.
343   // Returns 0 if no allocation events have been recorded.
344   double CurrentAllocationThroughputInBytesPerMillisecond() const;
345 
346   // Allocation throughput in old generation in bytes/milliseconds in the last
347   // kThroughputTimeFrameMs seconds.
348   // Returns 0 if no allocation events have been recorded.
349   double CurrentOldGenerationAllocationThroughputInBytesPerMillisecond() const;
350 
351   // Computes the context disposal rate in milliseconds. It takes the time
352   // frame of the first recorded context disposal to the current time and
353   // divides it by the number of recorded events.
354   // Returns 0 if no events have been recorded.
355   double ContextDisposalRateInMilliseconds() const;
356 
357   // Computes the average survival ratio based on the last recorded survival
358   // events.
359   // Returns 0 if no events have been recorded.
360   double AverageSurvivalRatio() const;
361 
362   // Returns true if at least one survival event was recorded.
363   bool SurvivalEventsRecorded() const;
364 
365   // Discard all recorded survival events.
366   void ResetSurvivalEvents();
367 
368   // Returns the average speed of the events in the buffer.
369   // If the buffer is empty, the result is 0.
370   // Otherwise, the result is between 1 byte/ms and 1 GB/ms.
371   static double AverageSpeed(const RingBuffer<BytesAndDuration>& buffer);
372   static double AverageSpeed(const RingBuffer<BytesAndDuration>& buffer,
373                              const BytesAndDuration& initial, double time_ms);
374 
375   void ResetForTesting();
376 
377  private:
378   // Print one detailed trace line in name=value format.
379   // TODO(ernstm): Move to Heap.
380   void PrintNVP() const;
381 
382   // Print one trace line.
383   // TODO(ernstm): Move to Heap.
384   void Print() const;
385 
386   // Prints a line and also adds it to the heap's ring buffer so that
387   // it can be included in later crash dumps.
388   void PRINTF_FORMAT(2, 3) Output(const char* format, ...) const;
389 
ClearMarkCompactStatistics()390   void ClearMarkCompactStatistics() {
391     cumulative_incremental_marking_steps_ = 0;
392     cumulative_incremental_marking_bytes_ = 0;
393     cumulative_incremental_marking_duration_ = 0;
394     cumulative_pure_incremental_marking_duration_ = 0;
395     longest_incremental_marking_step_ = 0;
396     cumulative_incremental_marking_finalization_steps_ = 0;
397     cumulative_incremental_marking_finalization_duration_ = 0;
398     longest_incremental_marking_finalization_step_ = 0;
399     cumulative_marking_duration_ = 0;
400     cumulative_sweeping_duration_ = 0;
401   }
402 
TotalExternalTime()403   double TotalExternalTime() const {
404     return current_.scopes[Scope::EXTERNAL_WEAK_GLOBAL_HANDLES] +
405            current_.scopes[Scope::MC_EXTERNAL_EPILOGUE] +
406            current_.scopes[Scope::MC_EXTERNAL_PROLOGUE] +
407            current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_EPILOGUE] +
408            current_.scopes[Scope::MC_INCREMENTAL_EXTERNAL_PROLOGUE] +
409            current_.scopes[Scope::SCAVENGER_EXTERNAL_EPILOGUE] +
410            current_.scopes[Scope::SCAVENGER_EXTERNAL_PROLOGUE];
411   }
412 
413   // Pointer to the heap that owns this tracer.
414   Heap* heap_;
415 
416   // Current tracer event. Populated during Start/Stop cycle. Valid after Stop()
417   // has returned.
418   Event current_;
419 
420   // Previous tracer event.
421   Event previous_;
422 
423   // Previous INCREMENTAL_MARK_COMPACTOR event.
424   Event previous_incremental_mark_compactor_event_;
425 
426   // Cumulative number of incremental marking steps since creation of tracer.
427   int cumulative_incremental_marking_steps_;
428 
429   // Cumulative size of incremental marking steps (in bytes) since creation of
430   // tracer.
431   intptr_t cumulative_incremental_marking_bytes_;
432 
433   // Cumulative duration of incremental marking steps since creation of tracer.
434   double cumulative_incremental_marking_duration_;
435 
436   // Cumulative duration of pure incremental marking steps since creation of
437   // tracer.
438   double cumulative_pure_incremental_marking_duration_;
439 
440   // Longest incremental marking step since start of marking.
441   double longest_incremental_marking_step_;
442 
443   // Cumulative number of incremental marking finalization steps since creation
444   // of tracer.
445   int cumulative_incremental_marking_finalization_steps_;
446 
447   // Cumulative duration of incremental marking finalization steps since
448   // creation of tracer.
449   double cumulative_incremental_marking_finalization_duration_;
450 
451   // Longest incremental marking finalization step since start of marking.
452   double longest_incremental_marking_finalization_step_;
453 
454   // Total marking time.
455   // This timer is precise when run with --print-cumulative-gc-stat
456   double cumulative_marking_duration_;
457 
458   // Total sweeping time on the main thread.
459   // This timer is precise when run with --print-cumulative-gc-stat
460   // TODO(hpayer): Account for sweeping time on sweeper threads. Add a
461   // different field for that.
462   // TODO(hpayer): This timer right now just holds the sweeping time
463   // of the initial atomic sweeping pause. Make sure that it accumulates
464   // all sweeping operations performed on the main thread.
465   double cumulative_sweeping_duration_;
466 
467   // Timestamp and allocation counter at the last sampled allocation event.
468   double allocation_time_ms_;
469   size_t new_space_allocation_counter_bytes_;
470   size_t old_generation_allocation_counter_bytes_;
471 
472   // Accumulated duration and allocated bytes since the last GC.
473   double allocation_duration_since_gc_;
474   size_t new_space_allocation_in_bytes_since_gc_;
475   size_t old_generation_allocation_in_bytes_since_gc_;
476 
477   double combined_mark_compact_speed_cache_;
478 
479   // Counts how many tracers were started without stopping.
480   int start_counter_;
481 
482   // Separate timer used for --runtime_call_stats
483   RuntimeCallTimer timer_;
484 
485   RingBuffer<BytesAndDuration> recorded_incremental_marking_steps_;
486   RingBuffer<BytesAndDuration> recorded_scavenges_total_;
487   RingBuffer<BytesAndDuration> recorded_scavenges_survived_;
488   RingBuffer<BytesAndDuration> recorded_compactions_;
489   RingBuffer<BytesAndDuration> recorded_mark_compacts_;
490   RingBuffer<BytesAndDuration> recorded_incremental_mark_compacts_;
491   RingBuffer<BytesAndDuration> recorded_new_generation_allocations_;
492   RingBuffer<BytesAndDuration> recorded_old_generation_allocations_;
493   RingBuffer<double> recorded_context_disposal_times_;
494   RingBuffer<double> recorded_survival_ratios_;
495 
496   DISALLOW_COPY_AND_ASSIGN(GCTracer);
497 };
498 }  // namespace internal
499 }  // namespace v8
500 
501 #endif  // V8_HEAP_GC_TRACER_H_
502