commit 3f9667022788ba1effcd1e47fc9e3decc4db569d
author Mathieu Chartier <mathieuc@google.com> Wed Sep 04 16:50:05 2013 -0700
committer Mathieu Chartier <mathieuc@google.com> Thu Sep 05 10:22:26 2013 -0700
tree 587c4e54f352725cb77701e097e8eed2f516f1d4
parent 280ebdf280c435a42b7586466c8317c7cf82beb8

Add more systrace logging to GC.

There was some confusing systrace messages which made it seem like
pauses were longer than they actually were due to premption occuring
during thread_list->ResumeAll().

Bug: 10612142

Change-Id: I6eeedd1cf85ff38c5b116f15059469db52cbb73b

runtime/gc/collector/garbage_collector.cc

diff --git a/runtime/gc/collector/garbage_collector.cc b/runtime/gc/collector/garbage_collector.cc
index b7641a4..edfea94 100644
--- a/runtime/gc/collector/garbage_collector.cc
+++ b/runtime/gc/collector/garbage_collector.cc
@@ -88,12 +88,16 @@
     bool done = false;
     while (!done) {
       uint64_t pause_start = NanoTime();
-      ATRACE_BEGIN("Application threads suspended");
+      ATRACE_BEGIN("Suspending mutator threads");
       thread_list->SuspendAll();
+      ATRACE_END();
+      ATRACE_BEGIN("All mutator threads suspended");
       done = HandleDirtyObjectsPhase();
-      thread_list->ResumeAll();
       ATRACE_END();
       uint64_t pause_end = NanoTime();
+      ATRACE_BEGIN("Resuming mutator threads");
+      thread_list->ResumeAll();
+      ATRACE_END();
       pause_times_.push_back(pause_end - pause_start);
     }
     {

runtime/gc/collector/mark_sweep.cc

diff --git a/runtime/gc/collector/mark_sweep.cc b/runtime/gc/collector/mark_sweep.cc
index 2f68f8e..953fbf9 100644
--- a/runtime/gc/collector/mark_sweep.cc
+++ b/runtime/gc/collector/mark_sweep.cc
@@ -1069,11 +1069,13 @@
   explicit CheckpointMarkThreadRoots(MarkSweep* mark_sweep) : mark_sweep_(mark_sweep) {}
 
   virtual void Run(Thread* thread) NO_THREAD_SAFETY_ANALYSIS {
+    ATRACE_BEGIN("Marking thread roots");
     // Note: self is not necessarily equal to thread since thread may be suspended.
     Thread* self = Thread::Current();
     CHECK(thread == self || thread->IsSuspended() || thread->GetState() == kWaitingPerformingGc)
         << thread->GetState() << " thread " << thread << " self " << self;
     thread->VisitRoots(MarkSweep::MarkRootParallelCallback, mark_sweep_);
+    ATRACE_END();
     mark_sweep_->GetBarrier().Pass(self);
   }