re-land: Track history of events in GCTracer.

- track incremental marking stats directly on GCTracer.
- add simple ring buffer class.
- track last 10 scavenges and mark-compacts in ring buffers on GCTracer.
- various clean-ups.

This is a re-land of https://codereview.chromium.org/391413006/ with
 - int instead of size_t in ring buffer unit test.
 - git cl format

R=hpayer@chromium.org
BUG=

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

git-svn-id: https://v8.googlecode.com/svn/branches/bleeding_edge@22593 ce2b1a6d-e550-0410-aec6-3dcde31c8c00

src/heap.h

@@ -547,10 +547,81 @@ enum ArrayStorageAllocationMode {
   INITIALIZE_ARRAY_ELEMENTS_WITH_HOLE
 };
 
+// TODO(ernstm): Move into GCTracer.
+// A simple ring buffer class with maximum size known at compile time.
+// The class only implements the functionality required in GCTracer.
+template <typename T, size_t MAX_SIZE>
+class RingBuffer {
+ public:
+  class const_iterator {
+   public:
+    const_iterator() : index_(0), elements_(NULL) {}
+
+    const_iterator(size_t index, const T* elements)
+        : index_(index), elements_(elements) {}
+
+    bool operator==(const const_iterator& rhs) const {
+      return elements_ == rhs.elements_ && index_ == rhs.index_;
+    }
+
+    bool operator!=(const const_iterator& rhs) const {
+      return elements_ != rhs.elements_ || index_ != rhs.index_;
+    }
+
+    operator const T*() const { return elements_ + index_; }
+
+    const T* operator->() const { return elements_ + index_; }
+
+    const T& operator*() const { return elements_[index_]; }
+
+    const_iterator& operator++() {
+      index_ = (index_ + 1) % (MAX_SIZE + 1);
+      return *this;
+    }
+
+    const_iterator& operator--() {
+      index_ = (index_ + MAX_SIZE) % (MAX_SIZE + 1);
+      return *this;
+    }
+
+   private:
+    size_t index_;
+    const T* elements_;
+  };
+
+  RingBuffer() : begin_(0), end_(0) {}
+
+  bool empty() const { return begin_ == end_; }
+  size_t size() const {
+    return (end_ - begin_ + MAX_SIZE + 1) % (MAX_SIZE + 1);
+  }
+  const_iterator begin() const { return const_iterator(begin_, elements_); }
+  const_iterator end() const { return const_iterator(end_, elements_); }
+  const_iterator back() const { return --end(); }
+  void push_back(const T& element) {
+    elements_[end_] = element;
+    end_ = (end_ + 1) % (MAX_SIZE + 1);
+    if (end_ == begin_) begin_ = (begin_ + 1) % (MAX_SIZE + 1);
+  }
+  void push_front(const T& element) {
+    begin_ = (begin_ + MAX_SIZE) % (MAX_SIZE + 1);
+    if (begin_ == end_) end_ = (end_ + MAX_SIZE) % (MAX_SIZE + 1);
+    elements_[begin_] = element;
+  }
+
+ private:
+  T elements_[MAX_SIZE + 1];
+  size_t begin_;
+  size_t end_;
+
+  DISALLOW_COPY_AND_ASSIGN(RingBuffer);
+};
+
 
 // GCTracer collects and prints ONE line after each garbage collector
 // invocation IFF --trace_gc is used.
 
+// TODO(ernstm): Unit tests. Move to separate file.
 class GCTracer BASE_EMBEDDED {
  public:
   class Scope BASE_EMBEDDED {
@@ -585,7 +656,8 @@ class GCTracer BASE_EMBEDDED {
 
     ~Scope() {
       ASSERT(scope_ < NUMBER_OF_SCOPES);  // scope_ is unsigned.
-      tracer_->scopes_[scope_] += base::OS::TimeCurrentMillis() - start_time_;
+      tracer_->current_.scopes[scope_] +=
+          base::OS::TimeCurrentMillis() - start_time_;
     }
 
    private:
@@ -596,72 +668,119 @@ class GCTracer BASE_EMBEDDED {
     DISALLOW_COPY_AND_ASSIGN(Scope);
   };
 
+
+  class Event {
+   public:
+    enum Type { SCAVENGER = 0, MARK_COMPACTOR = 1, START = 2 };
+
+    // Default constructor leaves the event uninitialized.
+    Event() {}
+
+    Event(Type type, const char* gc_reason, const char* collector_reason);
+
+    // Returns a string describing the event type.
+    const char* TypeName(bool short_name) const;
+
+    // Type of event
+    Type type;
+
+    const char* gc_reason;
+    const char* collector_reason;
+
+    // Timestamp set in the constructor.
+    double start_time;
+
+    // Timestamp set in the destructor.
+    double end_time;
+
+    // Size of objects in heap set in constructor.
+    intptr_t start_object_size;
+
+    // Size of objects in heap set in destructor.
+    intptr_t end_object_size;
+
+    // Size of memory allocated from OS set in constructor.
+    intptr_t start_memory_size;
+
+    // Size of memory allocated from OS set in destructor.
+    intptr_t end_memory_size;
+
+    // Total amount of space either wasted or contained in one of free lists
+    // before the current GC.
+    intptr_t start_holes_size;
+
+    // Total amount of space either wasted or contained in one of free lists
+    // after the current GC.
+    intptr_t end_holes_size;
+
+    // Number of incremental marking steps since creation of tracer.
+    // (value at start of event)
+    int incremental_marking_steps;
+
+    // Cumulative duration of incremental marking steps since creation of
+    // tracer. (value at start of event)
+    double incremental_marking_duration;
+
+    // Longest incremental marking step since start of marking.
+    // (value at start of event)
+    double longest_incremental_marking_step;
+
+    // Amounts of time spent in different scopes during GC.
+    double scopes[Scope::NUMBER_OF_SCOPES];
+  };
+
+  static const int kRingBufferMaxSize = 10;
+
+  typedef RingBuffer<Event, kRingBufferMaxSize> EventBuffer;
+
   explicit GCTracer(Heap* heap);
 
   // Start collecting data.
-  void start(GarbageCollector collector, const char* gc_reason,
+  void Start(GarbageCollector collector, const char* gc_reason,
              const char* collector_reason);
 
   // Stop collecting data and print results.
-  void stop();
+  void Stop();
 
- private:
-  // Returns a string matching the collector.
-  const char* CollectorString() const;
+  // Log an incremental marking step.
+  void AddIncrementalMarkingStep(double duration);
 
+ private:
   // Print one detailed trace line in name=value format.
+  // TODO(ernstm): Move to Heap.
   void PrintNVP() const;
 
   // Print one trace line.
+  // TODO(ernstm): Move to Heap.
   void Print() const;
 
-  // Timestamp set in the constructor.
-  double start_time_;
-
-  // Timestamp set in the destructor.
-  double end_time_;
-
-  // Size of objects in heap set in constructor.
-  intptr_t start_object_size_;
-
-  // Size of objects in heap set in destructor.
-  intptr_t end_object_size_;
-
-  // Size of memory allocated from OS set in constructor.
-  intptr_t start_memory_size_;
+  // Pointer to the heap that owns this tracer.
+  Heap* heap_;
 
-  // Size of memory allocated from OS set in destructor.
-  intptr_t end_memory_size_;
+  // Current tracer event. Populated during Start/Stop cycle. Valid after Stop()
+  // has returned.
+  Event current_;
 
-  // Type of collector.
-  GarbageCollector collector_;
+  // Previous tracer event.
+  Event previous_;
 
-  // Amounts of time spent in different scopes during GC.
-  double scopes_[Scope::NUMBER_OF_SCOPES];
+  // Previous MARK_COMPACTOR event.
+  Event previous_mark_compactor_event_;
 
-  // Total amount of space either wasted or contained in one of free lists
-  // before the current GC.
-  intptr_t in_free_list_or_wasted_before_gc_;
+  // RingBuffers for SCAVENGER events.
+  EventBuffer scavenger_events_;
 
-  // Difference between space used in the heap at the beginning of the current
-  // collection and the end of the previous collection.
-  intptr_t allocated_since_last_gc_;
+  // RingBuffers for MARK_COMPACTOR events.
+  EventBuffer mark_compactor_events_;
 
-  // Amount of time spent in mutator that is time elapsed between end of the
-  // previous collection and the beginning of the current one.
-  double spent_in_mutator_;
+  // Cumulative number of incremental marking steps since creation of tracer.
+  int incremental_marking_steps_;
 
-  // Incremental marking steps counters.
-  int steps_count_;
-  double steps_took_;
-  double longest_step_;
-  int steps_count_since_last_gc_;
-  double steps_took_since_last_gc_;
+  // Cumulative duration of incremental marking steps since creation of tracer.
+  double incremental_marking_duration_;
 
-  Heap* heap_;
-
-  const char* gc_reason_;
-  const char* collector_reason_;
+  // Longest incremental marking step since start of marking.
+  double longest_incremental_marking_step_;
 
   DISALLOW_COPY_AND_ASSIGN(GCTracer);
 };
@@ -1367,8 +1486,8 @@ class Heap {
   }
 
   // Update GC statistics that are tracked on the Heap.
-  void UpdateGCStatistics(double start_time, double end_time,
-                          double spent_in_mutator, double marking_time);
+  void UpdateCumulativeGCStatistics(double duration, double spent_in_mutator,
+                                    double marking_time);
 
   // Returns maximum GC pause.
   double get_max_gc_pause() { return max_gc_pause_; }
@@ -2238,11 +2357,6 @@ class Heap {
   // Minimal interval between two subsequent collections.
   double min_in_mutator_;
 
-  // Size of objects alive after last GC.
-  intptr_t alive_after_last_gc_;
-
-  double last_gc_end_timestamp_;
-
   // Cumulative GC time spent in marking
   double marking_time_;
 

src/incremental-marking.cc

@@ -22,12 +22,8 @@ IncrementalMarking::IncrementalMarking(Heap* heap)
       marking_deque_memory_(NULL),
       marking_deque_memory_committed_(false),
       steps_count_(0),
-      steps_took_(0),
-      longest_step_(0.0),
       old_generation_space_available_at_start_of_incremental_(0),
       old_generation_space_used_at_start_of_incremental_(0),
-      steps_count_since_last_gc_(0),
-      steps_took_since_last_gc_(0),
       should_hurry_(false),
       marking_speed_(0),
       allocated_(0),
@@ -658,9 +654,6 @@ void IncrementalMarking::UpdateMarkingDequeAfterScavenge() {
     }
   }
   marking_deque_.set_top(new_top);
-
-  steps_took_since_last_gc_ = 0;
-  steps_count_since_last_gc_ = 0;
 }
 
 
@@ -895,7 +888,6 @@ void IncrementalMarking::Step(intptr_t allocated_bytes,
   }
 
   steps_count_++;
-  steps_count_since_last_gc_++;
 
   bool speed_up = false;
 
@@ -964,9 +956,7 @@ void IncrementalMarking::Step(intptr_t allocated_bytes,
       FLAG_print_cumulative_gc_stat) {
     double end = base::OS::TimeCurrentMillis();
     double delta = (end - start);
-    longest_step_ = Max(longest_step_, delta);
-    steps_took_ += delta;
-    steps_took_since_last_gc_ += delta;
+    heap_->tracer()->AddIncrementalMarkingStep(delta);
     heap_->AddMarkingTime(delta);
   }
 }
@@ -974,14 +964,10 @@ void IncrementalMarking::Step(intptr_t allocated_bytes,
 
 void IncrementalMarking::ResetStepCounters() {
   steps_count_ = 0;
-  steps_took_ = 0;
-  longest_step_ = 0.0;
   old_generation_space_available_at_start_of_incremental_ =
       SpaceLeftInOldSpace();
   old_generation_space_used_at_start_of_incremental_ =
       heap_->PromotedTotalSize();
-  steps_count_since_last_gc_ = 0;
-  steps_took_since_last_gc_ = 0;
   bytes_rescanned_ = 0;
   marking_speed_ = kInitialMarkingSpeed;
   bytes_scanned_ = 0;

src/incremental-marking.h

@@ -136,16 +136,6 @@ class IncrementalMarking {
 
   inline void WhiteToGreyAndPush(HeapObject* obj, MarkBit mark_bit);
 
-  inline int steps_count() { return steps_count_; }
-
-  inline double steps_took() { return steps_took_; }
-
-  inline double longest_step() { return longest_step_; }
-
-  inline int steps_count_since_last_gc() { return steps_count_since_last_gc_; }
-
-  inline double steps_took_since_last_gc() { return steps_took_since_last_gc_; }
-
   inline void SetOldSpacePageFlags(MemoryChunk* chunk) {
     SetOldSpacePageFlags(chunk, IsMarking(), IsCompacting());
   }
@@ -226,12 +216,8 @@ class IncrementalMarking {
   MarkingDeque marking_deque_;
 
   int steps_count_;
-  double steps_took_;
-  double longest_step_;
   int64_t old_generation_space_available_at_start_of_incremental_;
   int64_t old_generation_space_used_at_start_of_incremental_;
-  int steps_count_since_last_gc_;
-  double steps_took_since_last_gc_;
   int64_t bytes_rescanned_;
   bool should_hurry_;
   int marking_speed_;

test/cctest/cctest.gyp

@@ -78,6 +78,7 @@
         'test-fixed-dtoa.cc',
         'test-flags.cc',
         'test-func-name-inference.cc',
+        'test-gc-tracer.cc',
         'test-global-handles.cc',
         'test-global-object.cc',
         'test-hashing.cc',

test/cctest/cctest.status

@@ -31,6 +31,10 @@
   'test-api/Bug*': [FAIL],
 
   ##############################################################################
+
+  # BUG(3465): SerializeToplevelIsolates crashes.
+  'test-serialize/SerializeToplevelIsolates': [SKIP],
+
   # BUG(382): Weird test. Can't guarantee that it never times out.
   'test-api/ApplyInterruption': [PASS, TIMEOUT],
 

test/cctest/test-gc-tracer.cc

+// Copyright 2014 the V8 project authors. All rights reserved.
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+//       notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+//       copyright notice, this list of conditions and the following
+//       disclaimer in the documentation and/or other materials provided
+//       with the distribution.
+//     * Neither the name of Google Inc. nor the names of its
+//       contributors may be used to endorse or promote products derived
+//       from this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+#include <stdlib.h>
+#include <utility>
+
+#include "src/v8.h"
+
+#include "test/cctest/cctest.h"
+
+using namespace v8::internal;
+
+TEST(RingBufferPartialFill) {
+  const int max_size = 6;
+  typedef RingBuffer<int, max_size>::const_iterator Iter;
+  RingBuffer<int, max_size> ring_buffer;
+  CHECK(ring_buffer.empty());
+  CHECK_EQ(static_cast<int>(ring_buffer.size()), 0);
+  CHECK(ring_buffer.begin() == ring_buffer.end());
+
+  // Fill ring_buffer partially: [0, 1, 2]
+  for (int i = 0; i < max_size / 2; i++) ring_buffer.push_back(i);
+
+  CHECK(!ring_buffer.empty());
+  CHECK(static_cast<int>(ring_buffer.size()) == max_size / 2);
+  CHECK(ring_buffer.begin() != ring_buffer.end());
+
+  // Test forward itartion
+  int i = 0;
+  for (Iter iter = ring_buffer.begin(); iter != ring_buffer.end(); ++iter) {
+    CHECK(*iter == i);
+    ++i;
+  }
+  CHECK_EQ(i, 3);  // one past last element.
+
+  // Test backward iteration
+  i = 2;
+  Iter iter = ring_buffer.back();
+  while (true) {
+    CHECK(*iter == i);
+    if (iter == ring_buffer.begin()) break;
+    --iter;
+    --i;
+  }
+  CHECK_EQ(i, 0);
+}
+
+
+TEST(RingBufferWrapAround) {
+  const int max_size = 6;
+  typedef RingBuffer<int, max_size>::const_iterator Iter;
+  RingBuffer<int, max_size> ring_buffer;
+
+  // Fill ring_buffer (wrap around): [9, 10, 11, 12, 13, 14]
+  for (int i = 0; i < 2 * max_size + 3; i++) ring_buffer.push_back(i);
+
+  CHECK(!ring_buffer.empty());
+  CHECK(static_cast<int>(ring_buffer.size()) == max_size);
+  CHECK(ring_buffer.begin() != ring_buffer.end());
+
+  // Test forward iteration
+  int i = 9;
+  for (Iter iter = ring_buffer.begin(); iter != ring_buffer.end(); ++iter) {
+    CHECK(*iter == i);
+    ++i;
+  }
+  CHECK_EQ(i, 15);  // one past last element.
+
+  // Test backward iteration
+  i = 14;
+  Iter iter = ring_buffer.back();
+  while (true) {
+    CHECK(*iter == i);
+    if (iter == ring_buffer.begin()) break;
+    --iter;
+    --i;
+  }
+  CHECK_EQ(i, 9);
+}
+
+
+TEST(RingBufferPushFront) {
+  const int max_size = 6;
+  typedef RingBuffer<int, max_size>::const_iterator Iter;
+  RingBuffer<int, max_size> ring_buffer;
+
+  // Fill ring_buffer (wrap around): [14, 13, 12, 11, 10, 9]
+  for (int i = 0; i < 2 * max_size + 3; i++) ring_buffer.push_front(i);
+
+  CHECK(!ring_buffer.empty());
+  CHECK(static_cast<int>(ring_buffer.size()) == max_size);
+  CHECK(ring_buffer.begin() != ring_buffer.end());
+
+  // Test forward iteration
+  int i = 14;
+  for (Iter iter = ring_buffer.begin(); iter != ring_buffer.end(); ++iter) {
+    CHECK(*iter == i);
+    --i;
+  }
+  CHECK_EQ(i, 8);  // one past last element.
+}