Add information about time spent in external callback to...

src/heap.cc

Index: src/heap.cc
===================================================================
--- src/heap.cc	(revision 3959)
+++ src/heap.cc	(working copy)
@@ -558,6 +558,7 @@
   VerifySymbolTable();
   if (collector == MARK_COMPACTOR && global_gc_prologue_callback_) {
     ASSERT(!allocation_allowed_);
+    GCTracer::ExternalScope scope(tracer);
     global_gc_prologue_callback_();
   }
   EnsureFromSpaceIsCommitted();
@@ -591,6 +592,7 @@
 
   if (collector == MARK_COMPACTOR && global_gc_epilogue_callback_) {
     ASSERT(!allocation_allowed_);
+    GCTracer::ExternalScope scope(tracer);
     global_gc_epilogue_callback_();
   }
   VerifySymbolTable();
@@ -4067,6 +4069,7 @@
 GCTracer::GCTracer()
     : start_time_(0.0),
       start_size_(0.0),
+      external_time_(0.0),
       gc_count_(0),
       full_gc_count_(0),
       is_compacting_(false),
@@ -4084,10 +4087,19 @@
 GCTracer::~GCTracer() {
   if (!FLAG_trace_gc) return;
   // Printf ONE line iff flag is set.
-  PrintF("%s %.1f -> %.1f MB, %d ms.\n",
-         CollectorString(),
-         start_size_, SizeOfHeapObjects(),
-         static_cast<int>(OS::TimeCurrentMillis() - start_time_));
+  int time = static_cast<int>(OS::TimeCurrentMillis() - start_time_);
+  int external_time = static_cast<int>(external_time_);
+  if (external_time > 0) {
+    PrintF("%s %.1f -> %.1f MB, %d / %d ms.\n",

[bak, 2010/02/26 08:20:30]

Refactor printing into:
PrintF(...);
if (external_time > 0) PrintF(...);
PrintF("\n");

+           CollectorString(),
+           start_size_, SizeOfHeapObjects(),
+           external_time, time);
+  } else {
+    PrintF("%s %.1f -> %.1f MB, %d ms.\n",
+           CollectorString(),
+           start_size_, SizeOfHeapObjects(),
+           time);
+  }
 
 #if defined(ENABLE_LOGGING_AND_PROFILING)
   Heap::PrintShortHeapStatistics();