Revision: 3960
Author: kasp...@chromium.org
Date: Fri Feb 26 00:27:20 2010
Log: Add information about time spent in external callback to
traces produces with --trace-gc.
Review URL: http://codereview.chromium.org/661170
http://code.google.com/p/v8/source/detail?r=3960

Modified:
  /branches/bleeding_edge/src/heap.cc
  /branches/bleeding_edge/src/heap.h

=======================================
--- /branches/bleeding_edge/src/heap.cc Thu Feb 25 07:43:27 2010
+++ /branches/bleeding_edge/src/heap.cc Fri Feb 26 00:27:20 2010
@@ -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,12 @@
  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();
=======================================
--- /branches/bleeding_edge/src/heap.h  Thu Feb 25 07:43:27 2010
+++ /branches/bleeding_edge/src/heap.h  Fri Feb 26 00:27:20 2010
@@ -1520,8 +1520,23 @@

  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 @@
    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_;