< prev index next >

src/share/vm/gc/parallel/psMarkSweep.cpp

Print this page

        

@@ -43,10 +43,11 @@
 #include "gc/shared/gcTraceTime.hpp"
 #include "gc/shared/isGCActiveMark.hpp"
 #include "gc/shared/referencePolicy.hpp"
 #include "gc/shared/referenceProcessor.hpp"
 #include "gc/shared/spaceDecorator.hpp"
+#include "logging/log.hpp"
 #include "oops/oop.inline.hpp"
 #include "runtime/biasedLocking.hpp"
 #include "runtime/fprofiler.hpp"
 #include "runtime/safepoint.hpp"
 #include "runtime/vmThread.hpp"

@@ -134,22 +135,20 @@
   heap->record_gen_tops_before_GC();
 
   // We need to track unique mark sweep invocations as well.
   _total_invocations++;
 
-  AdaptiveSizePolicyOutput(size_policy, heap->total_collections());
-
   heap->print_heap_before_gc();
   heap->trace_heap_before_gc(_gc_tracer);
 
   // Fill in TLABs
   heap->accumulate_statistics_all_tlabs();
   heap->ensure_parsability(true);  // retire TLABs
 
   if (VerifyBeforeGC && heap->total_collections() >= VerifyGCStartAt) {
     HandleMark hm;  // Discard invalid handles created during verification
-    Universe::verify(" VerifyBeforeGC:");
+    Universe::verify("Before GC");
   }
 
   // Verify object start arrays
   if (VerifyObjectStartArray &&
       VerifyBeforeGC) {

@@ -164,12 +163,12 @@
   bool young_gen_empty;
 
   {
     HandleMark hm;
 
-    TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
-    GCTraceTime t1(GCCauseString("Full GC", gc_cause), PrintGC, !PrintGCDetails, NULL);
+    GCTraceCPUTime tcpu;
+    GCTraceTime(Info, gc) t("Pause Full", NULL, gc_cause, true);
     TraceCollectorStats tcs(counters());
     TraceMemoryManagerStats tms(true /* Full GC */,gc_cause);
 
     if (TraceOldGenTime) accumulated_time()->start();
 

@@ -177,17 +176,13 @@
     size_policy->major_collection_begin();
 
     CodeCache::gc_prologue();
     BiasedLocking::preserve_marks();
 
-    // Capture heap size before collection for printing.
-    size_t prev_used = heap->used();
-
     // Capture metadata size before collection for sizing.
     size_t metadata_prev_used = MetaspaceAux::used_bytes();
 
-    // For PrintGCDetails
     size_t old_gen_prev_used = old_gen->used_in_bytes();
     size_t young_gen_prev_used = young_gen->used_in_bytes();
 
     allocate_stacks();
 

@@ -263,21 +258,13 @@
     // Let the size policy know we're done
     size_policy->major_collection_end(old_gen->used_in_bytes(), gc_cause);
 
     if (UseAdaptiveSizePolicy) {
 
-      if (PrintAdaptiveSizePolicy) {
-        gclog_or_tty->print("AdaptiveSizeStart: ");
-        gclog_or_tty->stamp();
-        gclog_or_tty->print_cr(" collection: %d ",
-                       heap->total_collections());
-        if (Verbose) {
-          gclog_or_tty->print("old_gen_capacity: " SIZE_FORMAT
-            " young_gen_capacity: " SIZE_FORMAT,
+     log_debug(gc, ergo)("AdaptiveSizeStart: collection: %d ", heap->total_collections());
+     log_trace(gc, ergo)("old_gen_capacity: " SIZE_FORMAT " young_gen_capacity: " SIZE_FORMAT,
             old_gen->capacity_in_bytes(), young_gen->capacity_in_bytes());
-        }
-      }
 
       // Don't check if the size_policy is ready here.  Let
       // the size_policy check that internally.
       if (UseAdaptiveGenerationSizePolicyAtMajorCollection &&
           AdaptiveSizePolicy::should_update_promo_stats(gc_cause)) {

@@ -330,14 +317,11 @@
         heap->resize_old_gen(size_policy->calculated_old_free_size_in_bytes());
 
         heap->resize_young_gen(size_policy->calculated_eden_size_in_bytes(),
                                size_policy->calculated_survivor_size_in_bytes());
       }
-      if (PrintAdaptiveSizePolicy) {
-        gclog_or_tty->print_cr("AdaptiveSizeStop: collection: %d ",
-                       heap->total_collections());
-      }
+      log_debug(gc, ergo)("AdaptiveSizeStop: collection: %d ", heap->total_collections());
     }
 
     if (UsePerfData) {
       heap->gc_policy_counters()->update_counters();
       heap->gc_policy_counters()->update_old_capacity(

@@ -351,31 +335,22 @@
     // We collected the heap, recalculate the metaspace capacity
     MetaspaceGC::compute_new_size();
 
     if (TraceOldGenTime) accumulated_time()->stop();
 
-    if (PrintGC) {
-      if (PrintGCDetails) {
-        // Don't print a GC timestamp here.  This is after the GC so
-        // would be confusing.
         young_gen->print_used_change(young_gen_prev_used);
         old_gen->print_used_change(old_gen_prev_used);
-      }
-      heap->print_heap_change(prev_used);
-      if (PrintGCDetails) {
         MetaspaceAux::print_metaspace_change(metadata_prev_used);
-      }
-    }
 
     // Track memory usage and detect low memory
     MemoryService::track_memory_usage();
     heap->update_counters();
   }
 
   if (VerifyAfterGC && heap->total_collections() >= VerifyGCStartAt) {
     HandleMark hm;  // Discard invalid handles created during verification
-    Universe::verify(" VerifyAfterGC:");
+    Universe::verify("After GC");
   }
 
   // Re-verify object start arrays
   if (VerifyObjectStartArray &&
       VerifyAfterGC) {

@@ -395,10 +370,12 @@
 
 #ifdef TRACESPINNING
   ParallelTaskTerminator::print_termination_counts();
 #endif
 
+  AdaptiveSizePolicyOutput::print(size_policy, heap->total_collections());
+
   _gc_timer->register_gc_end();
 
   _gc_tracer->report_gc_end(_gc_timer->gc_end(), _gc_timer->time_partitions());
 
   return true;

@@ -440,21 +417,19 @@
   const size_t new_young_size = young_gen->capacity_in_bytes() - absorb_size;
   if (new_young_size < young_gen->min_gen_size()) {
     return false; // Respect young gen minimum size.
   }
 
-  if (TraceAdaptiveGCBoundary && Verbose) {
-    gclog_or_tty->print(" absorbing " SIZE_FORMAT "K:  "
+  log_trace(heap, ergo)(" absorbing " SIZE_FORMAT "K:  "
                         "eden " SIZE_FORMAT "K->" SIZE_FORMAT "K "
                         "from " SIZE_FORMAT "K, to " SIZE_FORMAT "K "
                         "young_gen " SIZE_FORMAT "K->" SIZE_FORMAT "K ",
                         absorb_size / K,
                         eden_capacity / K, (eden_capacity - absorb_size) / K,
                         young_gen->from_space()->used_in_bytes() / K,
                         young_gen->to_space()->used_in_bytes() / K,
                         young_gen->capacity_in_bytes() / K, new_young_size / K);
-  }
 
   // Fill the unused part of the old gen.
   MutableSpace* const old_space = old_gen->object_space();
   HeapWord* const unused_start = old_space->top();
   size_t const unused_words = pointer_delta(old_space->end(), unused_start);

@@ -514,11 +489,11 @@
   _objarray_stack.clear(true);
 }
 
 void PSMarkSweep::mark_sweep_phase1(bool clear_all_softrefs) {
   // Recursively traverse all live objects and mark them
-  GCTraceTime tm("phase 1", PrintGCDetails && Verbose, true, _gc_timer);
+  GCTraceTime(Trace, gc) tm("Phase 1: Mark live objects", _gc_timer);
 
   ParallelScavengeHeap* heap = ParallelScavengeHeap::heap();
 
   // Need to clear claim bits before the tracing starts.
   ClassLoaderDataGraph::clear_claimed_marks();

@@ -573,11 +548,11 @@
   _gc_tracer->report_object_count_after_gc(is_alive_closure());
 }
 
 
 void PSMarkSweep::mark_sweep_phase2() {
-  GCTraceTime tm("phase 2", PrintGCDetails && Verbose, true, _gc_timer);
+  GCTraceTime(Trace, gc) tm("Phase 2: Compute new object addresses", _gc_timer);
 
   // Now all live objects are marked, compute the new object addresses.
 
   // It is not required that we traverse spaces in the same order in
   // phase2, phase3 and phase4, but the ValidateMarkSweep live oops

@@ -600,11 +575,11 @@
 };
 static PSAlwaysTrueClosure always_true;
 
 void PSMarkSweep::mark_sweep_phase3() {
   // Adjust the pointers to reflect the new locations
-  GCTraceTime tm("phase 3", PrintGCDetails && Verbose, true, _gc_timer);
+  GCTraceTime(Trace, gc) tm("Phase 3: Adjust pointers", _gc_timer);
 
   ParallelScavengeHeap* heap = ParallelScavengeHeap::heap();
   PSYoungGen* young_gen = heap->young_gen();
   PSOldGen* old_gen = heap->old_gen();
 

@@ -640,11 +615,11 @@
   old_gen->adjust_pointers();
 }
 
 void PSMarkSweep::mark_sweep_phase4() {
   EventMark m("4 compact heap");
-  GCTraceTime tm("phase 4", PrintGCDetails && Verbose, true, _gc_timer);
+  GCTraceTime(Trace, gc) tm("Phase 4: Move objects", _gc_timer);
 
   // All pointers are now adjusted, move objects accordingly
 
   ParallelScavengeHeap* heap = ParallelScavengeHeap::heap();
   PSYoungGen* young_gen = heap->young_gen();
< prev index next >