Measure new space allocation throughput.

src/heap/gc-tracer.cc

 // Copyright 2014 the V8 project authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "src/v8.h"
 
 #include "src/heap/gc-tracer.h"
 
 namespace v8 {
 namespace internal {
 
 static intptr_t CountTotalHolesSize(Heap* heap) {
   intptr_t holes_size = 0;
   OldSpaces spaces(heap);
   for (OldSpace* space = spaces.next(); space != NULL; space = spaces.next()) {
     holes_size += space->Waste() + space->Available();
   }
   return holes_size;
 }
 
 
+GCTracer::AllocationEvent::AllocationEvent(double duration,
+                                           intptr_t allocation_in_bytes) {
+  duration_ = duration;
+  allocation_in_bytes_ = allocation_in_bytes;
+}
+
+
 GCTracer::Event::Event(Type type, const char* gc_reason,
                        const char* collector_reason)
     : type(type),
       gc_reason(gc_reason),
       collector_reason(collector_reason),
       start_time(0.0),
       end_time(0.0),
       start_object_size(0),
       end_object_size(0),
       start_memory_size(0),
@@ skipping 41 matching lines @@
 
 
 GCTracer::GCTracer(Heap* heap)
     : heap_(heap),
       cumulative_incremental_marking_steps_(0),
       cumulative_incremental_marking_bytes_(0),
       cumulative_incremental_marking_duration_(0.0),
       cumulative_pure_incremental_marking_duration_(0.0),
       longest_incremental_marking_step_(0.0),
       cumulative_marking_duration_(0.0),
-      cumulative_sweeping_duration_(0.0) {
+      cumulative_sweeping_duration_(0.0),
+      new_space_top_after_gc_(0) {
   current_ = Event(Event::START, NULL, NULL);
   current_.end_time = base::OS::TimeCurrentMillis();
   previous_ = previous_mark_compactor_event_ = current_;
 }
 
 
 void GCTracer::Start(GarbageCollector collector, const char* gc_reason,
                      const char* collector_reason) {
   previous_ = current_;
+  double start_time = base::OS::TimeCurrentMillis();
+  if (new_space_top_after_gc_ != 0) {
+    AddNewSpaceAllocationTime(
+        start_time - previous_.end_time,
+        reinterpret_cast<intptr_t>((heap_->new_space()->top()) -
+                                   new_space_top_after_gc_));
+  }
   if (current_.type == Event::MARK_COMPACTOR)
     previous_mark_compactor_event_ = current_;
 
   if (collector == SCAVENGER) {
     current_ = Event(Event::SCAVENGER, gc_reason, collector_reason);
   } else {
     current_ = Event(Event::MARK_COMPACTOR, gc_reason, collector_reason);
   }
 
-  current_.start_time = base::OS::TimeCurrentMillis();
+  current_.start_time = start_time;
   current_.start_object_size = heap_->SizeOfObjects();
   current_.start_memory_size = heap_->isolate()->memory_allocator()->Size();
   current_.start_holes_size = CountTotalHolesSize(heap_);
   current_.new_space_object_size =
       heap_->new_space()->top() - heap_->new_space()->bottom();
 
   current_.cumulative_incremental_marking_steps =
       cumulative_incremental_marking_steps_;
   current_.cumulative_incremental_marking_bytes =
       cumulative_incremental_marking_bytes_;
   current_.cumulative_incremental_marking_duration =
       cumulative_incremental_marking_duration_;
   current_.cumulative_pure_incremental_marking_duration =
       cumulative_pure_incremental_marking_duration_;
   current_.longest_incremental_marking_step = longest_incremental_marking_step_;
 
   for (int i = 0; i < Scope::NUMBER_OF_SCOPES; i++) {
     current_.scopes[i] = 0;
   }
 }
 
 
 void GCTracer::Stop() {
   current_.end_time = base::OS::TimeCurrentMillis();
   current_.end_object_size = heap_->SizeOfObjects();
   current_.end_memory_size = heap_->isolate()->memory_allocator()->Size();
   current_.end_holes_size = CountTotalHolesSize(heap_);
+  new_space_top_after_gc_ =
+      reinterpret_cast<intptr_t>(heap_->new_space()->top());
 
   if (current_.type == Event::SCAVENGER) {
     current_.incremental_marking_steps =
         current_.cumulative_incremental_marking_steps -
         previous_.cumulative_incremental_marking_steps;
     current_.incremental_marking_bytes =
         current_.cumulative_incremental_marking_bytes -
         previous_.cumulative_incremental_marking_bytes;
     current_.incremental_marking_duration =
         current_.cumulative_incremental_marking_duration -
@@ skipping 37 matching lines @@
     if (FLAG_trace_gc_nvp)
       PrintNVP();
     else
       Print();
 
     heap_->PrintShortHeapStatistics();
   }
 }
 
 
+void GCTracer::AddNewSpaceAllocationTime(double duration,
+                                         intptr_t allocation_in_bytes) {
+  allocation_events_.push_front(AllocationEvent(duration, allocation_in_bytes));
+}
+
+
 void GCTracer::AddIncrementalMarkingStep(double duration, intptr_t bytes) {
   cumulative_incremental_marking_steps_++;
   cumulative_incremental_marking_bytes_ += bytes;
   cumulative_incremental_marking_duration_ += duration;
   longest_incremental_marking_step_ =
       Max(longest_incremental_marking_step_, duration);
   cumulative_marking_duration_ += duration;
   if (bytes > 0) {
     cumulative_pure_incremental_marking_duration_ += duration;
   }
@@ skipping 90 matching lines @@
       current_.start_object_size - previous_.end_object_size;
   PrintF("allocated=%" V8_PTR_PREFIX "d ", allocated_since_last_gc);
   PrintF("promoted=%" V8_PTR_PREFIX "d ", heap_->promoted_objects_size_);
   PrintF("semi_space_copied=%" V8_PTR_PREFIX "d ",
          heap_->semi_space_copied_object_size_);
   PrintF("nodes_died_in_new=%d ", heap_->nodes_died_in_new_space_);
   PrintF("nodes_copied_in_new=%d ", heap_->nodes_copied_in_new_space_);
   PrintF("nodes_promoted=%d ", heap_->nodes_promoted_);
   PrintF("promotion_rate=%.1f%% ", heap_->promotion_rate_);
   PrintF("semi_space_copy_rate=%.1f%% ", heap_->semi_space_copied_rate_);
+  PrintF("new_space_allocation_throughput=%d ",
+         NewSpaceAllocationThroughputInBytesPerMillisecond());
 
   if (current_.type == Event::SCAVENGER) {
     PrintF("steps_count=%d ", current_.incremental_marking_steps);
     PrintF("steps_took=%.1f ", current_.incremental_marking_duration);
     PrintF("scavenge_throughput=%" V8_PTR_PREFIX "d ",
            ScavengeSpeedInBytesPerMillisecond());
   } else {
     PrintF("steps_count=%d ", current_.incremental_marking_steps);
     PrintF("steps_took=%.1f ", current_.incremental_marking_duration);
     PrintF("longest_step=%.1f ", current_.longest_incremental_marking_step);
@@ skipping 121 matching lines @@
     bytes += iter->start_object_size;
     durations += iter->end_time - iter->start_time +
                  iter->pure_incremental_marking_duration;
     ++iter;
   }
 
   if (durations == 0.0) return 0;
 
   return static_cast<intptr_t>(bytes / durations);
 }
+
+
+intptr_t GCTracer::NewSpaceAllocationThroughputInBytesPerMillisecond() const {
+  intptr_t bytes = 0;
+  double durations = 0.0;
+  AllocationEventBuffer::const_iterator iter = allocation_events_.begin();
+  while (iter != allocation_events_.end()) {
+    bytes += iter->allocation_in_bytes_;
+    durations += iter->duration_;
+    ++iter;
+  }
+
+  if (durations == 0.0) return 0;
+
+  return static_cast<intptr_t>(bytes / durations);
+}
 }
 }  // namespace v8::internal