# HG changeset patch
# User ecaspole
# Date 1445435185 0
# Node ID 01ade4446d96080abc0a9d530a9d8c339ac5c4fb
# Parent  6dbde58b08a6a414926a598a324b8510ce5be618# Parent  71ebe0491d4d97e70356e4e8d1a3914cf1db7d8b
Merge

diff -r 6dbde58b08a6 -r 01ade4446d96 hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp
--- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp	Tue Oct 13 10:06:46 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp	Wed Oct 21 13:46:25 2015 +0000
@@ -1716,7 +1716,7 @@
   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 @@
     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 @@
             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);
           }
         }
 
diff -r 6dbde58b08a6 -r 01ade4446d96 hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp
--- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp	Tue Oct 13 10:06:46 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp	Wed Oct 21 13:46:25 2015 +0000
@@ -538,7 +538,7 @@
   // 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);
diff -r 6dbde58b08a6 -r 01ade4446d96 hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp
--- a/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp	Tue Oct 13 10:06:46 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp	Wed Oct 21 13:46:25 2015 +0000
@@ -298,6 +298,7 @@
   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 @@
     // 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 @@
     }
   }
   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) {
diff -r 6dbde58b08a6 -r 01ade4446d96 hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp
--- a/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp	Tue Oct 13 10:06:46 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp	Wed Oct 21 13:46:25 2015 +0000
@@ -92,6 +92,7 @@
   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 @@
     _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 @@
     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;
   }
diff -r 6dbde58b08a6 -r 01ade4446d96 hotspot/test/gc/g1/TestGCLogMessages.java
--- a/hotspot/test/gc/g1/TestGCLogMessages.java	Tue Oct 13 10:06:46 2015 +0200
+++ b/hotspot/test/gc/g1/TestGCLogMessages.java	Wed Oct 21 13:46:25 2015 +0000
@@ -79,6 +79,7 @@
         // 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),