Trace idle notification.

src/heap/heap.cc

 // Copyright 2012 the V8 project authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "src/v8.h"
 
 #include "src/accessors.h"
 #include "src/api.h"
 #include "src/base/once.h"
 #include "src/base/utils/random-number-generator.h"
@@ skipping 4269 matching lines @@
 
 bool Heap::WorthActivatingIncrementalMarking() {
   return incremental_marking()->IsStopped() &&
          incremental_marking()->WorthActivating() && NextGCIsLikelyToBeFull();
 }
 
 
 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(
       isolate_->counters()->gc_idle_notification());
 
   GCIdleTimeHandler::HeapState heap_state;
   heap_state.contexts_disposed = contexts_disposed_;
   heap_state.size_of_objects = static_cast<size_t>(SizeOfObjects());
   heap_state.incremental_marking_stopped = incremental_marking()->IsStopped();
   // TODO(ulan): Start incremental marking only for large heaps.
@@ skipping 29 matching lines @@
     case DO_SCAVENGE:
       CollectGarbage(NEW_SPACE, "idle notification: scavenge");
       break;
     case DO_FINALIZE_SWEEPING:
       mark_compact_collector()->EnsureSweepingCompleted();
       break;
     case DO_NOTHING:
       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;
 }
 
 
 #ifdef DEBUG
 
 void Heap::Print() {
   if (!HasBeenSetUp()) return;
   isolate()->PrintStack(stdout);
@@ skipping 1760 matching lines @@
       static_cast<int>(object_sizes_last_time_[index]));
   CODE_AGE_LIST_COMPLETE(ADJUST_LAST_TIME_OBJECT_COUNT)
 #undef ADJUST_LAST_TIME_OBJECT_COUNT
 
   MemCopy(object_counts_last_time_, object_counts_, sizeof(object_counts_));
   MemCopy(object_sizes_last_time_, object_sizes_, sizeof(object_sizes_));
   ClearObjectStats();
 }
 }
 }  // namespace v8::internal