< prev index next >

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

Print this page

        

@@ -44,10 +44,11 @@
 #include "gc/shared/isGCActiveMark.hpp"
 #include "gc/shared/referencePolicy.hpp"
 #include "gc/shared/referenceProcessor.hpp"
 #include "gc/shared/spaceDecorator.hpp"
 #include "memory/resourceArea.hpp"
+#include "logging/log.hpp"
 #include "oops/oop.inline.hpp"
 #include "runtime/biasedLocking.hpp"
 #include "runtime/fprofiler.hpp"
 #include "runtime/handles.inline.hpp"
 #include "runtime/threadCritical.hpp"

@@ -288,12 +289,10 @@
   PSOldGen* old_gen = heap->old_gen();
   PSAdaptiveSizePolicy* size_policy = heap->size_policy();
 
   heap->increment_total_collections();
 
-  AdaptiveSizePolicyOutput(size_policy, heap->total_collections());
-
   if (AdaptiveSizePolicy::should_update_eden_stats(gc_cause)) {
     // Gather the feedback data for eden occupancy.
     young_gen->eden_space()->accumulate_statistics();
   }
 

@@ -301,27 +300,25 @@
   heap->trace_heap_before_gc(&_gc_tracer);
 
   assert(!NeverTenure || _tenuring_threshold == markOopDesc::max_age + 1, "Sanity");
   assert(!AlwaysTenure || _tenuring_threshold == 0, "Sanity");
 
-  size_t prev_used = heap->used();
-
   // 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");
   }
 
   {
     ResourceMark rm;
     HandleMark hm;
 
-    TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
-    GCTraceTime t1(GCCauseString("GC", gc_cause), PrintGC, !PrintGCDetails, NULL);
+    GCTraceCPUTime tcpu;
+    GCTraceTime(Info, gc) tm("Pause Young", NULL, gc_cause, true);
     TraceCollectorStats tcs(counters());
     TraceMemoryManagerStats tms(false /* not full GC */,gc_cause);
 
     if (TraceYoungGenTime) accumulated_time()->start();
 

@@ -350,16 +347,11 @@
 #endif
 
     reference_processor()->enable_discovery();
     reference_processor()->setup_policy(false);
 
-    // We track how much was promoted to the next generation for
-    // the AdaptiveSizePolicy.
-    size_t old_gen_used_before = old_gen->used_in_bytes();
-
-    // For PrintGCDetails
-    size_t young_gen_used_before = young_gen->used_in_bytes();
+    PreGCValues pre_gc_values(heap);
 
     // Reset our survivor overflow.
     set_survivor_overflow(false);
 
     // We need to save the old top values before

@@ -381,11 +373,11 @@
     PSPromotionManager::pre_scavenge();
 
     // We'll use the promotion manager again later.
     PSPromotionManager* promotion_manager = PSPromotionManager::vm_thread_promotion_manager();
     {
-      GCTraceTime tm("Scavenge", false, false, &_gc_timer);
+      GCTraceTime(Debug, gc, phases) tm("Scavenge", &_gc_timer);
       ParallelScavengeHeap::ParStrongRootsScope psrs;
 
       GCTaskQueue* q = GCTaskQueue::create();
 
       if (!old_gen->object_space()->is_empty()) {

@@ -423,11 +415,11 @@
 
     scavenge_midpoint.update();
 
     // Process reference objects discovered during scavenge
     {
-      GCTraceTime tm("References", false, false, &_gc_timer);
+      GCTraceTime(Debug, gc, phases) tm("References", &_gc_timer);
 
       reference_processor()->setup_policy(false); // not always_clear
       reference_processor()->set_active_mt_degree(active_workers);
       PSKeepAliveClosure keep_alive(promotion_manager);
       PSEvacuateFollowersClosure evac_followers(promotion_manager);

@@ -452,23 +444,21 @@
         reference_processor()->enqueue_discovered_references(NULL);
       }
     }
 
     {
-      GCTraceTime tm("StringTable", false, false, &_gc_timer);
+      GCTraceTime(Debug, gc, phases) tm("StringTable", &_gc_timer);
       // Unlink any dead interned Strings and process the remaining live ones.
       PSScavengeRootsClosure root_closure(promotion_manager);
       StringTable::unlink_or_oops_do(&_is_alive_closure, &root_closure);
     }
 
     // Finally, flush the promotion_manager's labs, and deallocate its stacks.
     promotion_failure_occurred = PSPromotionManager::post_scavenge(_gc_tracer);
     if (promotion_failure_occurred) {
       clean_up_failed_promotion();
-      if (PrintGC) {
-        gclog_or_tty->print("--");
-      }
+      log_info(gc)("Promotion failed");
     }
 
     _gc_tracer.report_tenuring_threshold(tenuring_threshold());
 
     // Let the size policy know we're done.  Note that we count promotion

@@ -481,32 +471,22 @@
       young_gen->eden_space()->clear(SpaceDecorator::Mangle);
       young_gen->from_space()->clear(SpaceDecorator::Mangle);
       young_gen->swap_spaces();
 
       size_t survived = young_gen->from_space()->used_in_bytes();
-      size_t promoted = old_gen->used_in_bytes() - old_gen_used_before;
+      size_t promoted = old_gen->used_in_bytes() - pre_gc_values.old_gen_used();
       size_policy->update_averages(_survivor_overflow, survived, promoted);
 
       // A successful scavenge should restart the GC time limit count which is
       // for full GC's.
       size_policy->reset_gc_overhead_limit_count();
       if (UseAdaptiveSizePolicy) {
         // Calculate the new survivor size and tenuring threshold
 
-        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());
-          }
-        }
-
 
         if (UsePerfData) {
           PSGCAdaptivePolicyCounters* counters = heap->gc_policy_counters();
           counters->update_old_eden_size(
             size_policy->calculated_eden_size_in_bytes());

@@ -536,17 +516,13 @@
           size_policy->compute_survivor_space_size_and_threshold(
                                                            _survivor_overflow,
                                                            _tenuring_threshold,
                                                            survivor_limit);
 
-       if (PrintTenuringDistribution) {
-         gclog_or_tty->cr();
-         gclog_or_tty->print_cr("Desired survivor size " SIZE_FORMAT " bytes, new threshold %u"
-                                " (max threshold " UINTX_FORMAT ")",
+       log_debug(gc, age)("Desired survivor size " SIZE_FORMAT " bytes, new threshold %u (max threshold " UINTX_FORMAT ")",
                                 size_policy->calculated_survivor_size_in_bytes(),
                                 _tenuring_threshold, MaxTenuringThreshold);
-       }
 
         if (UsePerfData) {
           PSGCAdaptivePolicyCounters* counters = heap->gc_policy_counters();
           counters->update_tenuring_threshold(_tenuring_threshold);
           counters->update_survivor_size_counters();

@@ -600,14 +576,11 @@
         // a full collection.  Don't resize the old gen here.
 
         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());
       }
 
       // Update the structure of the eden. With NUMA-eden CPU hotplugging or offlining can
       // cause the change of the heap layout. Make sure eden is reshaped if that's the case.
       // Also update() will case adaptive NUMA chunk resizing.

@@ -626,11 +599,11 @@
 #endif
 
     NOT_PRODUCT(reference_processor()->verify_no_references_recorded());
 
     {
-      GCTraceTime tm("Prune Scavenge Root Methods", false, false, &_gc_timer);
+      GCTraceTime(Debug, gc, phases) tm("Prune Scavenge Root Methods", &_gc_timer);
 
       CodeCache::prune_scavenge_root_nmethods();
     }
 
     // Re-verify object start arrays

@@ -647,47 +620,41 @@
       CardTableExtension::verify_all_young_refs_imprecise();
     }
 
     if (TraceYoungGenTime) 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_used_before);
-      }
-      heap->print_heap_change(prev_used);
-    }
+    young_gen->print_used_change(pre_gc_values.young_gen_used());
+    old_gen->print_used_change(pre_gc_values.old_gen_used());
+    MetaspaceAux::print_metaspace_change(pre_gc_values.metadata_used());
 
     // Track memory usage and detect low memory
     MemoryService::track_memory_usage();
     heap->update_counters();
 
     gc_task_manager()->release_idle_workers();
   }
 
   if (VerifyAfterGC && heap->total_collections() >= VerifyGCStartAt) {
     HandleMark hm;  // Discard invalid handles created during verification
-    Universe::verify(" VerifyAfterGC:");
+    Universe::verify("After GC");
   }
 
   heap->print_heap_after_gc();
   heap->trace_heap_after_gc(&_gc_tracer);
 
   scavenge_exit.update();
 
-  if (PrintGCTaskTimeStamps) {
-    tty->print_cr("VM-Thread " JLONG_FORMAT " " JLONG_FORMAT " " JLONG_FORMAT,
+  log_debug(gc, task, time)("VM-Thread " JLONG_FORMAT " " JLONG_FORMAT " " JLONG_FORMAT,
                   scavenge_entry.ticks(), scavenge_midpoint.ticks(),
                   scavenge_exit.ticks());
     gc_task_manager()->print_task_time_stamps();
-  }
 
 #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());
 

@@ -706,13 +673,11 @@
 
     // Unforward all pointers in the young gen.
     PSPromotionFailedClosure unforward_closure;
     young_gen->object_iterate(&unforward_closure);
 
-    if (PrintGC && Verbose) {
-      gclog_or_tty->print_cr("Restoring " SIZE_FORMAT " marks", _preserved_oop_stack.size());
-    }
+    log_trace(gc, ergo)("Restoring " SIZE_FORMAT " marks", _preserved_oop_stack.size());
 
     // Restore any saved marks.
     while (!_preserved_oop_stack.is_empty()) {
       oop obj      = _preserved_oop_stack.pop();
       markOop mark = _preserved_mark_stack.pop();

@@ -770,23 +735,16 @@
   // changed, decide if that test should also be changed.
   size_t avg_promoted = (size_t) policy->padded_average_promoted_in_bytes();
   size_t promotion_estimate = MIN2(avg_promoted, young_gen->used_in_bytes());
   bool result = promotion_estimate < old_gen->free_in_bytes();
 
-  if (PrintGCDetails && Verbose) {
-    gclog_or_tty->print(result ? "  do scavenge: " : "  skip scavenge: ");
-    gclog_or_tty->print_cr(" average_promoted " SIZE_FORMAT
-      " padded_average_promoted " SIZE_FORMAT
-      " free in old gen " SIZE_FORMAT,
-      (size_t) policy->average_promoted_in_bytes(),
+  log_trace(ergo)("%s scavenge: average_promoted " SIZE_FORMAT " padded_average_promoted " SIZE_FORMAT " free in old gen " SIZE_FORMAT,
+                result ? "Do" : "Skip", (size_t) policy->average_promoted_in_bytes(),
       (size_t) policy->padded_average_promoted_in_bytes(),
       old_gen->free_in_bytes());
-    if (young_gen->used_in_bytes() <
-        (size_t) policy->padded_average_promoted_in_bytes()) {
-      gclog_or_tty->print_cr(" padded_promoted_average is greater"
-        " than maximum promotion = " SIZE_FORMAT, young_gen->used_in_bytes());
-    }
+  if (young_gen->used_in_bytes() < (size_t) policy->padded_average_promoted_in_bytes()) {
+    log_trace(ergo)(" padded_promoted_average is greater than maximum promotion = " SIZE_FORMAT, young_gen->used_in_bytes());
   }
 
   if (result) {
     _consecutive_skipped_scavenges = 0;
   } else {
< prev index next >