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: 19 RingBuffer() { Reset(); } 20 static const int kSize = 10; 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 31 int Count() const { return count_; } 32 33 template <typename Callback> 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 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 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. 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. 280 void AddMarkingTime(double duration) { 281 cumulative_marking_duration_ += duration; 282 } 283 284 // Time spent in marking. 285 double cumulative_marking_duration() const { 286 return cumulative_marking_duration_; 287 } 288 289 // Log time spent in sweeping on main thread. 290 void AddSweepingTime(double duration) { 291 cumulative_sweeping_duration_ += duration; 292 } 293 294 // Time spent in sweeping on main thread. 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 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 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