8150630: Add logging for ParScanThreadState merge phase

Improve visibility of the per-thread scan state merge phase by adding appropriate logging.

Reviewed-by: jmasa, tbenson
This commit is contained in:
Thomas Schatzl 2016-02-26 13:02:30 +01:00
parent d00c7378d6
commit 6fe8d6e7de
5 changed files with 20 additions and 2 deletions

View File

@ -4594,6 +4594,12 @@ void G1CollectedHeap::enqueue_discovered_references(G1ParScanThreadStateSet* per
g1_policy()->phase_times()->record_ref_enq_time(ref_enq_time * 1000.0);
}
void G1CollectedHeap::merge_per_thread_state_info(G1ParScanThreadStateSet* per_thread_states) {
double merge_pss_time_start = os::elapsedTime();
per_thread_states->flush();
g1_policy()->phase_times()->record_merge_pss_time_ms((os::elapsedTime() - merge_pss_time_start) * 1000.0);
}
void G1CollectedHeap::pre_evacuate_collection_set() {
_expand_heap_after_alloc_failure = true;
_evacuation_failed = false;
@ -4696,7 +4702,7 @@ void G1CollectedHeap::post_evacuate_collection_set(EvacuationInfo& evacuation_in
_allocator->release_gc_alloc_regions(evacuation_info);
per_thread_states->flush();
merge_per_thread_state_info(per_thread_states);
record_obj_copy_mem_stats();

View File

@ -522,6 +522,9 @@ protected:
// after processing.
void enqueue_discovered_references(G1ParScanThreadStateSet* per_thread_states);
// Merges the information gathered on a per-thread basis for all worker threads
// during GC into global variables.
void merge_per_thread_state_info(G1ParScanThreadStateSet* per_thread_states);
public:
WorkGang* workers() const { return _workers; }

View File

@ -413,6 +413,7 @@ void G1GCPhaseTimes::print() {
_recorded_non_young_free_cset_time_ms));
log_trace(gc, phases)("%sYoung Free CSet: %.1lf ms", Indents[3], _recorded_young_free_cset_time_ms);
log_trace(gc, phases)("%sNon-Young Free CSet: %.1lf ms", Indents[3], _recorded_non_young_free_cset_time_ms);
print_stats(Indents[2], "Merge Per-Thread State", _recorded_merge_pss_time_ms);
if (_cur_verify_after_time_ms > 0.0) {
print_stats(Indents[2], "Verify After", _cur_verify_after_time_ms);
}

View File

@ -111,6 +111,8 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
double _recorded_preserve_cm_referents_time_ms;
double _recorded_merge_pss_time_ms;
double _recorded_young_free_cset_time_ms;
double _recorded_non_young_free_cset_time_ms;
@ -241,6 +243,10 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
_recorded_preserve_cm_referents_time_ms = time_ms;
}
void record_merge_pss_time_ms(double time_ms) {
_recorded_merge_pss_time_ms = time_ms;
}
void record_cur_collection_start_sec(double time_ms) {
_cur_collection_start_sec = time_ms;
}

View File

@ -23,7 +23,7 @@
/*
* @test TestGCLogMessages
* @bug 8035406 8027295 8035398 8019342 8027959 8048179 8027962 8069330 8076463
* @bug 8035406 8027295 8035398 8019342 8027959 8048179 8027962 8069330 8076463 8150630
* @summary Ensure the output for a minor GC with G1
* includes the expected necessary messages.
* @key gc
@ -88,6 +88,8 @@ public class TestGCLogMessages {
new LogMessageWithLevel("Humongous Register", Level.DEBUG),
// Preserve CM Referents
new LogMessageWithLevel("Preserve CM Refs", Level.DEBUG),
// Merge PSS
new LogMessageWithLevel("Merge Per-Thread State", Level.DEBUG),
};
void checkMessagesAtLevel(OutputAnalyzer output, LogMessageWithLevel messages[], Level level) throws Exception {