src/share/vm/gc/g1/concurrentMarkThread.cpp

@@ -90,19 +90,21 @@
     jlong sleep_time_ms = mmu_tracker->when_ms(now, prediction_ms);
     os::sleep(this, sleep_time_ms, false);
   }
 }
 
-class GCConcPhaseTimer : StackObj {
+class G1ConcPhaseTimer : public GCTraceConcTimeImpl<LogLevel::Info, LOG_TAGS(gc, marking)> {
   G1ConcurrentMark* _cm;
 
  public:
-  GCConcPhaseTimer(G1ConcurrentMark* cm, const char* title) : _cm(cm) {
+  G1ConcPhaseTimer(G1ConcurrentMark* cm, const char* title) :
+     GCTraceConcTimeImpl<LogLevel::Info,  LogTag::_gc, LogTag::_marking>(title),
+     _cm(cm) {
     _cm->register_concurrent_phase_start(title);
   }
 
-  ~GCConcPhaseTimer() {
+  ~G1ConcPhaseTimer() {
     _cm->register_concurrent_phase_end();
   }
 };
 
 void ConcurrentMarkThread::run_service() {

@@ -118,17 +120,19 @@
       _cm->root_regions()->cancel_scan();
       break;
     }
 
     assert(GCId::current() != GCId::undefined(), "GC id should have been set up by the initial mark GC.");
+
+    GCTraceConcTime(Info, gc) tt("Concurrent Cycle");
     {
       ResourceMark rm;
       HandleMark   hm;
       double cycle_start = os::elapsedVTime();
 
       {
-        GCConcPhaseTimer(_cm, "Concurrent Clearing of Claimed Marks");
+        G1ConcPhaseTimer t(_cm, "Concurrent Clear Claimed Marks");
         ClassLoaderDataGraph::clear_claimed_marks();
       }
 
       // We have to ensure that we finish scanning the root regions
       // before the next GC takes place. To ensure this we have to

@@ -137,45 +141,45 @@
       // subsequent GC could block us from joining the STS and proceed
       // without the root regions have been scanned which would be a
       // correctness issue.
 
       {
-        GCConcPhaseTimer(_cm, "Concurrent Root Region Scanning");
-        _cm->scanRootRegions();
+        G1ConcPhaseTimer t(_cm, "Concurrent Scan Root Regions");
+        _cm->scan_root_regions();
       }
 
       // It would be nice to use the GCTraceConcTime class here but
       // the "end" logging is inside the loop and not at the end of
       // a scope. Mimicking the same log output as GCTraceConcTime instead.
       jlong mark_start = os::elapsed_counter();
-      log_info(gc)("Concurrent Mark (%.3fs)", TimeHelper::counter_to_seconds(mark_start));
+      log_info(gc, marking)("Concurrent Mark (%.3fs)", TimeHelper::counter_to_seconds(mark_start));
 
       int iter = 0;
       do {
         iter++;
         if (!cm()->has_aborted()) {
-          GCConcPhaseTimer(_cm, "Concurrent Mark");
-          _cm->markFromRoots();
+          G1ConcPhaseTimer t(_cm, "Concurrent Mark From Roots");
+          _cm->mark_from_roots();
         }
 
         double mark_end_time = os::elapsedVTime();
         jlong mark_end = os::elapsed_counter();
         _vtime_mark_accum += (mark_end_time - cycle_start);
         if (!cm()->has_aborted()) {
           delay_to_keep_mmu(g1_policy, true /* remark */);
-          log_info(gc)("Concurrent Mark (%.3fs, %.3fs) %.3fms",
+          log_info(gc, marking)("Concurrent Mark (%.3fs, %.3fs) %.3fms",
                        TimeHelper::counter_to_seconds(mark_start),
                        TimeHelper::counter_to_seconds(mark_end),
                        TimeHelper::counter_to_millis(mark_end - mark_start));
 
           CMCheckpointRootsFinalClosure final_cl(_cm);
           VM_CGC_Operation op(&final_cl, "Pause Remark", true /* needs_pll */);
           VMThread::execute(&op);
         }
         if (cm()->restart_for_overflow()) {
-          log_debug(gc)("Restarting conc marking because of MS overflow in remark (restart #%d).", iter);
-          log_info(gc)("Concurrent Mark restart for overflow");
+          log_debug(gc, marking)("Restarting Concurrent Marking because of Mark Stack Overflow in Remark (Iteration #%d).", iter);
+          log_info(gc, marking)("Concurrent Mark Restart due to overflow");
         }
       } while (cm()->restart_for_overflow());
 
       double end_time = os::elapsedVTime();
       // Update the total virtual time before doing this, since it will try

@@ -205,15 +209,13 @@
         // takes place, then we would carry on freeing regions in
         // case they are needed by the pause. If a Full GC takes
         // place, it would wait for us to process the regions
         // reclaimed by cleanup.
 
-        GCTraceConcTime(Info, gc) tt("Concurrent Cleanup");
-        GCConcPhaseTimer(_cm, "Concurrent Cleanup");
-
+        G1ConcPhaseTimer t(_cm, "Concurrent Complete Cleanup");
         // Now do the concurrent cleanup operation.
-        _cm->completeCleanup();
+        _cm->complete_cleanup();
 
         // Notify anyone who's waiting that there are no more free
         // regions coming. We have to do this before we join the STS
         // (in fact, we should not attempt to join the STS in the
         // interval between finishing the cleanup pause and clearing

@@ -254,20 +256,20 @@
       {
         SuspendibleThreadSetJoiner sts_join;
         if (!cm()->has_aborted()) {
           g1_policy->record_concurrent_mark_cleanup_completed();
         } else {
-          log_info(gc)("Concurrent Mark abort");
+          log_info(gc, marking)("Concurrent Mark Abort");
         }
       }
 
       // We now want to allow clearing of the marking bitmap to be
       // suspended by a collection pause.
       // We may have aborted just before the remark. Do not bother clearing the
       // bitmap then, as it has been done during mark abort.
       if (!cm()->has_aborted()) {
-        GCConcPhaseTimer(_cm, "Concurrent Bitmap Clearing");
+        G1ConcPhaseTimer t(_cm, "Concurrent Cleanup for Next Mark");
         _cm->cleanup_for_next_mark();
       } else {
         assert(!G1VerifyBitmaps || _cm->nextMarkBitmapIsClear(), "Next mark bitmap must be clear");
       }
     }