Make new space allocation throughput estimation more accurate.
authorulan <ulan@chromium.org>
Thu, 21 May 2015 10:19:09 +0000 (03:19 -0700)
committerCommit bot <commit-bot@chromium.org>
Thu, 21 May 2015 10:18:51 +0000 (10:18 +0000)
Sample new space allocation throughput at scavenge and at idle notificatioon.

This will allow better estimation of mutator idleness for switching between
latency and memory modes in idle notification handler.

BUG=chromium:486005
LOG=NO
TEST=cctest/test-heap/NewSpaceAllocationThroughput

Review URL: https://codereview.chromium.org/1125193005

Cr-Commit-Position: refs/heads/master@{#28537}

src/heap/gc-tracer.cc
src/heap/gc-tracer.h
src/heap/heap.cc
src/heap/heap.h
src/heap/spaces.cc
src/heap/spaces.h
test/cctest/test-heap.cc

index 1c5226d..927915d 100644 (file)
@@ -20,7 +20,7 @@ static intptr_t CountTotalHolesSize(Heap* heap) {
 
 
 GCTracer::AllocationEvent::AllocationEvent(double duration,
-                                           intptr_t allocation_in_bytes) {
+                                           size_t allocation_in_bytes) {
   duration_ = duration;
   allocation_in_bytes_ = allocation_in_bytes;
 }
@@ -99,7 +99,10 @@ GCTracer::GCTracer(Heap* heap)
       longest_incremental_marking_step_(0.0),
       cumulative_marking_duration_(0.0),
       cumulative_sweeping_duration_(0.0),
-      new_space_top_after_gc_(0),
+      new_space_allocation_time_ms_(0.0),
+      new_space_allocation_counter_bytes_(0),
+      new_space_allocation_duration_since_gc_(0.0),
+      new_space_allocation_in_bytes_since_gc_(0),
       start_counter_(0) {
   current_ = Event(Event::START, NULL, NULL);
   current_.end_time = base::OS::TimeCurrentMillis();
@@ -114,12 +117,7 @@ void GCTracer::Start(GarbageCollector collector, const char* gc_reason,
 
   previous_ = current_;
   double start_time = heap_->MonotonicallyIncreasingTimeInMs();
-  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_));
-  }
+  SampleNewSpaceAllocation(start_time, heap_->NewSpaceAllocationCounter());
   if (current_.type == Event::INCREMENTAL_MARK_COMPACTOR)
     previous_incremental_mark_compactor_event_ = current_;
 
@@ -184,8 +182,8 @@ void GCTracer::Stop(GarbageCollector collector) {
   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());
+
+  AddNewSpaceAllocation(current_.end_time);
 
   int committed_memory = static_cast<int>(heap_->CommittedMemory() / KB);
   int used_memory = static_cast<int>(current_.end_object_size / KB);
@@ -259,9 +257,37 @@ void GCTracer::Stop(GarbageCollector collector) {
 }
 
 
-void GCTracer::AddNewSpaceAllocationTime(double duration,
-                                         intptr_t allocation_in_bytes) {
-  allocation_events_.push_front(AllocationEvent(duration, allocation_in_bytes));
+void GCTracer::SampleNewSpaceAllocation(double current_ms,
+                                        size_t counter_bytes) {
+  if (new_space_allocation_time_ms_ == 0) {
+    // It is the first sample.
+    new_space_allocation_time_ms_ = current_ms;
+    new_space_allocation_counter_bytes_ = counter_bytes;
+    return;
+  }
+  // This assumes that counters are unsigned integers so that the subtraction
+  // below works even if the new counter is less then the old counter.
+  size_t allocated_bytes = counter_bytes - new_space_allocation_counter_bytes_;
+  double duration = current_ms - new_space_allocation_time_ms_;
+  const double kMinDurationMs = 1;
+  if (duration < kMinDurationMs) {
+    // Do not sample small durations to avoid precision errors.
+    return;
+  }
+  new_space_allocation_time_ms_ = current_ms;
+  new_space_allocation_counter_bytes_ = counter_bytes;
+  new_space_allocation_duration_since_gc_ += duration;
+  new_space_allocation_in_bytes_since_gc_ += allocated_bytes;
+}
+
+
+void GCTracer::AddNewSpaceAllocation(double current_ms) {
+  new_space_allocation_time_ms_ = current_ms;
+  allocation_events_.push_front(
+      AllocationEvent(new_space_allocation_duration_since_gc_,
+                      new_space_allocation_in_bytes_since_gc_));
+  new_space_allocation_duration_since_gc_ = 0;
+  new_space_allocation_in_bytes_since_gc_ = 0;
 }
 
 
@@ -555,11 +581,12 @@ intptr_t GCTracer::FinalIncrementalMarkCompactSpeedInBytesPerMillisecond()
 }
 
 
-intptr_t GCTracer::NewSpaceAllocationThroughputInBytesPerMillisecond() const {
-  intptr_t bytes = 0;
-  double durations = 0.0;
+size_t GCTracer::NewSpaceAllocationThroughputInBytesPerMillisecond() const {
+  size_t bytes = new_space_allocation_in_bytes_since_gc_;
+  double durations = new_space_allocation_duration_since_gc_;
   AllocationEventBuffer::const_iterator iter = allocation_events_.begin();
-  while (iter != allocation_events_.end()) {
+  const size_t max_bytes = static_cast<size_t>(-1);
+  while (iter != allocation_events_.end() && bytes < max_bytes - bytes) {
     bytes += iter->allocation_in_bytes_;
     durations += iter->duration_;
     ++iter;
@@ -567,7 +594,27 @@ intptr_t GCTracer::NewSpaceAllocationThroughputInBytesPerMillisecond() const {
 
   if (durations == 0.0) return 0;
 
-  return static_cast<intptr_t>(bytes / durations);
+  return static_cast<size_t>(bytes / durations + 0.5);
+}
+
+
+size_t GCTracer::NewSpaceAllocatedBytesInLast(double time_ms) const {
+  size_t bytes = new_space_allocation_in_bytes_since_gc_;
+  double durations = new_space_allocation_duration_since_gc_;
+  AllocationEventBuffer::const_iterator iter = allocation_events_.begin();
+  const size_t max_bytes = static_cast<size_t>(-1);
+  while (iter != allocation_events_.end() && bytes < max_bytes - bytes &&
+         durations < time_ms) {
+    bytes += iter->allocation_in_bytes_;
+    durations += iter->duration_;
+    ++iter;
+  }
+
+  if (durations < time_ms) return 0;
+
+  bytes = static_cast<size_t>(bytes * (time_ms / durations) + 0.5);
+  // Return at least 1 since 0 means "no data".
+  return std::max<size_t>(bytes, 1);
 }
 
 
index ca144b2..df30dcc 100644 (file)
@@ -141,15 +141,15 @@ class GCTracer {
     // Default constructor leaves the event uninitialized.
     AllocationEvent() {}
 
-    AllocationEvent(double duration, intptr_t allocation_in_bytes);
+    AllocationEvent(double duration, size_t allocation_in_bytes);
 
-    // Time spent in the mutator during the end of the last garbage collection
-    // to the beginning of the next garbage collection.
+    // Time spent in the mutator during the end of the last sample to the
+    // beginning of the next sample.
     double duration_;
 
-    // Memory allocated in the new space during the end of the last garbage
-    // collection to the beginning of the next garbage collection.
-    intptr_t allocation_in_bytes_;
+    // Memory allocated in the new space during the end of the last sample
+    // to the beginning of the next sample
+    size_t allocation_in_bytes_;
   };
 
 
@@ -295,8 +295,11 @@ class GCTracer {
   // Stop collecting data and print results.
   void Stop(GarbageCollector collector);
 
-  // Log an allocation throughput event.
-  void AddNewSpaceAllocationTime(double duration, intptr_t allocation_in_bytes);
+  // Sample and accumulate bytes allocated since the last GC.
+  void SampleNewSpaceAllocation(double current_ms, size_t counter_bytes);
+
+  // Log the accumulated new space allocation bytes.
+  void AddNewSpaceAllocation(double current_ms);
 
   void AddContextDisposalTime(double time);
 
@@ -379,8 +382,12 @@ class GCTracer {
   intptr_t FinalIncrementalMarkCompactSpeedInBytesPerMillisecond() const;
 
   // Allocation throughput in the new space in bytes/millisecond.
-  // Returns 0 if no events have been recorded.
-  intptr_t NewSpaceAllocationThroughputInBytesPerMillisecond() const;
+  // Returns 0 if no allocation events have been recorded.
+  size_t NewSpaceAllocationThroughputInBytesPerMillisecond() const;
+
+  // Bytes allocated in new space in the specified time.
+  // Returns 0 if no allocation events have been recorded.
+  size_t NewSpaceAllocatedBytesInLast(double time_ms) const;
 
   // Computes the context disposal rate in milliseconds. It takes the time
   // frame of the first recorded context disposal to the current time and
@@ -485,9 +492,13 @@ class GCTracer {
   // all sweeping operations performed on the main thread.
   double cumulative_sweeping_duration_;
 
-  // Holds the new space top pointer recorded at the end of the last garbage
-  // collection.
-  intptr_t new_space_top_after_gc_;
+  // Timestamp and allocation counter at the last sampled allocation event.
+  double new_space_allocation_time_ms_;
+  size_t new_space_allocation_counter_bytes_;
+
+  // Accumulated duration and allocated bytes since the last GC.
+  double new_space_allocation_duration_since_gc_;
+  size_t new_space_allocation_in_bytes_since_gc_;
 
   // Counts how many tracers were started without stopping.
   int start_counter_;
index 62c3821..e801ff9 100644 (file)
@@ -141,6 +141,7 @@ Heap::Heap()
       gc_count_at_last_idle_gc_(0),
       full_codegen_bytes_generated_(0),
       crankshaft_codegen_bytes_generated_(0),
+      new_space_allocation_counter_(0),
       gcs_since_last_deopt_(0),
       allocation_sites_scratchpad_length_(0),
       promotion_queue_(this),
@@ -461,6 +462,7 @@ void Heap::GarbageCollectionPrologue() {
     maximum_size_scavenges_ = 0;
   }
   CheckNewSpaceExpansionCriteria();
+  UpdateNewSpaceAllocationCounter();
 }
 
 
@@ -4620,8 +4622,7 @@ GCIdleTimeHandler::HeapState Heap::ComputeHeapState(bool reduce_memory) {
   heap_state.used_new_space_size = new_space_.Size();
   heap_state.new_space_capacity = new_space_.Capacity();
   heap_state.new_space_allocation_throughput_in_bytes_per_ms =
-      static_cast<size_t>(
-          tracer()->NewSpaceAllocationThroughputInBytesPerMillisecond());
+      tracer()->NewSpaceAllocationThroughputInBytesPerMillisecond();
   return heap_state;
 }
 
@@ -4774,6 +4775,10 @@ bool Heap::IdleNotification(double deadline_in_seconds) {
       GCIdleTimeHandler::kMaxFrameRenderingIdleTime;
   bool has_low_gc_activity = (start_ms - last_gc_time_) > kLastGCTimeTreshold;
 
+  if (is_long_idle_notification) {
+    tracer()->SampleNewSpaceAllocation(start_ms, NewSpaceAllocationCounter());
+  }
+
   GCIdleTimeHandler::HeapState heap_state =
       ComputeHeapState(is_long_idle_notification && has_low_gc_activity);
 
index 4535bbb..8b41fb7 100644 (file)
@@ -1312,6 +1312,19 @@ class Heap {
     }
   }
 
+  void UpdateNewSpaceAllocationCounter() {
+    new_space_allocation_counter_ = NewSpaceAllocationCounter();
+  }
+
+  size_t NewSpaceAllocationCounter() {
+    return new_space_allocation_counter_ + new_space()->AllocatedSinceLastGC();
+  }
+
+  // This should be used only for testing.
+  void set_new_space_allocation_counter(size_t new_value) {
+    new_space_allocation_counter_ = new_value;
+  }
+
   // Update GC statistics that are tracked on the Heap.
   void UpdateCumulativeGCStatistics(double duration, double spent_in_mutator,
                                     double marking_time);
@@ -2182,6 +2195,11 @@ class Heap {
   size_t full_codegen_bytes_generated_;
   size_t crankshaft_codegen_bytes_generated_;
 
+  // This counter is increased before each GC and never reset.
+  // To account for the bytes allocated since the last GC, use the
+  // NewSpaceAllocationCounter() function.
+  size_t new_space_allocation_counter_;
+
   // If the --deopt_every_n_garbage_collections flag is set to a positive value,
   // this variable holds the number of garbage collections since the last
   // deoptimization triggered by garbage collection.
index fea1416..8069e51 100644 (file)
@@ -1576,7 +1576,7 @@ void SemiSpace::SetUp(Address start, int initial_capacity, int target_capacity,
   address_mask_ = ~(maximum_capacity - 1);
   object_mask_ = address_mask_ | kHeapObjectTagMask;
   object_expected_ = reinterpret_cast<uintptr_t>(start) | kHeapObjectTag;
-  age_mark_ = start_;
+  age_mark_ = start_ + NewSpacePage::kObjectStartOffset;
 }
 
 
index b1a8c51..9f57ecc 100644 (file)
@@ -2439,6 +2439,25 @@ class NewSpace : public Space {
   // Return the available bytes without growing.
   intptr_t Available() override { return Capacity() - Size(); }
 
+  intptr_t PagesFromStart(Address addr) {
+    return static_cast<intptr_t>(addr - bottom()) / Page::kPageSize;
+  }
+
+  size_t AllocatedSinceLastGC() {
+    intptr_t allocated = top() - to_space_.age_mark();
+    if (allocated < 0) {
+      // Runtime has lowered the top below the age mark.
+      return 0;
+    }
+    // Correctly account for non-allocatable regions at the beginning of
+    // each page from the age_mark() to the top().
+    intptr_t pages =
+        PagesFromStart(top()) - PagesFromStart(to_space_.age_mark());
+    allocated -= pages * (NewSpacePage::kObjectStartOffset);
+    DCHECK(0 <= allocated && allocated <= Size());
+    return static_cast<size_t>(allocated);
+  }
+
   // Return the maximum capacity of a semispace.
   int MaximumCapacity() {
     DCHECK(to_space_.MaximumTotalCapacity() ==
index 2e5f180..94a50e5 100644 (file)
@@ -5473,3 +5473,89 @@ TEST(Regress1878) {
 
   CHECK(!try_catch.HasCaught());
 }
+
+
+void AllocateInNewSpace(Isolate* isolate, size_t bytes) {
+  CHECK(bytes >= FixedArray::kHeaderSize);
+  CHECK(bytes % kPointerSize == 0);
+  Factory* factory = isolate->factory();
+  HandleScope scope(isolate);
+  AlwaysAllocateScope always_allocate(isolate);
+  int elements =
+      static_cast<int>((bytes - FixedArray::kHeaderSize) / kPointerSize);
+  Handle<FixedArray> array = factory->NewFixedArray(elements, NOT_TENURED);
+  CHECK(isolate->heap()->InNewSpace(*array));
+  CHECK_EQ(bytes, static_cast<size_t>(array->Size()));
+}
+
+
+TEST(NewSpaceAllocationCounter) {
+  CcTest::InitializeVM();
+  v8::HandleScope scope(CcTest::isolate());
+  Isolate* isolate = CcTest::i_isolate();
+  Heap* heap = isolate->heap();
+  size_t counter1 = heap->NewSpaceAllocationCounter();
+  heap->CollectGarbage(NEW_SPACE);
+  const size_t kSize = 1024;
+  AllocateInNewSpace(isolate, kSize);
+  size_t counter2 = heap->NewSpaceAllocationCounter();
+  CHECK_EQ(kSize, counter2 - counter1);
+  heap->CollectGarbage(NEW_SPACE);
+  size_t counter3 = heap->NewSpaceAllocationCounter();
+  CHECK_EQ(0, counter3 - counter2);
+  // Test counter overflow.
+  size_t max_counter = -1;
+  heap->set_new_space_allocation_counter(max_counter - 10 * kSize);
+  size_t start = heap->NewSpaceAllocationCounter();
+  for (int i = 0; i < 20; i++) {
+    AllocateInNewSpace(isolate, kSize);
+    size_t counter = heap->NewSpaceAllocationCounter();
+    CHECK_EQ(kSize, counter - start);
+    start = counter;
+  }
+}
+
+
+TEST(NewSpaceAllocationThroughput) {
+  CcTest::InitializeVM();
+  v8::HandleScope scope(CcTest::isolate());
+  Isolate* isolate = CcTest::i_isolate();
+  Heap* heap = isolate->heap();
+  GCTracer* tracer = heap->tracer();
+  int time1 = 100;
+  size_t counter1 = 1000;
+  tracer->SampleNewSpaceAllocation(time1, counter1);
+  int time2 = 200;
+  size_t counter2 = 2000;
+  tracer->SampleNewSpaceAllocation(time2, counter2);
+  size_t throughput =
+      tracer->NewSpaceAllocationThroughputInBytesPerMillisecond();
+  CHECK_EQ((counter2 - counter1) / (time2 - time1), throughput);
+  int time3 = 1000;
+  size_t counter3 = 30000;
+  tracer->SampleNewSpaceAllocation(time3, counter3);
+  throughput = tracer->NewSpaceAllocationThroughputInBytesPerMillisecond();
+  CHECK_EQ((counter3 - counter1) / (time3 - time1), throughput);
+}
+
+
+TEST(NewSpaceAllocationThroughput2) {
+  CcTest::InitializeVM();
+  v8::HandleScope scope(CcTest::isolate());
+  Isolate* isolate = CcTest::i_isolate();
+  Heap* heap = isolate->heap();
+  GCTracer* tracer = heap->tracer();
+  int time1 = 100;
+  size_t counter1 = 1000;
+  tracer->SampleNewSpaceAllocation(time1, counter1);
+  int time2 = 200;
+  size_t counter2 = 2000;
+  tracer->SampleNewSpaceAllocation(time2, counter2);
+  size_t bytes = tracer->NewSpaceAllocatedBytesInLast(1000);
+  CHECK_EQ(0, bytes);
+  int time3 = 1000;
+  size_t counter3 = 30000;
+  tracer->SampleNewSpaceAllocation(time3, counter3);
+  bytes = tracer->NewSpaceAllocatedBytesInLast(100);
+  CHECK_EQ((counter3 - counter1) * 100 / (time3 - time1), bytes);
+}