From ae2b08f42085dda707ce126cd30bbc3ff07afcd2 Mon Sep 17 00:00:00 2001
From: "ulan@chromium.org" <ulan@chromium.org>
Date: Mon, 1 Sep 2014 12:06:16 +0000
Subject: [PATCH] Trace idle notification.

BUG=
R=yangguo@chromium.org

Review URL: https://codereview.chromium.org/521873006

git-svn-id: https://v8.googlecode.com/svn/branches/bleeding_edge@23559 ce2b1a6d-e550-0410-aec6-3dcde31c8c00
---
 src/flag-definitions.h           |  2 ++
 src/heap/gc-idle-time-handler.cc | 21 +++++++++++++++++++++
 src/heap/gc-idle-time-handler.h  |  2 ++
 src/heap/heap.cc                 | 11 +++++++++++
 4 files changed, 36 insertions(+)

diff --git a/src/flag-definitions.h b/src/flag-definitions.h
index 7796700..87f83d9 100644
--- a/src/flag-definitions.h
+++ b/src/flag-definitions.h
@@ -495,6 +495,8 @@ DEFINE_BOOL(trace_gc_nvp, false,
             "after each garbage collection")
 DEFINE_BOOL(trace_gc_ignore_scavenger, false,
             "do not print trace line after scavenger collection")
+DEFINE_BOOL(trace_idle_notification, false,
+            "print one trace line following each idle notification")
 DEFINE_BOOL(print_cumulative_gc_stat, false,
             "print cumulative GC statistics in name=value format on exit")
 DEFINE_BOOL(print_max_heap_committed, false,
diff --git a/src/heap/gc-idle-time-handler.cc b/src/heap/gc-idle-time-handler.cc
index 258d4fe..8def900 100644
--- a/src/heap/gc-idle-time-handler.cc
+++ b/src/heap/gc-idle-time-handler.cc
@@ -16,6 +16,27 @@ const int GCIdleTimeHandler::kMaxMarkCompactsInIdleRound = 7;
 const int GCIdleTimeHandler::kIdleScavengeThreshold = 5;
 
 
+void GCIdleTimeAction::Print() {
+  switch (type) {
+    case DO_NOTHING:
+      PrintF("no action");
+      break;
+    case DO_INCREMENTAL_MARKING:
+      PrintF("incremental marking with step %" V8_PTR_PREFIX "d", parameter);
+      break;
+    case DO_SCAVENGE:
+      PrintF("scavenge");
+      break;
+    case DO_FULL_GC:
+      PrintF("full GC");
+      break;
+    case DO_FINALIZE_SWEEPING:
+      PrintF("finalize sweeping");
+      break;
+  }
+}
+
+
 size_t GCIdleTimeHandler::EstimateMarkingStepSize(
     size_t idle_time_in_ms, size_t marking_speed_in_bytes_per_ms) {
   DCHECK(idle_time_in_ms > 0);
diff --git a/src/heap/gc-idle-time-handler.h b/src/heap/gc-idle-time-handler.h
index 7ffb7bd..b0bdce6 100644
--- a/src/heap/gc-idle-time-handler.h
+++ b/src/heap/gc-idle-time-handler.h
@@ -56,6 +56,8 @@ class GCIdleTimeAction {
     return result;
   }
 
+  void Print();
+
   GCIdleTimeActionType type;
   intptr_t parameter;
 };
diff --git a/src/heap/heap.cc b/src/heap/heap.cc
index e31a281..6781711 100644
--- a/src/heap/heap.cc
+++ b/src/heap/heap.cc
@@ -4287,6 +4287,10 @@ bool Heap::WorthActivatingIncrementalMarking() {
 bool Heap::IdleNotification(int idle_time_in_ms) {
   // If incremental marking is off, we do not perform idle notification.
   if (!FLAG_incremental_marking) return true;
+  base::ElapsedTimer timer;
+  if (FLAG_trace_idle_notification) {
+    timer.Start();
+  }
   isolate()->counters()->gc_idle_time_allotted_in_ms()->AddSample(
       idle_time_in_ms);
   HistogramTimerScope idle_notification_scope(
@@ -4336,6 +4340,13 @@ bool Heap::IdleNotification(int idle_time_in_ms) {
       result = true;
       break;
   }
+  if (FLAG_trace_idle_notification) {
+    int actual_time_ms = static_cast<int>(timer.Elapsed().InMilliseconds());
+    PrintF("Idle notification: requested idle time %d ms, actual time %d ms [",
+           idle_time_in_ms, actual_time_ms);
+    action.Print();
+    PrintF("]\n");
+  }
 
   return result;
 }
-- 
2.7.4