Improved GC statistics (cumulative and per collection).

src/heap.cc

 // Copyright 2009 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
@@ skipping 97 matching lines @@
 // ConfigureHeap.
 
 // Will be 4 * reserved_semispace_size_ to ensure that young
 // generation can be aligned to its size.
 int Heap::survived_since_last_expansion_ = 0;
 int Heap::external_allocation_limit_ = 0;
 
 Heap::HeapState Heap::gc_state_ = NOT_IN_GC;
 
 int Heap::mc_count_ = 0;
+int Heap::ms_count_ = 0;
 int Heap::gc_count_ = 0;
 
+GCTracer* Heap::tracer_ = NULL;
+
 int Heap::unflattened_strings_length_ = 0;
 
 int Heap::always_allocate_scope_depth_ = 0;
 int Heap::linear_allocation_scope_depth_ = 0;
 int Heap::contexts_disposed_ = 0;
 
 #ifdef DEBUG
 bool Heap::allocation_allowed_ = true;
 
 int Heap::allocation_timeout_ = 0;
 bool Heap::disallow_allocation_failure_ = false;
 #endif  // DEBUG
 
+int GCTracer::alive_after_last_gc_ = 0;
+double GCTracer::last_gc_end_timestamp_ = 0.0;
+int GCTracer::max_gc_pause_ = 0;
+int GCTracer::max_alive_after_gc_ = 0;
+int GCTracer::min_in_mutator_ = kMaxInt;
 
 int Heap::Capacity() {
   if (!HasBeenSetup()) return 0;
 
   return new_space_.Capacity() +
       old_pointer_space_->Capacity() +
       old_data_space_->Capacity() +
       code_space_->Capacity() +
       map_space_->Capacity() +
       cell_space_->Capacity();
@@ skipping 420 matching lines @@
   ThreadManager::IterateThreads(&visitor);
 }
 
 
 void Heap::PerformGarbageCollection(AllocationSpace space,
                                     GarbageCollector collector,
                                     GCTracer* tracer) {
   VerifySymbolTable();
   if (collector == MARK_COMPACTOR && global_gc_prologue_callback_) {
     ASSERT(!allocation_allowed_);
-    GCTracer::ExternalScope scope(tracer);
+    GCTracer::Scope scope(tracer, GCTracer::Scope::EXTERNAL);
     global_gc_prologue_callback_();
   }
 
   GCType gc_type =
       collector == MARK_COMPACTOR ? kGCTypeMarkSweepCompact : kGCTypeScavenge;
 
   for (int i = 0; i < gc_prologue_callbacks_.length(); ++i) {
     if (gc_type & gc_prologue_callbacks_[i].gc_type) {
       gc_prologue_callbacks_[i].callback(gc_type, kNoGCCallbackFlags);
     }
   }
 
   EnsureFromSpaceIsCommitted();
 
   if (collector == MARK_COMPACTOR) {
     // Perform mark-sweep with optional compaction.
     MarkCompact(tracer);
 
     int old_gen_size = PromotedSpaceSize();
     old_gen_promotion_limit_ =
         old_gen_size + Max(kMinimumPromotionLimit, old_gen_size / 3);
     old_gen_allocation_limit_ =
         old_gen_size + Max(kMinimumAllocationLimit, old_gen_size / 2);
     old_gen_exhausted_ = false;
   } else {
+    tracer_ = tracer;
     Scavenge();
+    tracer_ = NULL;
   }
 
   Counters::objs_since_last_young.Set(0);
 
   if (collector == MARK_COMPACTOR) {
     DisableAssertNoAllocation allow_allocation;
-    GCTracer::ExternalScope scope(tracer);
+    GCTracer::Scope scope(tracer, GCTracer::Scope::EXTERNAL);
     GlobalHandles::PostGarbageCollectionProcessing();
   }
 
   // Update relocatables.
   Relocatable::PostGarbageCollectionProcessing();
 
   if (collector == MARK_COMPACTOR) {
     // Register the amount of external allocated memory.
     amount_of_external_allocated_memory_at_last_global_gc_ =
         amount_of_external_allocated_memory_;
   }
 
   GCCallbackFlags callback_flags = tracer->is_compacting()
       ? kGCCallbackFlagCompacted
       : kNoGCCallbackFlags;
   for (int i = 0; i < gc_epilogue_callbacks_.length(); ++i) {
     if (gc_type & gc_epilogue_callbacks_[i].gc_type) {
       gc_epilogue_callbacks_[i].callback(gc_type, callback_flags);
     }
   }
 
   if (collector == MARK_COMPACTOR && global_gc_epilogue_callback_) {
     ASSERT(!allocation_allowed_);
-    GCTracer::ExternalScope scope(tracer);
+    GCTracer::Scope scope(tracer, GCTracer::Scope::EXTERNAL);
     global_gc_epilogue_callback_();
   }
   VerifySymbolTable();
 }
 
 
 void Heap::MarkCompact(GCTracer* tracer) {
   gc_state_ = MARK_COMPACT;
-  mc_count_++;
+  if (MarkCompactCollector::IsCompacting()) {
+    mc_count_++;
+  } else {
+    ms_count_++;
+  }
   tracer->set_full_gc_count(mc_count_);
   LOG(ResourceEvent("markcompact", "begin"));
 
   MarkCompactCollector::Prepare(tracer);
 
   bool is_compacting = MarkCompactCollector::IsCompacting();
 
   MarkCompactPrologue(is_compacting);
 
   MarkCompactCollector::CollectGarbage();
@@ skipping 522 matching lines @@
         promotion_queue.insert(object, first_word.ToMap());
         object->set_map_word(MapWord::FromForwardingAddress(target));
 
         // Give the space allocated for the result a proper map by
         // treating it as a free list node (not linked into the free
         // list).
         FreeListNode* node = FreeListNode::FromAddress(target->address());
         node->set_size(object_size);
 
         *p = target;
+        tracer()->increment_promoted_objects_size(object_size);
         return;
       }
     } else {
       OldSpace* target_space = Heap::TargetSpace(object);
       ASSERT(target_space == Heap::old_pointer_space_ ||
              target_space == Heap::old_data_space_);
       result = target_space->AllocateRaw(object_size);
       if (!result->IsFailure()) {
         HeapObject* target = HeapObject::cast(result);
         if (target_space == Heap::old_pointer_space_) {
@@ skipping 15 matching lines @@
           // Objects promoted to the data space can be copied immediately
           // and not revisited---we will never sweep that space for
           // pointers and the copied objects do not contain pointers to
           // new space objects.
           *p = MigrateObject(object, target, object_size);
 #ifdef DEBUG
           VerifyNonPointerSpacePointersVisitor v;
           (*p)->Iterate(&v);
 #endif
         }
+        tracer()->increment_promoted_objects_size(object_size);
         return;
       }
     }
   }
   // The object should remain in new space or the old space allocation failed.
   Object* result = new_space_.AllocateRaw(object_size);
   // Failed allocation at this point is utterly unexpected.
   ASSERT(!result->IsFailure());
   *p = MigrateObject(object, HeapObject::cast(result), object_size);
 }
@@ skipping 2526 matching lines @@
   roots_[kStackLimitRootIndex] =
       reinterpret_cast<Object*>(
           (StackGuard::jslimit() & ~kSmiTagMask) | kSmiTag);
   roots_[kRealStackLimitRootIndex] =
       reinterpret_cast<Object*>(
           (StackGuard::real_jslimit() & ~kSmiTagMask) | kSmiTag);
 }
 
 
 void Heap::TearDown() {
+  if (FLAG_print_cumulative_gc_stat) {
+    PrintF("\n\n");
+    PrintF("gc_count=%d ", gc_count_);
+    PrintF("mark_sweep_count=%d ", ms_count_);
+    PrintF("mark_compact_count=%d ", mc_count_);
+    PrintF("max_gc_pause=%d ", GCTracer::get_max_gc_pause());
+    PrintF("min_in_mutator=%d ", GCTracer::get_min_in_mutator());
+    PrintF("max_alive_after_gc=%d ", GCTracer::get_max_alive_after_gc());
+    PrintF("\n\n");
+  }
+
   GlobalHandles::TearDown();
 
   ExternalStringTable::TearDown();
 
   new_space_.TearDown();
 
   if (old_pointer_space_ != NULL) {
     old_pointer_space_->TearDown();
     delete old_pointer_space_;
     old_pointer_space_ = NULL;
@@ skipping 455 matching lines @@
 void Heap::TracePathToGlobal() {
   search_target = NULL;
   search_for_any_global = true;
 
   MarkRootVisitor root_visitor;
   IterateRoots(&root_visitor, VISIT_ONLY_STRONG);
 }
 #endif
 
 
+static int CountTotalHolesSize() {
+  int holes_size = 0;
+  OldSpaces spaces;
+  for (OldSpace* space = spaces.next();
+       space != NULL;
+       space = spaces.next()) {
+    holes_size += space->Waste() + space->AvailableFree();
+  }
+  return holes_size;
+}
+
+
 GCTracer::GCTracer()
     : start_time_(0.0),
-      start_size_(0.0),
-      external_time_(0.0),
+      start_size_(0),
       gc_count_(0),
       full_gc_count_(0),
       is_compacting_(false),
-      marked_count_(0) {
+      marked_count_(0),
+      allocated_since_last_gc_(0),
+      spent_in_mutator_(0),
+      promoted_objects_size_(0) {
   // These two fields reflect the state of the previous full collection.
   // Set them before they are changed by the collector.
   previous_has_compacted_ = MarkCompactCollector::HasCompacted();
   previous_marked_count_ = MarkCompactCollector::previous_marked_count();
-  if (!FLAG_trace_gc) return;
+  if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
   start_time_ = OS::TimeCurrentMillis();
-  start_size_ = SizeOfHeapObjects();
+  start_size_ = Heap::SizeOfObjects();
+
+  for (int i = 0; i < Scope::kNumberOfScopes; i++) {
+    scopes_[i] = 0;
+  }
+
+  in_free_list_or_wasted_before_gc_ = CountTotalHolesSize();
+
+  allocated_since_last_gc_ = Heap::SizeOfObjects() - alive_after_last_gc_;
+
+  if (last_gc_end_timestamp_ > 0) {
+    spent_in_mutator_ = Max(start_time_ - last_gc_end_timestamp_, 0.0);
+  }
 }
 
 
 GCTracer::~GCTracer() {
-  if (!FLAG_trace_gc) return;
   // Printf ONE line iff flag is set.
-  int time = static_cast<int>(OS::TimeCurrentMillis() - start_time_);
-  int external_time = static_cast<int>(external_time_);
-  PrintF("%s %.1f -> %.1f MB, ",
-         CollectorString(), start_size_, SizeOfHeapObjects());
-  if (external_time > 0) PrintF("%d / ", external_time);
-  PrintF("%d ms.\n", time);
+  if (!FLAG_trace_gc && !FLAG_print_cumulative_gc_stat) return;
+
+  bool first_gc = (last_gc_end_timestamp_ == 0);
+
+  alive_after_last_gc_ = Heap::SizeOfObjects();
+  last_gc_end_timestamp_ = OS::TimeCurrentMillis();
+
+  int time = static_cast<int>(last_gc_end_timestamp_ - start_time_);
+
+  // Update cumulative GC statistics if required.
+  if (FLAG_print_cumulative_gc_stat) {
+    max_gc_pause_ = Max(max_gc_pause_, time);
+    max_alive_after_gc_ = Max(max_alive_after_gc_, alive_after_last_gc_);
+    if (!first_gc) {
+      min_in_mutator_ = Min(min_in_mutator_,
+                            static_cast<int>(spent_in_mutator_));
+    }
+  }
+
+  if (!FLAG_trace_gc_nvp) {
+    int external_time = static_cast<int>(scopes_[Scope::EXTERNAL]);
+
+    PrintF("%s %.1f -> %.1f MB, ",
+           CollectorString(),
+           static_cast<double>(start_size_) / MB,
+           SizeOfHeapObjects());
+
+    if (external_time > 0) PrintF("%d / ", external_time);
+    PrintF("%d ms.\n", time);
+  } else {
+    PrintF("pause=%d ", time);
+    PrintF("mutator=%d ",
+           static_cast<int>(spent_in_mutator_));
+
+    PrintF("gc=");
+    switch (collector_) {
+      case SCAVENGER:
+        PrintF("s");
+        break;
+      case MARK_COMPACTOR:
+        PrintF(MarkCompactCollector::HasCompacted() ? "mc" : "ms");
+        break;
+      default:
+        UNREACHABLE();
+    }
+    PrintF(" ");
+
+    PrintF("external=%d ", static_cast<int>(scopes_[Scope::EXTERNAL]));
+    PrintF("mark=%d ", static_cast<int>(scopes_[Scope::MC_MARK]));
+    PrintF("sweep=%d ", static_cast<int>(scopes_[Scope::MC_SWEEP]));
+    PrintF("compact=%d ", static_cast<int>(scopes_[Scope::MC_COMPACT]));
+
+    PrintF("total_size_before=%d ", start_size_);
+    PrintF("total_size_after=%d ", Heap::SizeOfObjects());
+    PrintF("holes_size_before=%d ", in_free_list_or_wasted_before_gc_);
+    PrintF("holes_size_after=%d ", CountTotalHolesSize());
+
+    PrintF("allocated=%d ", allocated_since_last_gc_);
+    PrintF("promoted=%d ", promoted_objects_size_);
+
+    PrintF("\n");
+  }
 
 #if defined(ENABLE_LOGGING_AND_PROFILING)
   Heap::PrintShortHeapStatistics();
 #endif
 }
 
 
 const char* GCTracer::CollectorString() {
   switch (collector_) {
     case SCAVENGER:
@@ skipping 118 matching lines @@
 void ExternalStringTable::TearDown() {
   new_space_strings_.Free();
   old_space_strings_.Free();
 }
 
 
 List<Object*> ExternalStringTable::new_space_strings_;
 List<Object*> ExternalStringTable::old_space_strings_;
 
 } }  // namespace v8::internal