- Consolidate verbose-gc output to be a single line which can be imported easily into spreadsheets.

runtime/vm/scavenger.cc

 // Copyright (c) 2011, the Dart project authors.  Please see the AUTHORS file
 // for details. All rights reserved. Use of this source code is governed by a
 // BSD-style license that can be found in the LICENSE file.
 
 #include "vm/scavenger.h"
 
 #include <algorithm>
 #include <map>
 #include <utility>
 
@@ skipping 56 matching lines @@
 
 class ScavengerVisitor : public ObjectPointerVisitor {
  public:
   explicit ScavengerVisitor(Isolate* isolate, Scavenger* scavenger)
       : ObjectPointerVisitor(isolate),
         scavenger_(scavenger),
         heap_(scavenger->heap_),
         vm_heap_(Dart::vm_isolate()->heap()),
         delayed_weak_stack_(),
         growth_policy_(PageSpace::kControlGrowth),
-        bytes_promoted_(0),
         visiting_old_pointers_(false),
         in_scavenge_pointer_(false) {}
 
   void VisitPointers(RawObject** first, RawObject** last) {
     for (RawObject** current = first; current <= last; current++) {
       ScavengePointer(current);
     }
   }
 
   GrowableArray<RawObject*>* DelayedWeakStack() {
@@ skipping 14 matching lines @@
     delay_set_.insert(std::make_pair(raw_key, raw_weak));
   }
 
   void Finalize() {
     DelaySet::iterator it = delay_set_.begin();
     for (; it != delay_set_.end(); ++it) {
       WeakProperty::Clear(it->second);
     }
   }
 
-  intptr_t bytes_promoted() { return bytes_promoted_; }
-
  private:
   void UpdateStoreBuffer(RawObject** p, RawObject* obj) {
     uword ptr = reinterpret_cast<uword>(p);
     ASSERT(obj->IsHeapObject());
     ASSERT(!scavenger_->Contains(ptr));
     ASSERT(!heap_->CodeContains(ptr));
     ASSERT(heap_->Contains(ptr));
     // If the newly written object is not a new object, drop it immediately.
     if (!obj->IsNewObject()) return;
     isolate()->store_buffer()->AddPointer(ptr);
@@ skipping 56 matching lines @@
         // a coin toss determines if an object is promoted or whether it should
         // survive in this generation.
         //
         // This object is a survivor of a previous scavenge. Attempt to promote
         // the object.
         new_addr = heap_->TryAllocate(size, Heap::kOld, growth_policy_);
         if (new_addr != 0) {
           // If promotion succeeded then we need to remember it so that it can
           // be traversed later.
           scavenger_->PushToPromotedStack(new_addr);
-          bytes_promoted_ += size;
           if (HeapTrace::is_enabled()) {
             heap_->trace()->TracePromotion(raw_addr, new_addr);
           }
         } else if (!scavenger_->had_promotion_failure_) {
           // Signal a promotion failure and set the growth policy for
           // this, and all subsequent promotion allocations, to force
           // growth.
           scavenger_->had_promotion_failure_ = true;
           growth_policy_ = PageSpace::kForceGrowth;
           new_addr = heap_->TryAllocate(size, Heap::kOld, growth_policy_);
           if (new_addr != 0) {
             scavenger_->PushToPromotedStack(new_addr);
-            bytes_promoted_ += size;
             if (HeapTrace::is_enabled()) {
               heap_->trace()->TracePromotion(raw_addr, new_addr);
             }
           } else {
             // Promotion did not succeed. Copy into the to space
             // instead.
             new_addr = scavenger_->TryAllocate(size);
             if (HeapTrace::is_enabled()) {
               heap_->trace()->TraceCopy(raw_addr, new_addr);
             }
@@ skipping 26 matching lines @@
     }
   }
 
   Scavenger* scavenger_;
   Heap* heap_;
   Heap* vm_heap_;
   typedef std::multimap<RawObject*, RawWeakProperty*> DelaySet;
   DelaySet delay_set_;
   GrowableArray<RawObject*> delayed_weak_stack_;
   PageSpace::GrowthPolicy growth_policy_;
-  intptr_t bytes_promoted_;
 
   bool visiting_old_pointers_;
   bool in_scavenge_pointer_;
 
   DISALLOW_COPY_AND_ASSIGN(ScavengerVisitor);
 };
 
 
 class ScavengerWeakVisitor : public HandleVisitor {
  public:
@@ skipping 35 matching lines @@
  private:
   MemoryRegion* to_;
 
   DISALLOW_COPY_AND_ASSIGN(VerifyStoreBufferPointerVisitor);
 };
 
 
 Scavenger::Scavenger(Heap* heap, intptr_t max_capacity, uword object_alignment)
     : heap_(heap),
       object_alignment_(object_alignment),
-      count_(0),
       scavenging_(false) {
   // Verify assumptions about the first word in objects which the scavenger is
   // going to use for forwarding pointers.
   ASSERT(Object::tags_offset() == 0);
   ASSERT(kForwardingMask == (1 << RawObject::kFreeBit));
 
   // Allocate the virtual memory for this scavenge heap.
   space_ = VirtualMemory::Reserve(max_capacity);
   ASSERT(space_ != NULL);
 
@@ skipping 93 matching lines @@
         }
         handled++;
         if (handled == count) {
           break;
         }
       }
     }
     delete pending;
     pending = next;
   }
-  if (FLAG_verbose_gc) {
-    OS::PrintErr("StoreBuffer: %"Pd", %"Pd" (entries, dups)\n",
-                 entries, duplicates);
-  }
+  heap_->RecordData(0, entries);
+  heap_->RecordData(1, duplicates);
   StoreBufferBlock* block = isolate->store_buffer_block();
   entries = block->Count();
   duplicates = 0;
   for (intptr_t i = 0; i < entries; i++) {
     RawObject** pointer = reinterpret_cast<RawObject**>(block->At(i));
     RawObject* value = *pointer;
     if (value->IsHeapObject()) {
       if (from_->Contains(RawObject::ToAddr(value))) {
         visitor->VisitPointer(pointer);
       } else {
         duplicates++;
       }
     }
   }
   block->Reset();
-  if (FLAG_verbose_gc) {
-    OS::PrintErr("StoreBufferBlock: %"Pd", %"Pd" (entries, dups)\n",
-                 entries, duplicates);
-  }
+  heap_->RecordData(2, entries);
+  heap_->RecordData(3, duplicates);

[siva, 2013/01/04 01:40:12]

It might be more readable to have an enumeration on
top as:
enum {
  kStoreBufferEntries = 0,
  kStoreBufferDuplicates = 1,
  kStoreBufferBlockEntries = 2,
  kStoreBufferBlockDuplicates = 3
};

[Ivan Posva, 2013/01/04 02:14:31]

Done. Here and in pages.cc

 }
 
 
 void Scavenger::IterateRoots(Isolate* isolate,
                              ScavengerVisitor* visitor,
                              bool visit_prologue_weak_persistent_handles) {
-  IterateStoreBuffers(isolate, visitor);
+  int64_t start = OS::GetCurrentTimeMicros();
   isolate->VisitObjectPointers(visitor,
                                visit_prologue_weak_persistent_handles,
                                StackFrameIterator::kDontValidateFrames);
+  int64_t middle = OS::GetCurrentTimeMicros();
+  IterateStoreBuffers(isolate, visitor);
+  int64_t end = OS::GetCurrentTimeMicros();
+  heap_->RecordTime(0, middle - start);
+  heap_->RecordTime(1, end - middle);
 }
 
 
 bool Scavenger::IsUnreachable(RawObject** p) {
   RawObject* raw_obj = *p;
   if (!raw_obj->IsHeapObject()) {
     return false;
   }
   if (!raw_obj->IsNewObject()) {
     return false;
@@ skipping 156 matching lines @@
 void Scavenger::VisitObjects(ObjectVisitor* visitor) const {
   uword cur = FirstObjectStart();
   while (cur < top_) {
     RawObject* raw_obj = RawObject::FromAddr(cur);
     visitor->VisitObject(raw_obj);
     cur += raw_obj->Size();
   }
 }
 
 
-void Scavenger::Scavenge(const char* gc_reason) {
+void Scavenger::Scavenge() {
   // TODO(cshapiro): Add a decision procedure for determining when the
   // the API callbacks should be invoked.
-  Scavenge(false, gc_reason);
+  Scavenge(false);
 }
 
 
-void Scavenger::Scavenge(bool invoke_api_callbacks, const char* gc_reason) {
+void Scavenger::Scavenge(bool invoke_api_callbacks) {
   // Scavenging is not reentrant. Make sure that is the case.
   ASSERT(!scavenging_);
   scavenging_ = true;
   had_promotion_failure_ = false;
   Isolate* isolate = Isolate::Current();
   NoHandleScope no_handles(isolate);
 
   if (FLAG_verify_before_gc) {
     OS::PrintErr("Verifying before Scavenge...");
     heap_->Verify();
     OS::PrintErr(" done.\n");
   }
 
-  if (FLAG_verbose_gc) {
-    OS::PrintErr("Start scavenge for %s collection\n", gc_reason);
-  }
   uword prev_first_obj_start = FirstObjectStart();
   uword prev_top_addr = *(TopAddress());
-  Timer timer(FLAG_verbose_gc, "Scavenge");
-  timer.Start();
-
-  intptr_t in_use_before = in_use();
 
   // Setup the visitor and run a scavenge.
   ScavengerVisitor visitor(isolate, this);
   Prologue(isolate, invoke_api_callbacks);
   IterateRoots(isolate, &visitor, !invoke_api_callbacks);
+  int64_t start = OS::GetCurrentTimeMicros();
   ProcessToSpace(&visitor);
+  int64_t middle = OS::GetCurrentTimeMicros();
   IterateWeakReferences(isolate, &visitor);
   ScavengerWeakVisitor weak_visitor(this);
   IterateWeakRoots(isolate, &weak_visitor, invoke_api_callbacks);
   visitor.Finalize();
   ProcessPeerReferents();
+  int64_t end = OS::GetCurrentTimeMicros();
+  heap_->RecordTime(2, middle - start);
+  heap_->RecordTime(3, end - middle);

[siva, 2013/01/04 01:40:12]

Ditto for these 0, 1, 2, 3 values.

   Epilogue(isolate, invoke_api_callbacks);
-  timer.Stop();
-
-  if (FLAG_verbose_gc) {
-    const intptr_t KB2 = KB / 2;
-    double survival = ((in_use() + visitor.bytes_promoted()) /
-                       static_cast<double>(in_use_before)) * 100.0;
-    double promoted = (visitor.bytes_promoted() /
-                       static_cast<double>(in_use() + visitor.bytes_promoted()))
-                      * 100.0;
-    OS::PrintErr("Scavenge[%d]: %"Pd64"us (%"Pd"K -> %"Pd"K, %"Pd"K)\n"
-                 "Surviving %"Pd"K %.1f%%\n"
-                 "Promoted survivors %"Pd"K %.1f%%\n",
-                 count_,
-                 timer.TotalElapsedTime(),
-                 (in_use_before + KB2) / KB,
-                 (in_use() + KB2) / KB,
-                 (capacity() + KB2) / KB,
-                 (in_use() + visitor.bytes_promoted() + KB2) / KB,
-                 survival,
-                 (visitor.bytes_promoted() + KB2) / KB,
-                 promoted);
-  }
 
   if (FLAG_verify_after_gc) {
     OS::PrintErr("Verifying after Scavenge...");
     heap_->Verify();
     OS::PrintErr(" done.\n");
   }
 
   if (HeapTrace::is_enabled()) {
     heap_->trace()->TraceDeathRange(prev_first_obj_start, prev_top_addr);
   }
 
-  count_++;
   // Done scavenging. Reset the marker.
   ASSERT(scavenging_);
   scavenging_ = false;
 }
 
 
 void Scavenger::WriteProtect(bool read_only) {
   space_->Protect(
       read_only ? VirtualMemory::kReadOnly : VirtualMemory::kReadWrite);
 }
@@ skipping 12 matching lines @@
   PeerTable::iterator it = peer_table_.find(raw_obj);
   return (it == peer_table_.end()) ? NULL : it->second;
 }
 
 
 int64_t Scavenger::PeerCount() const {
   return static_cast<int64_t>(peer_table_.size());
 }
 
 }  // namespace dart