< prev index next >

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

Print this page

        

@@ -29,12 +29,10 @@
 #include "gc/g1/concurrentMark.inline.hpp"
 #include "gc/g1/concurrentMarkThread.inline.hpp"
 #include "gc/g1/g1CollectedHeap.inline.hpp"
 #include "gc/g1/g1CollectorPolicy.hpp"
 #include "gc/g1/g1CollectorState.hpp"
-#include "gc/g1/g1ErgoVerbose.hpp"
-#include "gc/g1/g1Log.hpp"
 #include "gc/g1/g1OopClosures.inline.hpp"
 #include "gc/g1/g1RemSet.hpp"
 #include "gc/g1/g1StringDedup.hpp"
 #include "gc/g1/heapRegion.inline.hpp"
 #include "gc/g1/heapRegionManager.inline.hpp"

@@ -48,10 +46,11 @@
 #include "gc/shared/genOopClosures.inline.hpp"
 #include "gc/shared/referencePolicy.hpp"
 #include "gc/shared/strongRootsScope.hpp"
 #include "gc/shared/taskqueue.inline.hpp"
 #include "gc/shared/vmGCOperations.hpp"
+#include "logging/log.hpp"
 #include "memory/allocation.hpp"
 #include "memory/resourceArea.hpp"
 #include "oops/oop.inline.hpp"
 #include "runtime/atomic.inline.hpp"
 #include "runtime/handles.inline.hpp"

@@ -277,13 +276,11 @@
   assert(isEmpty(), "stack should been emptied while handling overflow");
   assert(_capacity <= (jint) MarkStackSizeMax, "stack bigger than permitted");
   // Clear expansion flag
   _should_expand = false;
   if (_capacity == (jint) MarkStackSizeMax) {
-    if (PrintGCDetails && Verbose) {
-      gclog_or_tty->print_cr(" (benign) Can't expand marking stack capacity, at max size limit");
-    }
+    log_trace(gc)("(benign) Can't expand marking stack capacity, at max size limit");
     return;
   }
   // Double capacity if possible
   jint new_capacity = MIN2(_capacity*2, (jint) MarkStackSizeMax);
   // Do not give up existing stack until we have managed to

@@ -299,17 +296,14 @@
     }
     _base = (oop*)(_virtual_space.low());
     _index = 0;
     _capacity = new_capacity;
   } else {
-    if (PrintGCDetails && Verbose) {
       // Failed to double capacity, continue;
-      gclog_or_tty->print(" (benign) Failed to expand marking stack capacity from "
-                          SIZE_FORMAT "K to " SIZE_FORMAT "K",
+    log_trace(gc)("(benign) Failed to expand marking stack capacity from " SIZE_FORMAT "K to " SIZE_FORMAT "K",
                           _capacity / K, new_capacity / K);
     }
-  }
 }
 
 void CMMarkStack::set_should_expand() {
   // If we're resetting the marking state because of an
   // marking stack overflow, record that we should, if

@@ -574,18 +568,10 @@
     _cleanup_task_overhead = marking_task_overhead();
   }
   _cleanup_sleep_factor =
                    (1.0 - cleanup_task_overhead()) / cleanup_task_overhead();
 
-#if 0
-  gclog_or_tty->print_cr("Marking Threads          %d", parallel_marking_threads());
-  gclog_or_tty->print_cr("CM Marking Task Overhead %1.4lf", marking_task_overhead());
-  gclog_or_tty->print_cr("CM Sleep Factor          %1.4lf", sleep_factor());
-  gclog_or_tty->print_cr("CL Marking Task Overhead %1.4lf", cleanup_task_overhead());
-  gclog_or_tty->print_cr("CL Sleep Factor          %1.4lf", cleanup_sleep_factor());
-#endif
-
   _parallel_workers = new WorkGang("G1 Marker",
        _max_parallel_marking_threads, false, true);
   if (_parallel_workers == NULL) {
     vm_exit_during_initialization("Failed necessary allocation.");
   } else {

@@ -920,14 +906,11 @@
       // we exit this method to abort the pause and restart concurrent
       // marking.
       reset_marking_state(true /* clear_overflow */);
       force_overflow()->update();
 
-      if (G1Log::fine()) {
-        gclog_or_tty->gclog_stamp();
-        gclog_or_tty->print_cr("[GC concurrent-mark-reset-for-overflow]");
-      }
+      log_info(gc)("Concurrent Mark reset for overflow");
     }
   }
 
   // after this, each task should reset its own data structures then
   // then go into the second barrier

@@ -1085,37 +1068,35 @@
     }
   }
 };
 
 void ConcurrentMark::scanRootRegions() {
-  double scan_start = os::elapsedTime();
+  jlong scan_start = os::elapsed_counter();
 
   // Start of concurrent marking.
   ClassLoaderDataGraph::clear_claimed_marks();
 
   // scan_in_progress() will have been set to true only if there was
   // at least one root region to scan. So, if it's false, we
   // should not attempt to do any further work.
   if (root_regions()->scan_in_progress()) {
-    if (G1Log::fine()) {
-      gclog_or_tty->gclog_stamp();
-      gclog_or_tty->print_cr("[GC concurrent-root-region-scan-start]");
-    }
+    log_info(gc)("Concurrent Root Region Scan (%.3fs)", TimeHelper::counter_to_seconds(scan_start));
 
     _parallel_marking_threads = calc_parallel_marking_threads();
     assert(parallel_marking_threads() <= max_parallel_marking_threads(),
            "Maximum number of marking threads exceeded");
     uint active_workers = MAX2(1U, parallel_marking_threads());
 
     CMRootRegionScanTask task(this);
     _parallel_workers->set_active_workers(active_workers);
     _parallel_workers->run_task(&task);
 
-    if (G1Log::fine()) {
-      gclog_or_tty->gclog_stamp();
-      gclog_or_tty->print_cr("[GC concurrent-root-region-scan-end, %1.7lf secs]", os::elapsedTime() - scan_start);
-    }
+    double end_time_ms = os::elapsed_counter();
+    log_info(gc)("Concurrent Root Region Scan (%.3fs, %.3fs) %.3fms",
+                 TimeHelper::counter_to_seconds(scan_start),
+                 TimeHelper::counter_to_seconds(end_time_ms),
+                 TimeHelper::counter_to_millis(end_time_ms - scan_start));
 
     // It's possible that has_aborted() is true here without actually
     // aborting the survivor scan earlier. This is OK as it's
     // mainly used for sanity checking.
     root_regions()->scan_finished();

@@ -1148,26 +1129,10 @@
   _parallel_workers->set_active_workers(active_workers);
   _parallel_workers->run_task(&markingTask);
   print_stats();
 }
 
-// Helper class to get rid of some boilerplate code.
-class G1CMTraceTime : public StackObj {
-  GCTraceTimeImpl _gc_trace_time;
-  static bool doit_and_prepend(bool doit) {
-    if (doit) {
-      gclog_or_tty->put(' ');
-    }
-    return doit;
-  }
-
- public:
-  G1CMTraceTime(const char* title, bool doit)
-    : _gc_trace_time(title, doit_and_prepend(doit), false, G1CollectedHeap::heap()->gc_timer_cm()) {
-  }
-};
-
 void ConcurrentMark::checkpointRootsFinal(bool clear_all_soft_refs) {
   // world is stopped at this checkpoint
   assert(SafepointSynchronize::is_at_safepoint(),
          "world should be stopped");
 

@@ -1182,12 +1147,11 @@
   SvcGCMarker sgcm(SvcGCMarker::OTHER);
 
   if (VerifyDuringGC) {
     HandleMark hm;  // handle scope
     g1h->prepare_for_verify();
-    Universe::verify(VerifyOption_G1UsePrevMarking,
-                     " VerifyDuringGC:(before)");
+    Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (before)");
   }
   g1h->check_bitmaps("Remark Start");
 
   G1CollectorPolicy* g1p = g1h->g1_policy();
   g1p->record_concurrent_mark_remark_start();

@@ -1201,28 +1165,25 @@
   weakRefsWork(clear_all_soft_refs);
 
   if (has_overflown()) {
     // Oops.  We overflowed.  Restart concurrent marking.
     _restart_for_overflow = true;
-    if (G1TraceMarkStackOverflow) {
-      gclog_or_tty->print_cr("\nRemark led to restart for overflow.");
-    }
+    log_develop(gc)("Remark led to restart for overflow.");
 
     // Verify the heap w.r.t. the previous marking bitmap.
     if (VerifyDuringGC) {
       HandleMark hm;  // handle scope
       g1h->prepare_for_verify();
-      Universe::verify(VerifyOption_G1UsePrevMarking,
-                       " VerifyDuringGC:(overflow)");
+      Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (overflow)");
     }
 
     // Clear the marking state because we will be restarting
     // marking due to overflowing the global mark stack.
     reset_marking_state();
   } else {
     {
-      G1CMTraceTime trace("GC aggregate-data", G1Log::finer());
+      GCTraceTime(Debug, gc) trace("GC aggregate-data", g1h->gc_timer_cm());
 
       // Aggregate the per-task counting data that we have accumulated
       // while marking.
       aggregate_count_data();
     }

@@ -1235,12 +1196,11 @@
                                        true /* expected_active */);
 
     if (VerifyDuringGC) {
       HandleMark hm;  // handle scope
       g1h->prepare_for_verify();
-      Universe::verify(VerifyOption_G1UseNextMarking,
-                       " VerifyDuringGC:(after)");
+      Universe::verify(VerifyOption_G1UseNextMarking, "During GC (after)");
     }
     g1h->check_bitmaps("Remark End");
     assert(!restart_for_overflow(), "sanity");
     // Completely reset the marking state since marking completed
     set_non_marking_state();

@@ -1755,12 +1715,11 @@
   g1h->verify_region_sets_optional();
 
   if (VerifyDuringGC) {
     HandleMark hm;  // handle scope
     g1h->prepare_for_verify();
-    Universe::verify(VerifyOption_G1UsePrevMarking,
-                     " VerifyDuringGC:(before)");
+    Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (before)");
   }
   g1h->check_bitmaps("Cleanup Start");
 
   G1CollectorPolicy* g1p = g1h->g1_policy();
   g1p->record_concurrent_mark_cleanup_start();

@@ -1798,12 +1757,12 @@
 
   double count_end = os::elapsedTime();
   double this_final_counting_time = (count_end - start);
   _total_counting_time += this_final_counting_time;
 
-  if (G1PrintRegionLivenessInfo) {
-    G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Marking");
+  if (Log<LOG_TAGS(gc, liveness)>::is_trace()) {
+    G1PrintRegionLivenessInfoClosure cl("Post-Marking");
     _g1h->heap_region_iterate(&cl);
   }
 
   // Install newly created mark bitMap as "prev".
   swapMarkBitMaps();

@@ -1842,23 +1801,18 @@
 
   // Statistics.
   double end = os::elapsedTime();
   _cleanup_times.add((end - start) * 1000.0);
 
-  if (G1Log::fine()) {
-    g1h->g1_policy()->print_heap_transition(start_used_bytes);
-  }
-
   // Clean up will have freed any regions completely full of garbage.
   // Update the soft reference policy with the new heap occupancy.
   Universe::update_heap_info_at_gc();
 
   if (VerifyDuringGC) {
     HandleMark hm;  // handle scope
     g1h->prepare_for_verify();
-    Universe::verify(VerifyOption_G1UsePrevMarking,
-                     " VerifyDuringGC:(after)");
+    Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (after)");
   }
 
   g1h->check_bitmaps("Cleanup End");
 
   g1h->verify_region_sets_optional();

@@ -1887,15 +1841,13 @@
   G1CollectedHeap* g1h = G1CollectedHeap::heap();
 
   _cleanup_list.verify_optional();
   FreeRegionList tmp_free_list("Tmp Free List");
 
-  if (G1ConcRegionFreeingVerbose) {
-    gclog_or_tty->print_cr("G1ConcRegionFreeing [complete cleanup] : "
+  log_develop(gc, freelist)("G1ConcRegionFreeing [complete cleanup] : "
                            "cleanup list has %u entries",
                            _cleanup_list.length());
-  }
 
   // No one else should be accessing the _cleanup_list at this point,
   // so it is not necessary to take any locks
   while (!_cleanup_list.is_empty()) {
     HeapRegion* hr = _cleanup_list.remove_region(true /* from_head */);

@@ -1909,17 +1861,15 @@
     // we do during this process. We'll also append the local list when
     // _cleanup_list is empty (which means we just removed the last
     // region from the _cleanup_list).
     if ((tmp_free_list.length() % G1SecondaryFreeListAppendLength == 0) ||
         _cleanup_list.is_empty()) {
-      if (G1ConcRegionFreeingVerbose) {
-        gclog_or_tty->print_cr("G1ConcRegionFreeing [complete cleanup] : "
+      log_develop(gc, freelist)("G1ConcRegionFreeing [complete cleanup] : "
                                "appending %u entries to the secondary_free_list, "
                                "cleanup list still has %u entries",
                                tmp_free_list.length(),
                                _cleanup_list.length());
-      }
 
       {
         MutexLockerEx x(SecondaryFreeList_lock, Mutex::_no_safepoint_check_flag);
         g1h->secondary_free_list_add(&tmp_free_list);
         SecondaryFreeList_lock->notify_all();

@@ -2172,11 +2122,11 @@
   G1CMIsAliveClosure g1_is_alive(g1h);
 
   // Inner scope to exclude the cleaning of the string and symbol
   // tables from the displayed time.
   {
-    G1CMTraceTime t("GC ref-proc", G1Log::finer());
+    GCTraceTime(Debug, gc) trace("GC ref-proc", g1h->gc_timer_cm());
 
     ReferenceProcessor* rp = g1h->ref_processor_cm();
 
     // See the comment in G1CollectedHeap::ref_processing_init()
     // about how reference processing currently works in G1.

@@ -2262,28 +2212,28 @@
 
   assert(_markStack.isEmpty(), "Marking should have completed");
 
   // Unload Klasses, String, Symbols, Code Cache, etc.
   {
-    G1CMTraceTime trace("Unloading", G1Log::finer());
+    GCTraceTime(Debug, gc) trace("Unloading", g1h->gc_timer_cm());
 
     if (ClassUnloadingWithConcurrentMark) {
       bool purged_classes;
 
       {
-        G1CMTraceTime trace("System Dictionary Unloading", G1Log::finest());
+        GCTraceTime(Trace, gc) trace("System Dictionary Unloading", g1h->gc_timer_cm());
         purged_classes = SystemDictionary::do_unloading(&g1_is_alive, false /* Defer klass cleaning */);
       }
 
       {
-        G1CMTraceTime trace("Parallel Unloading", G1Log::finest());
+        GCTraceTime(Trace, gc) trace("Parallel Unloading", g1h->gc_timer_cm());
         weakRefsWorkParallelPart(&g1_is_alive, purged_classes);
       }
     }
 
     if (G1StringDedup::is_enabled()) {
-      G1CMTraceTime trace("String Deduplication Unlink", G1Log::finest());
+      GCTraceTime(Trace, gc) trace("String Deduplication Unlink", g1h->gc_timer_cm());
       G1StringDedup::unlink(&g1_is_alive);
     }
   }
 }
 

@@ -2400,11 +2350,11 @@
 void ConcurrentMark::checkpointRootsFinalWork() {
   ResourceMark rm;
   HandleMark   hm;
   G1CollectedHeap* g1h = G1CollectedHeap::heap();
 
-  G1CMTraceTime trace("Finalize Marking", G1Log::finer());
+  GCTraceTime(Debug, gc) trace("Finalize Marking", g1h->gc_timer_cm());
 
   g1h->ensure_parsability(false);
 
   // this is remark, so we'll use up all active threads
   uint active_workers = g1h->workers()->active_workers();

@@ -2717,16 +2667,18 @@
     task_card_bm->clear();
   }
 }
 
 void ConcurrentMark::print_stats() {
-  if (G1MarkingVerboseLevel > 0) {
-    gclog_or_tty->print_cr("---------------------------------------------------------------------");
+  LogHandle(gc, stats) log;
+  if (!log.is_debug()) {
+    return;
+  }
+  log.debug("---------------------------------------------------------------------");
     for (size_t i = 0; i < _active_tasks; ++i) {
       _tasks[i]->print_stats();
-      gclog_or_tty->print_cr("---------------------------------------------------------------------");
-    }
+    log.debug("---------------------------------------------------------------------");
   }
 }
 
 // abandon current marking iteration due to a Full GC
 void ConcurrentMark::abort() {

@@ -2766,47 +2718,43 @@
   _g1h->register_concurrent_cycle_end();
 }
 
 static void print_ms_time_info(const char* prefix, const char* name,
                                NumberSeq& ns) {
-  gclog_or_tty->print_cr("%s%5d %12s: total time = %8.2f s (avg = %8.2f ms).",
+  log_trace(gc, marking, stats, exit)("%s%5d %12s: total time = %8.2f s (avg = %8.2f ms).",
                          prefix, ns.num(), name, ns.sum()/1000.0, ns.avg());
   if (ns.num() > 0) {
-    gclog_or_tty->print_cr("%s         [std. dev = %8.2f ms, max = %8.2f ms]",
+    log_trace(gc, marking, stats, exit)("%s         [std. dev = %8.2f ms, max = %8.2f ms]",
                            prefix, ns.sd(), ns.maximum());
   }
 }
 
 void ConcurrentMark::print_summary_info() {
-  gclog_or_tty->print_cr(" Concurrent marking:");
+  LogHandle(gc, marking, stats, exit) log;
+  if (!log.is_trace()) {
+    return;
+  }
+
+  log.trace(" Concurrent marking:");
   print_ms_time_info("  ", "init marks", _init_times);
   print_ms_time_info("  ", "remarks", _remark_times);
   {
     print_ms_time_info("     ", "final marks", _remark_mark_times);
     print_ms_time_info("     ", "weak refs", _remark_weak_ref_times);
 
   }
   print_ms_time_info("  ", "cleanups", _cleanup_times);
-  gclog_or_tty->print_cr("    Final counting total time = %8.2f s (avg = %8.2f ms).",
-                         _total_counting_time,
-                         (_cleanup_times.num() > 0 ? _total_counting_time * 1000.0 /
-                          (double)_cleanup_times.num()
-                         : 0.0));
+  log.trace("    Final counting total time = %8.2f s (avg = %8.2f ms).",
+            _total_counting_time, (_cleanup_times.num() > 0 ? _total_counting_time * 1000.0 / (double)_cleanup_times.num() : 0.0));
   if (G1ScrubRemSets) {
-    gclog_or_tty->print_cr("    RS scrub total time = %8.2f s (avg = %8.2f ms).",
-                           _total_rs_scrub_time,
-                           (_cleanup_times.num() > 0 ? _total_rs_scrub_time * 1000.0 /
-                            (double)_cleanup_times.num()
-                           : 0.0));
-  }
-  gclog_or_tty->print_cr("  Total stop_world time = %8.2f s.",
-                         (_init_times.sum() + _remark_times.sum() +
-                          _cleanup_times.sum())/1000.0);
-  gclog_or_tty->print_cr("  Total concurrent time = %8.2f s "
-                "(%8.2f s marking).",
-                cmThread()->vtime_accum(),
-                cmThread()->vtime_mark_accum());
+    log.trace("    RS scrub total time = %8.2f s (avg = %8.2f ms).",
+              _total_rs_scrub_time, (_cleanup_times.num() > 0 ? _total_rs_scrub_time * 1000.0 / (double)_cleanup_times.num() : 0.0));
+  }
+  log.trace("  Total stop_world time = %8.2f s.",
+            (_init_times.sum() + _remark_times.sum() + _cleanup_times.sum())/1000.0);
+  log.trace("  Total concurrent time = %8.2f s (%8.2f s marking).",
+            cmThread()->vtime_accum(), cmThread()->vtime_mark_accum());
 }
 
 void ConcurrentMark::print_worker_threads_on(outputStream* st) const {
   _parallel_workers->print_worker_threads_on(st);
 }

@@ -3182,18 +3130,18 @@
   // limits to get the regular clock call early
   decrease_limits();
 }
 
 void CMTask::print_stats() {
-  gclog_or_tty->print_cr("Marking Stats, task = %u, calls = %d",
+  log_debug(gc, stats)("Marking Stats, task = %u, calls = %d",
                          _worker_id, _calls);
-  gclog_or_tty->print_cr("  Elapsed time = %1.2lfms, Termination time = %1.2lfms",
+  log_debug(gc, stats)("  Elapsed time = %1.2lfms, Termination time = %1.2lfms",
                          _elapsed_time_ms, _termination_time_ms);
-  gclog_or_tty->print_cr("  Step Times (cum): num = %d, avg = %1.2lfms, sd = %1.2lfms",
+  log_debug(gc, stats)("  Step Times (cum): num = %d, avg = %1.2lfms, sd = %1.2lfms",
                          _step_times_ms.num(), _step_times_ms.avg(),
                          _step_times_ms.sd());
-  gclog_or_tty->print_cr("                    max = %1.2lfms, total = %1.2lfms",
+  log_debug(gc, stats)("                    max = %1.2lfms, total = %1.2lfms",
                          _step_times_ms.maximum(), _step_times_ms.sum());
 }
 
 bool ConcurrentMark::try_stealing(uint worker_id, int* hash_seed, oop& obj) {
   return _task_queues->steal(worker_id, hash_seed, obj);

@@ -3699,31 +3647,29 @@
 #define G1PPRL_SUM_BYTE_FORMAT(tag)    "  " tag ": " SIZE_FORMAT
 #define G1PPRL_SUM_MB_FORMAT(tag)      "  " tag ": %1.2f MB"
 #define G1PPRL_SUM_MB_PERC_FORMAT(tag) G1PPRL_SUM_MB_FORMAT(tag) " / %1.2f %%"
 
 G1PrintRegionLivenessInfoClosure::
-G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name)
-  : _out(out),
-    _total_used_bytes(0), _total_capacity_bytes(0),
+G1PrintRegionLivenessInfoClosure(const char* phase_name)
+  : _total_used_bytes(0), _total_capacity_bytes(0),
     _total_prev_live_bytes(0), _total_next_live_bytes(0),
     _hum_used_bytes(0), _hum_capacity_bytes(0),
     _hum_prev_live_bytes(0), _hum_next_live_bytes(0),
     _total_remset_bytes(0), _total_strong_code_roots_bytes(0) {
   G1CollectedHeap* g1h = G1CollectedHeap::heap();
   MemRegion g1_reserved = g1h->g1_reserved();
   double now = os::elapsedTime();
 
   // Print the header of the output.
-  _out->cr();
-  _out->print_cr(G1PPRL_LINE_PREFIX" PHASE %s @ %1.3f", phase_name, now);
-  _out->print_cr(G1PPRL_LINE_PREFIX" HEAP"
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX" PHASE %s @ %1.3f", phase_name, now);
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX" HEAP"
                  G1PPRL_SUM_ADDR_FORMAT("reserved")
                  G1PPRL_SUM_BYTE_FORMAT("region-size"),
                  p2i(g1_reserved.start()), p2i(g1_reserved.end()),
                  HeapRegion::GrainBytes);
-  _out->print_cr(G1PPRL_LINE_PREFIX);
-  _out->print_cr(G1PPRL_LINE_PREFIX
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX);
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX
                 G1PPRL_TYPE_H_FORMAT
                 G1PPRL_ADDR_BASE_H_FORMAT
                 G1PPRL_BYTE_H_FORMAT
                 G1PPRL_BYTE_H_FORMAT
                 G1PPRL_BYTE_H_FORMAT

@@ -3731,11 +3677,11 @@
                 G1PPRL_BYTE_H_FORMAT
                 G1PPRL_BYTE_H_FORMAT,
                 "type", "address-range",
                 "used", "prev-live", "next-live", "gc-eff",
                 "remset", "code-roots");
-  _out->print_cr(G1PPRL_LINE_PREFIX
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX
                 G1PPRL_TYPE_H_FORMAT
                 G1PPRL_ADDR_BASE_H_FORMAT
                 G1PPRL_BYTE_H_FORMAT
                 G1PPRL_BYTE_H_FORMAT
                 G1PPRL_BYTE_H_FORMAT

@@ -3813,11 +3759,11 @@
   _total_next_live_bytes += next_live_bytes;
   _total_remset_bytes    += remset_bytes;
   _total_strong_code_roots_bytes += strong_code_roots_bytes;
 
   // Print a line for this particular region.
-  _out->print_cr(G1PPRL_LINE_PREFIX
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX
                  G1PPRL_TYPE_FORMAT
                  G1PPRL_ADDR_BASE_FORMAT
                  G1PPRL_BYTE_FORMAT
                  G1PPRL_BYTE_FORMAT
                  G1PPRL_BYTE_FORMAT

@@ -3833,12 +3779,12 @@
 
 G1PrintRegionLivenessInfoClosure::~G1PrintRegionLivenessInfoClosure() {
   // add static memory usages to remembered set sizes
   _total_remset_bytes += HeapRegionRemSet::fl_mem_size() + HeapRegionRemSet::static_mem_size();
   // Print the footer of the output.
-  _out->print_cr(G1PPRL_LINE_PREFIX);
-  _out->print_cr(G1PPRL_LINE_PREFIX
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX);
+  log_trace(gc, liveness)(G1PPRL_LINE_PREFIX
                  " SUMMARY"
                  G1PPRL_SUM_MB_FORMAT("capacity")
                  G1PPRL_SUM_MB_PERC_FORMAT("used")
                  G1PPRL_SUM_MB_PERC_FORMAT("prev-live")
                  G1PPRL_SUM_MB_PERC_FORMAT("next-live")

@@ -3851,7 +3797,6 @@
                  perc(_total_prev_live_bytes, _total_capacity_bytes),
                  bytes_to_mb(_total_next_live_bytes),
                  perc(_total_next_live_bytes, _total_capacity_bytes),
                  bytes_to_mb(_total_remset_bytes),
                  bytes_to_mb(_total_strong_code_roots_bytes));
-  _out->cr();
 }
< prev index next >