stan/jdk-24
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

8035654: Add times for evacuation failure handling in "Other" time

Browse Source 
Detailed breakdown of time spent in the evacuation failure handling phases to make the "Other" time roughly correspond to the sum of its parts.

Reviewed-by: jwilhelm, jmasa
This commit is contained in:
Thomas Schatzl 2014-03-17 10:13:42 +01:00
parent 80188ce0b2
commit 2a8616c9d6
5 changed files with 93 additions and 1 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

8
hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
View File

@ -2360,8 +2360,12 @@ public:
};
size_t G1CollectedHeap::recalculate_used() const {
double recalculate_used_start = os::elapsedTime();
SumUsedClosure blk;
heap_region_iterate(&blk);
g1_policy()->phase_times()->record_evac_fail_recalc_used_time((os::elapsedTime() - recalculate_used_start) * 1000.0);
return blk.result();
}
@ -4376,6 +4380,8 @@ void G1CollectedHeap::finalize_for_evac_failure() {
void G1CollectedHeap::remove_self_forwarding_pointers() {
assert(check_cset_heap_region_claim_values(HeapRegion::InitialClaimValue), "sanity");
double remove_self_forwards_start = os::elapsedTime();
G1ParRemoveSelfForwardPtrsTask rsfp_task(this);
if (G1CollectedHeap::use_parallel_gc_threads()) {
@ -4403,6 +4409,8 @@ void G1CollectedHeap::remove_self_forwarding_pointers() {
}
_objs_with_preserved_marks.clear(true);
_preserved_marks_of_objs.clear(true);
g1_policy()->phase_times()->record_evac_fail_remove_self_forwards((os::elapsedTime() - remove_self_forwards_start) * 1000.0);
}
void G1CollectedHeap::push_on_evac_failure_scan_stack(oop obj) {

10
hotspot/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.cpp
View File

@ -309,6 +309,16 @@ void G1GCPhaseTimes::print(double pause_time_sec) {
if (_cur_verify_before_time_ms > 0.0) {
print_stats(2, "Verify Before", _cur_verify_before_time_ms);
}
if (G1CollectedHeap::heap()->evacuation_failed()) {
double evac_fail_handling = _cur_evac_fail_recalc_used + _cur_evac_fail_remove_self_forwards +
_cur_evac_fail_restore_remsets;
print_stats(2, "Evacuation Failure", evac_fail_handling);
if (G1Log::finest()) {
print_stats(3, "Recalculate Used", _cur_evac_fail_recalc_used);
print_stats(3, "Remove Self Forwards", _cur_evac_fail_remove_self_forwards);
print_stats(3, "Restore RemSet", _cur_evac_fail_restore_remsets);
}
}
print_stats(2, "Choose CSet",
(_recorded_young_cset_choice_time_ms +
_recorded_non_young_cset_choice_time_ms));

16
hotspot/src/share/vm/gc_implementation/g1/g1GCPhaseTimes.hpp
View File

@ -133,6 +133,10 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
double _cur_strong_code_root_migration_time_ms;
double _cur_strong_code_root_purge_time_ms;
double _cur_evac_fail_recalc_used;
double _cur_evac_fail_restore_remsets;
double _cur_evac_fail_remove_self_forwards;
double _cur_clear_ct_time_ms;
double _cur_ref_proc_time_ms;
double _cur_ref_enq_time_ms;
@ -230,6 +234,18 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
_cur_strong_code_root_purge_time_ms = ms;
}
void record_evac_fail_recalc_used_time(double ms) {
_cur_evac_fail_recalc_used = ms;
}
void record_evac_fail_restore_remsets(double ms) {
_cur_evac_fail_restore_remsets = ms;
}
void record_evac_fail_remove_self_forwards(double ms) {
_cur_evac_fail_remove_self_forwards = ms;
}
void record_ref_proc_time(double ms) {
_cur_ref_proc_time_ms = ms;
}

5
hotspot/src/share/vm/gc_implementation/g1/g1RemSet.cpp
View File

@ -462,8 +462,9 @@ void G1RemSet::cleanup_after_oops_into_collection_set_do() {
int into_cset_n_buffers = into_cset_dcqs.completed_buffers_num();
if (_g1->evacuation_failed()) {
// Restore remembered sets for the regions pointing into the collection set.
double restore_remembered_set_start = os::elapsedTime();
// Restore remembered sets for the regions pointing into the collection set.
if (G1DeferredRSUpdate) {
// If deferred RS updates are enabled then we just need to transfer
// the completed buffers from (a) the DirtyCardQueueSet used to hold
@ -482,6 +483,8 @@ void G1RemSet::cleanup_after_oops_into_collection_set_do() {
}
assert(n_completed_buffers == into_cset_n_buffers, "missed some buffers");
}
_g1->g1_policy()->phase_times()->record_evac_fail_restore_remsets((os::elapsedTime() - restore_remembered_set_start) * 1000.0);
}
// Free any completed buffers in the DirtyCardQueueSet used to hold cards

55
hotspot/test/gc/g1/TestGCLogMessages.java
View File

@ -35,6 +35,11 @@ import com.oracle.java.testlibrary.OutputAnalyzer;
public class TestGCLogMessages {
public static void main(String[] args) throws Exception {
testNormalLogs();
testWithToSpaceExhaustionLogs();
}
private static void testNormalLogs() throws Exception {
ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
"-Xmx10M",
@ -74,8 +79,43 @@ public class TestGCLogMessages {
output.shouldContain("[Code Root Purge");
output.shouldContain("[Young Free CSet");
output.shouldContain("[Non-Young Free CSet");
// also check evacuation failure messages once
output.shouldNotContain("[Evacuation Failure");
output.shouldNotContain("[Recalculate Used");
output.shouldNotContain("[Remove Self Forwards");
output.shouldNotContain("[Restore RemSet");
output.shouldHaveExitValue(0);
}
private static void testWithToSpaceExhaustionLogs() throws Exception {
ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
"-Xmx10M",
"-Xmn5M",
"-XX:+PrintGCDetails",
GCTestWithToSpaceExhaustion.class.getName());
OutputAnalyzer output = new OutputAnalyzer(pb.start());
output.shouldContain("[Evacuation Failure");
output.shouldNotContain("[Recalculate Used");
output.shouldNotContain("[Remove Self Forwards");
output.shouldNotContain("[Restore RemSet");
output.shouldHaveExitValue(0);
pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
"-Xmx10M",
"-Xmn5M",
"-XX:+PrintGCDetails",
"-XX:+UnlockExperimentalVMOptions",
"-XX:G1LogLevel=finest",
GCTestWithToSpaceExhaustion.class.getName());
output = new OutputAnalyzer(pb.start());
output.shouldContain("[Evacuation Failure");
output.shouldContain("[Recalculate Used");
output.shouldContain("[Remove Self Forwards");
output.shouldContain("[Restore RemSet");
output.shouldHaveExitValue(0);
}
static class GCTest {
@ -89,4 +129,19 @@ public class TestGCLogMessages {
System.out.println("Done");
}
}
static class GCTestWithToSpaceExhaustion {
private static byte[] garbage;
private static byte[] largeObject;
public static void main(String [] args) {
largeObject = new byte[5*1024*1024];
System.out.println("Creating garbage");
// create 128MB of garbage. This should result in at least one GC,
// some of them with to-space exhaustion.
for (int i = 0; i < 1024; i++) {
garbage = new byte[128 * 1024];
}
System.out.println("Done");
}
}
}