From 57f47e704f90d87edad9baba00236b09795ab43c Mon Sep 17 00:00:00 2001
From: "kasperl@chromium.org"
 <kasperl@chromium.org@ce2b1a6d-e550-0410-aec6-3dcde31c8c00>
Date: Fri, 26 Feb 2010 08:27:20 +0000
Subject: [PATCH] Add information about time spent in external callback to
 traces produces with --trace-gc. Review URL:
 http://codereview.chromium.org/661170

git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@3960 ce2b1a6d-e550-0410-aec6-3dcde31c8c00
---
 src/heap.cc | 13 +++++++++----
 src/heap.h  | 20 +++++++++++++++++++-
 2 files changed, 28 insertions(+), 5 deletions(-)

diff --git a/src/heap.cc b/src/heap.cc
index cfb786ac7a..20db826eda 100644
--- a/src/heap.cc
+++ b/src/heap.cc
@@ -558,6 +558,7 @@ void Heap::PerformGarbageCollection(AllocationSpace space,
   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 @@ void Heap::PerformGarbageCollection(AllocationSpace space,
 
   if (collector == MARK_COMPACTOR && global_gc_epilogue_callback_) {
     ASSERT(!allocation_allowed_);
+    GCTracer::ExternalScope scope(tracer);
     global_gc_epilogue_callback_();
   }
   VerifySymbolTable();
@@ -4067,6 +4069,7 @@ void Heap::TracePathToGlobal() {
 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,12 @@ GCTracer::GCTracer()
 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_);
+  PrintF("%s %.1f -> %.1f MB, ",
+         CollectorString(), start_size_, SizeOfHeapObjects());
+  if (external_time > 0) PrintF("%d / ", external_time);
+  PrintF("%d ms.\n", time);
 
 #if defined(ENABLE_LOGGING_AND_PROFILING)
   Heap::PrintShortHeapStatistics();
diff --git a/src/heap.h b/src/heap.h
index 9948b96d7b..5b27926504 100644
--- a/src/heap.h
+++ b/src/heap.h
@@ -1520,8 +1520,23 @@ class DisableAssertNoAllocation {
 
 class GCTracer BASE_EMBEDDED {
  public:
-  GCTracer();
+  // Time spent while in the external scope counts towards the
+  // external time in the tracer and will be reported separately.
+  class ExternalScope BASE_EMBEDDED {
+   public:
+    explicit ExternalScope(GCTracer* tracer) : tracer_(tracer) {
+      start_time_ = OS::TimeCurrentMillis();
+    }
+    ~ExternalScope() {
+      tracer_->external_time_ += OS::TimeCurrentMillis() - start_time_;
+    }
 
+   private:
+    GCTracer* tracer_;
+    double start_time_;
+  };
+
+  GCTracer();
   ~GCTracer();
 
   // Sets the collector.
@@ -1555,6 +1570,9 @@ class GCTracer BASE_EMBEDDED {
   double start_size_;  // Size of objects in heap set in constructor.
   GarbageCollector collector_;  // Type of collector.
 
+  // Keep track of the amount of time spent in external callbacks.
+  double external_time_;
+
   // A count (including this one, eg, the first collection is 1) of the
   // number of garbage collections.
   int gc_count_;