Revision: 13551
Author:   [email protected]
Date:     Wed Jan 30 02:51:13 2013
Log: Precisely measure duration of mark and sweep phases. Changed print_cumulative_gc_stat flag to only print GC statistics at end of program.

BUG=

Review URL: https://codereview.chromium.org/11595006
http://code.google.com/p/v8/source/detail?r=13551

Modified:
 /branches/bleeding_edge/src/heap.cc
 /branches/bleeding_edge/src/heap.h
 /branches/bleeding_edge/src/incremental-marking.cc
 /branches/bleeding_edge/src/mark-compact.cc

=======================================
--- /branches/bleeding_edge/src/heap.cc Thu Jan 24 03:55:05 2013
+++ /branches/bleeding_edge/src/heap.cc Wed Jan 30 02:51:13 2013
@@ -145,6 +145,8 @@
       min_in_mutator_(kMaxInt),
       alive_after_last_gc_(0),
       last_gc_end_timestamp_(0.0),
+      marking_time_(0.0),
+      sweeping_time_(0.0),
       store_buffer_(this),
       marking_(this),
       incremental_marking_(this),
@@ -6338,7 +6340,7 @@
 #endif

   if (FLAG_print_cumulative_gc_stat) {
-    PrintF("\n\n");
+    PrintF("\n");
     PrintF("gc_count=%d ", gc_count_);
     PrintF("mark_sweep_count=%d ", ms_count_);
     PrintF("max_gc_pause=%d ", get_max_gc_pause());
@@ -6346,6 +6348,8 @@
     PrintF("min_in_mutator=%d ", get_min_in_mutator());
     PrintF("max_alive_after_gc=%" V8_PTR_PREFIX "d ",
            get_max_alive_after_gc());
+    PrintF("total_marking_time=%f ", marking_time());
+    PrintF("total_sweeping_time=%f ", sweeping_time());
     PrintF("\n\n");
   }

@@ -7036,6 +7040,9 @@

   if (collector_ == SCAVENGER && FLAG_trace_gc_ignore_scavenger) return;

+  heap_->AddMarkingTime(scopes_[Scope::MC_MARK]);
+
+  if (FLAG_print_cumulative_gc_stat && !FLAG_trace_gc) return;
   PrintPID("%8.0f ms: ", heap_->isolate()->time_millis_since_init());

   if (!FLAG_trace_gc_nvp) {
=======================================
--- /branches/bleeding_edge/src/heap.h  Wed Jan 23 23:54:40 2013
+++ /branches/bleeding_edge/src/heap.h  Wed Jan 30 02:51:13 2013
@@ -1595,6 +1595,24 @@

   // Returns minimal interval between two subsequent collections.
   int get_min_in_mutator() { return min_in_mutator_; }
+
+  // TODO(hpayer): remove, should be handled by GCTracer
+  void AddMarkingTime(double marking_time) {
+    marking_time_ += marking_time;
+  }
+
+  double marking_time() const {
+    return marking_time_;
+  }
+
+  // TODO(hpayer): remove, should be handled by GCTracer
+  void AddSweepingTime(double sweeping_time) {
+    sweeping_time_ += sweeping_time;
+  }
+
+  double sweeping_time() const {
+    return sweeping_time_;
+  }

   MarkCompactCollector* mark_compact_collector() {
     return &mark_compact_collector_;
@@ -2035,7 +2053,6 @@

   GCTracer* tracer_;

-
   // Allocates a small number to string cache.
   MUST_USE_RESULT MaybeObject* AllocateInitialNumberStringCache();
   // Creates and installs the full-sized number string cache.
@@ -2173,6 +2190,12 @@

   double last_gc_end_timestamp_;

+  // Cumulative GC time spent in marking
+  double marking_time_;
+
+  // Cumulative GC time spent in sweeping
+  double sweeping_time_;
+
   MarkCompactCollector mark_compact_collector_;

   StoreBuffer store_buffer_;
=======================================
--- /branches/bleeding_edge/src/incremental-marking.cc Thu Dec 6 07:51:42 2012 +++ /branches/bleeding_edge/src/incremental-marking.cc Wed Jan 30 02:51:13 2013
@@ -754,18 +754,24 @@
 void IncrementalMarking::Hurry() {
   if (state() == MARKING) {
     double start = 0.0;
-    if (FLAG_trace_incremental_marking) {
-      PrintF("[IncrementalMarking] Hurry\n");
+    if (FLAG_trace_incremental_marking || FLAG_print_cumulative_gc_stat) {
       start = OS::TimeCurrentMillis();
+      if (FLAG_trace_incremental_marking) {
+        PrintF("[IncrementalMarking] Hurry\n");
+      }
     }
     // TODO(gc) hurry can mark objects it encounters black as mutator
     // was stopped.
     ProcessMarkingDeque();
     state_ = COMPLETE;
-    if (FLAG_trace_incremental_marking) {
+    if (FLAG_trace_incremental_marking || FLAG_print_cumulative_gc_stat) {
       double end = OS::TimeCurrentMillis();
-      PrintF("[IncrementalMarking] Complete (hurry), spent %d ms.\n",
-             static_cast<int>(end - start));
+      double delta = end - start;
+      heap_->AddMarkingTime(delta);
+      if (FLAG_trace_incremental_marking) {
+        PrintF("[IncrementalMarking] Complete (hurry), spent %d ms.\n",
+               static_cast<int>(delta));
+      }
     }
   }

@@ -889,7 +895,8 @@

   double start = 0;

-  if (FLAG_trace_incremental_marking || FLAG_trace_gc) {
+  if (FLAG_trace_incremental_marking || FLAG_trace_gc ||
+      FLAG_print_cumulative_gc_stat) {
     start = OS::TimeCurrentMillis();
   }

@@ -969,12 +976,14 @@
     }
   }

-  if (FLAG_trace_incremental_marking || FLAG_trace_gc) {
+  if (FLAG_trace_incremental_marking || FLAG_trace_gc ||
+      FLAG_print_cumulative_gc_stat) {
     double end = OS::TimeCurrentMillis();
     double delta = (end - start);
     longest_step_ = Max(longest_step_, delta);
     steps_took_ += delta;
     steps_took_since_last_gc_ += delta;
+    heap_->AddMarkingTime(delta);
   }
 }

=======================================
--- /branches/bleeding_edge/src/mark-compact.cc Mon Jan 28 02:25:38 2013
+++ /branches/bleeding_edge/src/mark-compact.cc Wed Jan 30 02:51:13 2013
@@ -2831,6 +2831,11 @@
   ASSERT_EQ(skip_list_mode == REBUILD_SKIP_LIST,
             space->identity() == CODE_SPACE);
ASSERT((p->skip_list() == NULL) || (skip_list_mode == REBUILD_SKIP_LIST));
+
+  double start_time = 0.0;
+  if (FLAG_print_cumulative_gc_stat) {
+    start_time = OS::TimeCurrentMillis();
+  }

   MarkBit::CellType* cells = p->markbits()->cells();
   p->MarkSweptPrecisely();
@@ -2897,6 +2902,9 @@
     space->Free(free_start, static_cast<int>(p->area_end() - free_start));
   }
   p->ResetLiveBytes();
+  if (FLAG_print_cumulative_gc_stat) {
+    space->heap()->AddSweepingTime(OS::TimeCurrentMillis() - start_time);
+  }
 }


@@ -3491,6 +3499,11 @@
 // spaces will not contain the free space map.
intptr_t MarkCompactCollector::SweepConservatively(PagedSpace* space, Page* p) {
   ASSERT(!p->IsEvacuationCandidate() && !p->WasSwept());
+  double start_time = 0.0;
+  if (FLAG_print_cumulative_gc_stat) {
+    start_time = OS::TimeCurrentMillis();
+  }
+
   MarkBit::CellType* cells = p->markbits()->cells();
   p->MarkSweptConservatively();

@@ -3577,6 +3590,10 @@
   }

   p->ResetLiveBytes();
+
+  if (FLAG_print_cumulative_gc_stat) {
+    space->heap()->AddSweepingTime(OS::TimeCurrentMillis() - start_time);
+  }
   return freed_bytes;
 }

--
--
v8-dev mailing list
[email protected]
http://groups.google.com/group/v8-dev
--- You received this message because you are subscribed to the Google Groups "v8-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to [email protected].
For more options, visit https://groups.google.com/groups/opt_out.


Reply via email to