This commit is contained in:
Joseph Provino 2016-02-27 00:07:03 +00:00
commit e87c6f1b09
8 changed files with 80 additions and 23 deletions

View File

@ -4395,6 +4395,8 @@ public:
{ }
void work(uint worker_id) {
G1GCParPhaseTimesTracker x(_g1h->g1_policy()->phase_times(), G1GCPhaseTimes::PreserveCMReferents, worker_id);
ResourceMark rm;
HandleMark hm;
@ -4458,13 +4460,8 @@ void G1CollectedHeap::process_weak_jni_handles() {
g1_policy()->phase_times()->record_ref_proc_time(ref_proc_time * 1000.0);
}
// Weak Reference processing during an evacuation pause (part 1).
void G1CollectedHeap::process_discovered_references(G1ParScanThreadStateSet* per_thread_states) {
double ref_proc_start = os::elapsedTime();
ReferenceProcessor* rp = _ref_processor_stw;
assert(rp->discovery_enabled(), "should have been enabled");
void G1CollectedHeap::preserve_cm_referents(G1ParScanThreadStateSet* per_thread_states) {
double preserve_cm_referents_start = os::elapsedTime();
// Any reference objects, in the collection set, that were 'discovered'
// by the CM ref processor should have already been copied (either by
// applying the external root copy closure to the discovered lists, or
@ -4492,9 +4489,18 @@ void G1CollectedHeap::process_discovered_references(G1ParScanThreadStateSet* per
per_thread_states,
no_of_gc_workers,
_task_queues);
workers()->run_task(&keep_cm_referents);
g1_policy()->phase_times()->record_preserve_cm_referents_time_ms((os::elapsedTime() - preserve_cm_referents_start) * 1000.0);
}
// Weak Reference processing during an evacuation pause (part 1).
void G1CollectedHeap::process_discovered_references(G1ParScanThreadStateSet* per_thread_states) {
double ref_proc_start = os::elapsedTime();
ReferenceProcessor* rp = _ref_processor_stw;
assert(rp->discovery_enabled(), "should have been enabled");
// Closure to test whether a referent is alive.
G1STWIsAliveClosure is_alive(this);
@ -4526,6 +4532,8 @@ void G1CollectedHeap::process_discovered_references(G1ParScanThreadStateSet* per
NULL,
_gc_timer_stw);
} else {
uint no_of_gc_workers = workers()->active_workers();
// Parallel reference processing
assert(rp->num_q() == no_of_gc_workers, "sanity");
assert(no_of_gc_workers <= rp->max_num_q(), "sanity");
@ -4583,6 +4591,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;
@ -4641,6 +4655,7 @@ void G1CollectedHeap::post_evacuate_collection_set(EvacuationInfo& evacuation_in
// objects (and their reachable sub-graphs) that were
// not copied during the pause.
if (g1_policy()->should_process_references()) {
preserve_cm_referents(per_thread_states);
process_discovered_references(per_thread_states);
} else {
ref_processor_stw()->verify_no_references_recorded();
@ -4684,7 +4699,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

@ -511,6 +511,9 @@ protected:
// allocated block, or else "NULL".
HeapWord* expand_and_allocate(size_t word_size, AllocationContext_t context);
// Preserve any referents discovered by concurrent marking that have not yet been
// copied by the STW pause.
void preserve_cm_referents(G1ParScanThreadStateSet* per_thread_states);
// Process any reference objects discovered during
// an incremental evacuation pause.
void process_discovered_references(G1ParScanThreadStateSet* per_thread_states);
@ -519,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

@ -1,5 +1,5 @@
/*
* Copyright (c) 2013, 2015, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2013, 2016, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -129,6 +129,8 @@ G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
_gc_par_phases[RedirtyCards] = new WorkerDataArray<double>(max_gc_threads, "Parallel Redirty:", true, 3);
_redirtied_cards = new WorkerDataArray<size_t>(max_gc_threads, "Redirtied Cards:", true, 3);
_gc_par_phases[RedirtyCards]->link_thread_work_items(_redirtied_cards);
_gc_par_phases[PreserveCMReferents] = new WorkerDataArray<double>(max_gc_threads, "Parallel Preserve CM Refs:", true, 3);
}
void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) {
@ -392,10 +394,12 @@ void G1GCPhaseTimes::print() {
print_stats(Indents[2], "Choose CSet",
(_recorded_young_cset_choice_time_ms +
_recorded_non_young_cset_choice_time_ms));
print_stats(Indents[2], "Preserve CM Refs", _recorded_preserve_cm_referents_time_ms);
print_stats(Indents[2], "Ref Proc", _cur_ref_proc_time_ms);
print_stats(Indents[2], "Ref Enq", _cur_ref_enq_time_ms);
print_stats(Indents[2], "Redirty Cards", _recorded_redirty_logged_cards_time_ms);
par_phase_printer.print(RedirtyCards);
par_phase_printer.print(PreserveCMReferents);
if (G1EagerReclaimHumongousObjects) {
print_stats(Indents[2], "Humongous Register", _cur_fast_reclaim_humongous_register_time_ms);
@ -409,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

@ -1,5 +1,5 @@
/*
* Copyright (c) 2013, 2015, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2013, 2016, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -69,6 +69,7 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
StringDedupQueueFixup,
StringDedupTableFixup,
RedirtyCards,
PreserveCMReferents,
GCParPhasesSentinel
};
@ -108,6 +109,10 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
double _recorded_redirty_logged_cards_time_ms;
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;
@ -234,6 +239,14 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
_recorded_redirty_logged_cards_time_ms = time_ms;
}
void record_preserve_cm_referents_time_ms(double time_ms) {
_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

@ -1,5 +1,5 @@
/*
* Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2015, 2016, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -47,14 +47,16 @@ void G1IHOPControl::update_allocation_info(double allocation_time_s, size_t allo
void G1IHOPControl::print() {
size_t cur_conc_mark_start_threshold = get_conc_mark_start_threshold();
log_debug(gc, ihop)("Basic information (value update), threshold: " SIZE_FORMAT "B (%1.2f), target occupancy: " SIZE_FORMAT "B, current occupancy: " SIZE_FORMAT "B,"
" recent old gen allocation rate: %1.2f, recent marking phase length: %1.2f",
log_debug(gc, ihop)("Basic information (value update), threshold: " SIZE_FORMAT "B (%1.2f), target occupancy: " SIZE_FORMAT "B, current occupancy: " SIZE_FORMAT "B, "
"recent allocation size: " SIZE_FORMAT "B, recent allocation duration: %1.2fms, recent old gen allocation rate: %1.2fB/s, recent marking phase length: %1.2fms",
cur_conc_mark_start_threshold,
cur_conc_mark_start_threshold * 100.0 / _target_occupancy,
_target_occupancy,
G1CollectedHeap::heap()->used(),
_last_allocated_bytes,
_last_allocation_time_s * 1000.0,
_last_allocation_time_s > 0.0 ? _last_allocated_bytes / _last_allocation_time_s : 0.0,
last_marking_length_s());
last_marking_length_s() * 1000.0);
}
void G1IHOPControl::send_trace_event(G1NewTracer* tracer) {
@ -191,13 +193,16 @@ void G1AdaptiveIHOPControl::update_marking_length(double marking_length_s) {
void G1AdaptiveIHOPControl::print() {
G1IHOPControl::print();
size_t actual_target = actual_target_threshold();
log_debug(gc, ihop)("Adaptive IHOP information (value update), threshold: " SIZE_FORMAT "B (%1.2f), internal target occupancy: " SIZE_FORMAT "B,"
" predicted old gen allocation rate: %1.2f, predicted marking phase length: %1.2f, prediction active: %s",
log_debug(gc, ihop)("Adaptive IHOP information (value update), threshold: " SIZE_FORMAT "B (%1.2f), internal target occupancy: " SIZE_FORMAT "B, "
"occupancy: " SIZE_FORMAT "B, additional buffer size: " SIZE_FORMAT "B, predicted old gen allocation rate: %1.2fB/s, "
"predicted marking phase length: %1.2fms, prediction active: %s",
get_conc_mark_start_threshold(),
percent_of(get_conc_mark_start_threshold(), actual_target),
actual_target,
G1CollectedHeap::heap()->used(),
_last_unrestrained_young_size,
_predictor->get_new_prediction(&_allocation_rate_s),
_predictor->get_new_prediction(&_marking_times_s),
_predictor->get_new_prediction(&_marking_times_s) * 1000.0,
have_enough_data_for_prediction() ? "true" : "false");
}

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2014, 2015, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2014, 2016, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -327,6 +327,9 @@ oop G1ParScanThreadState::copy_to_survivor_space(InCSetState const state,
G1ParScanThreadState* G1ParScanThreadStateSet::state_for_worker(uint worker_id) {
assert(worker_id < _n_workers, "out of bounds access");
if (_states[worker_id] == NULL) {
_states[worker_id] = new_par_scan_state(worker_id, _young_cset_length);
}
return _states[worker_id];
}
@ -352,6 +355,10 @@ void G1ParScanThreadStateSet::flush() {
for (uint worker_index = 0; worker_index < _n_workers; ++worker_index) {
G1ParScanThreadState* pss = _states[worker_index];
if (pss == NULL) {
continue;
}
_total_cards_scanned += _cards_scanned[worker_index];
pss->flush(_surviving_young_words_total);

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2014, 2015, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2014, 2016, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -200,6 +200,7 @@ class G1ParScanThreadStateSet : public StackObj {
size_t* _surviving_young_words_total;
size_t* _cards_scanned;
size_t _total_cards_scanned;
size_t _young_cset_length;
uint _n_workers;
bool _flushed;
@ -210,10 +211,11 @@ class G1ParScanThreadStateSet : public StackObj {
_surviving_young_words_total(NEW_C_HEAP_ARRAY(size_t, young_cset_length, mtGC)),
_cards_scanned(NEW_C_HEAP_ARRAY(size_t, n_workers, mtGC)),
_total_cards_scanned(0),
_young_cset_length(young_cset_length),
_n_workers(n_workers),
_flushed(false) {
for (uint i = 0; i < n_workers; ++i) {
_states[i] = new_par_scan_state(i, young_cset_length);
_states[i] = NULL;
}
memset(_surviving_young_words_total, 0, young_cset_length * sizeof(size_t));
memset(_cards_scanned, 0, n_workers * sizeof(size_t));

View File

@ -1,5 +1,5 @@
/*
* Copyright (c) 2014, 2015, Oracle and/or its affiliates. All rights reserved.
* Copyright (c) 2014, 2016, Oracle and/or its affiliates. All rights reserved.
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
*
* This code is free software; you can redistribute it and/or modify it
@ -23,7 +23,7 @@
/*
* @test TestGCLogMessages
* @bug 8035406 8027295 8035398 8019342 8027959 8048179 8027962 8069330
* @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
@ -86,6 +86,10 @@ public class TestGCLogMessages {
// Humongous Eager Reclaim
new LogMessageWithLevel("Humongous Reclaim", Level.DEBUG),
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 {