Merge

hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp

@@ -1716,7 +1716,7 @@ HeapWord* G1CollectedHeap::expand_and_allocate(size_t word_size, AllocationConte
   return NULL;
 }
 
-bool G1CollectedHeap::expand(size_t expand_bytes) {
+bool G1CollectedHeap::expand(size_t expand_bytes, double* expand_time_ms) {
   size_t aligned_expand_bytes = ReservedSpace::page_align_size_up(expand_bytes);
   aligned_expand_bytes = align_size_up(aligned_expand_bytes,
                                        HeapRegion::GrainBytes);
@@ -1733,10 +1733,14 @@ bool G1CollectedHeap::expand(size_t expand_bytes) {
     return false;
   }
 
+  double expand_heap_start_time_sec = os::elapsedTime();
   uint regions_to_expand = (uint)(aligned_expand_bytes / HeapRegion::GrainBytes);
   assert(regions_to_expand > 0, "Must expand by at least one region");
 
   uint expanded_by = _hrm.expand_by(regions_to_expand);
+  if (expand_time_ms != NULL) {
+    *expand_time_ms = (os::elapsedTime() - expand_heap_start_time_sec) * MILLIUNITS;
+  }
 
   if (expanded_by > 0) {
     size_t actual_expand_bytes = expanded_by * HeapRegion::GrainBytes;
@@ -3997,9 +4001,11 @@ G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) {
             size_t bytes_before = capacity();
             // No need for an ergo verbose message here,
             // expansion_amount() does this when it returns a value > 0.
-            if (!expand(expand_bytes)) {
+            double expand_ms;
+            if (!expand(expand_bytes, &expand_ms)) {
               // We failed to expand the heap. Cannot do anything about it.
             }
+            g1_policy()->phase_times()->record_expand_heap_time(expand_ms);
           }
         }
 

hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp

@@ -538,7 +538,7 @@ public:
   // Returns true if the heap was expanded by the requested amount;
   // false otherwise.
   // (Rounds up to a HeapRegion boundary.)
-  bool expand(size_t expand_bytes);
+  bool expand(size_t expand_bytes, double* expand_time_ms = NULL);
 
   // Returns the PLAB statistics for a given destination.
   inline G1EvacStats* alloc_buffer_stats(InCSetState dest);

hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp

@@ -298,6 +298,7 @@ void G1GCPhaseTimes::note_gc_start(uint active_gc_threads, bool mark_in_progress
   assert(active_gc_threads > 0, "The number of threads must be > 0");
   assert(active_gc_threads <= _max_gc_threads, "The number of active threads must be <= the max number of threads");
   _active_gc_threads = active_gc_threads;
+  _cur_expand_heap_time_ms = 0.0;
 
   for (int i = 0; i < GCParPhasesSentinel; i++) {
     _gc_par_phases[i]->reset();
@@ -363,6 +364,9 @@ double G1GCPhaseTimes::accounted_time_ms() {
     // current value of "other time"
     misc_time_ms += _cur_clear_ct_time_ms;
 
+    // Remove expand heap time from "other time"
+    misc_time_ms += _cur_expand_heap_time_ms;
+
     return misc_time_ms;
 }
 
@@ -536,6 +540,8 @@ void G1GCPhaseTimes::print(double pause_time_sec) {
     }
   }
   print_stats(1, "Clear CT", _cur_clear_ct_time_ms);
+  print_stats(1, "Expand Heap After Collection", _cur_expand_heap_time_ms);
+
   double misc_time_ms = pause_time_sec * MILLIUNITS - accounted_time_ms();
   print_stats(1, "Other", misc_time_ms);
   if (_cur_verify_before_time_ms > 0.0) {

hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp

@@ -92,6 +92,7 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
   double _cur_string_dedup_fixup_time_ms;
 
   double _cur_clear_ct_time_ms;
+  double _cur_expand_heap_time_ms;
   double _cur_ref_proc_time_ms;
   double _cur_ref_enq_time_ms;
 
@@ -155,6 +156,10 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
     _cur_clear_ct_time_ms = ms;
   }
 
+  void record_expand_heap_time(double ms) {
+    _cur_expand_heap_time_ms = ms;
+  }
+
   void record_par_time(double ms) {
     _cur_collection_par_time_ms = ms;
   }
@@ -252,6 +257,10 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
     return _cur_clear_ct_time_ms;
   }
 
+  double cur_expand_heap_time_ms() {
+    return _cur_expand_heap_time_ms;
+  }
+
   double root_region_scan_wait_time_ms() {
     return _root_region_scan_wait_time_ms;
   }

hotspot/test/gc/g1/TestGCLogMessages.java

@@ -79,6 +79,7 @@ public class TestGCLogMessages {
         // Misc Top-level
         new LogMessageWithLevel("Code Root Purge", Level.FINER),
         new LogMessageWithLevel("String Dedup Fixup", Level.FINER),
+        new LogMessageWithLevel("Expand Heap After Collection", Level.FINER),
         // Free CSet
         new LogMessageWithLevel("Young Free CSet", Level.FINEST),
         new LogMessageWithLevel("Non-Young Free CSet", Level.FINEST),