8060017: G1: Report heap sizing time
Summary: Report heap expansion time done on VM thread after collection. Previously this was included in "Other" time.
Reviewed-by: mgerdin, tschatzl
--- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Tue Oct 20 14:00:00 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Tue Oct 20 14:01:49 2015 -0400
@@ -1712,7 +1712,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);
@@ -1729,10 +1729,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;
@@ -3990,9 +3994,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);
}
}
--- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp Tue Oct 20 14:00:00 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp Tue Oct 20 14:01:49 2015 -0400
@@ -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);
--- a/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp Tue Oct 20 14:00:00 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp Tue Oct 20 14:01:49 2015 -0400
@@ -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) {
--- a/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp Tue Oct 20 14:00:00 2015 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp Tue Oct 20 14:01:49 2015 -0400
@@ -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;
}
--- a/hotspot/test/gc/g1/TestGCLogMessages.java Tue Oct 20 14:00:00 2015 +0200
+++ b/hotspot/test/gc/g1/TestGCLogMessages.java Tue Oct 20 14:01:49 2015 -0400
@@ -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),