提交 e2dd879f 编写于 作者: B brutisso

7172279: G1: Clean up TraceGen0Time and TraceGen1Time data gathering

Summary: Simplify code, remove unused code, remove ExitAfterGCNum
Reviewed-by: huntch, johnc
上级 75a70ca5
...@@ -3930,12 +3930,6 @@ G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) { ...@@ -3930,12 +3930,6 @@ G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) {
gc_epilogue(false); gc_epilogue(false);
} }
if (ExitAfterGCNum > 0 && total_collections() == ExitAfterGCNum) {
gclog_or_tty->print_cr("Stopping after GC #%d", ExitAfterGCNum);
print_tracing_info();
vm_exit(-1);
}
} }
// The closing of the inner scope, immediately above, will complete // The closing of the inner scope, immediately above, will complete
......
...@@ -133,12 +133,7 @@ G1CollectorPolicy::G1CollectorPolicy() : ...@@ -133,12 +133,7 @@ G1CollectorPolicy::G1CollectorPolicy() :
? ParallelGCThreads : 1), ? ParallelGCThreads : 1),
_recent_gc_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), _recent_gc_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)),
_all_pause_times_ms(new NumberSeq()),
_stop_world_start(0.0), _stop_world_start(0.0),
_all_stop_world_times_ms(new NumberSeq()),
_all_yield_times_ms(new NumberSeq()),
_summary(new Summary()),
_cur_clear_ct_time_ms(0.0), _cur_clear_ct_time_ms(0.0),
_root_region_scan_wait_time_ms(0.0), _root_region_scan_wait_time_ms(0.0),
...@@ -154,12 +149,6 @@ G1CollectorPolicy::G1CollectorPolicy() : ...@@ -154,12 +149,6 @@ G1CollectorPolicy::G1CollectorPolicy() :
_num_cc_clears(0L), _num_cc_clears(0L),
#endif #endif
_aux_num(10),
_all_aux_times_ms(new NumberSeq[_aux_num]),
_cur_aux_start_times_ms(new double[_aux_num]),
_cur_aux_times_ms(new double[_aux_num]),
_cur_aux_times_set(new bool[_aux_num]),
_concurrent_mark_remark_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), _concurrent_mark_remark_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)),
_concurrent_mark_cleanup_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)), _concurrent_mark_cleanup_times_ms(new TruncatedSeq(NumPrevPausesForHeuristics)),
...@@ -185,8 +174,6 @@ G1CollectorPolicy::G1CollectorPolicy() : ...@@ -185,8 +174,6 @@ G1CollectorPolicy::G1CollectorPolicy() :
_pause_time_target_ms((double) MaxGCPauseMillis), _pause_time_target_ms((double) MaxGCPauseMillis),
_gcs_are_young(true), _gcs_are_young(true),
_young_pause_num(0),
_mixed_pause_num(0),
_during_marking(false), _during_marking(false),
_in_marking_window(false), _in_marking_window(false),
...@@ -197,8 +184,6 @@ G1CollectorPolicy::G1CollectorPolicy() : ...@@ -197,8 +184,6 @@ G1CollectorPolicy::G1CollectorPolicy() :
_recent_avg_pause_time_ratio(0.0), _recent_avg_pause_time_ratio(0.0),
_all_full_gc_times_ms(new NumberSeq()),
_initiate_conc_mark_if_possible(false), _initiate_conc_mark_if_possible(false),
_during_initial_mark_pause(false), _during_initial_mark_pause(false),
_last_young_gc(false), _last_young_gc(false),
...@@ -851,7 +836,7 @@ void G1CollectorPolicy::record_full_collection_end() { ...@@ -851,7 +836,7 @@ void G1CollectorPolicy::record_full_collection_end() {
double full_gc_time_sec = end_sec - _cur_collection_start_sec; double full_gc_time_sec = end_sec - _cur_collection_start_sec;
double full_gc_time_ms = full_gc_time_sec * 1000.0; double full_gc_time_ms = full_gc_time_sec * 1000.0;
_all_full_gc_times_ms->add(full_gc_time_ms); _trace_gen1_time_data.record_full_collection(full_gc_time_ms);
update_recent_gc_times(end_sec, full_gc_time_ms); update_recent_gc_times(end_sec, full_gc_time_ms);
...@@ -900,7 +885,7 @@ void G1CollectorPolicy::record_collection_pause_start(double start_time_sec, ...@@ -900,7 +885,7 @@ void G1CollectorPolicy::record_collection_pause_start(double start_time_sec,
_g1->used(), _g1->recalculate_used())); _g1->used(), _g1->recalculate_used()));
double s_w_t_ms = (start_time_sec - _stop_world_start) * 1000.0; double s_w_t_ms = (start_time_sec - _stop_world_start) * 1000.0;
_all_stop_world_times_ms->add(s_w_t_ms); _trace_gen0_time_data.record_start_collection(s_w_t_ms);
_stop_world_start = 0.0; _stop_world_start = 0.0;
_cur_collection_start_sec = start_time_sec; _cur_collection_start_sec = start_time_sec;
...@@ -937,11 +922,6 @@ void G1CollectorPolicy::record_collection_pause_start(double start_time_sec, ...@@ -937,11 +922,6 @@ void G1CollectorPolicy::record_collection_pause_start(double start_time_sec,
} }
#endif #endif
for (int i = 0; i < _aux_num; ++i) {
_cur_aux_times_ms[i] = 0.0;
_cur_aux_times_set[i] = false;
}
// This is initialized to zero here and is set during the evacuation // This is initialized to zero here and is set during the evacuation
// pause if we actually waited for the root region scanning to finish. // pause if we actually waited for the root region scanning to finish.
_root_region_scan_wait_time_ms = 0.0; _root_region_scan_wait_time_ms = 0.0;
...@@ -990,7 +970,7 @@ void G1CollectorPolicy::record_concurrent_mark_cleanup_completed() { ...@@ -990,7 +970,7 @@ void G1CollectorPolicy::record_concurrent_mark_cleanup_completed() {
void G1CollectorPolicy::record_concurrent_pause() { void G1CollectorPolicy::record_concurrent_pause() {
if (_stop_world_start > 0.0) { if (_stop_world_start > 0.0) {
double yield_ms = (os::elapsedTime() - _stop_world_start) * 1000.0; double yield_ms = (os::elapsedTime() - _stop_world_start) * 1000.0;
_all_yield_times_ms->add(yield_ms); _trace_gen0_time_data.record_yield_time(yield_ms);
} }
} }
...@@ -1197,21 +1177,6 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) { ...@@ -1197,21 +1177,6 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) {
_mmu_tracker->add_pause(end_time_sec - elapsed_ms/1000.0, _mmu_tracker->add_pause(end_time_sec - elapsed_ms/1000.0,
end_time_sec, false); end_time_sec, false);
// This assert is exempted when we're doing parallel collection pauses,
// because the fragmentation caused by the parallel GC allocation buffers
// can lead to more memory being used during collection than was used
// before. Best leave this out until the fragmentation problem is fixed.
// Pauses in which evacuation failed can also lead to negative
// collections, since no space is reclaimed from a region containing an
// object whose evacuation failed.
// Further, we're now always doing parallel collection. But I'm still
// leaving this here as a placeholder for a more precise assertion later.
// (DLD, 10/05.)
assert((true || parallel) // Always using GC LABs now.
|| _g1->evacuation_failed()
|| _cur_collection_pause_used_at_start_bytes >= cur_used_bytes,
"Negative collection");
size_t freed_bytes = size_t freed_bytes =
_cur_collection_pause_used_at_start_bytes - cur_used_bytes; _cur_collection_pause_used_at_start_bytes - cur_used_bytes;
size_t surviving_bytes = _collection_set_bytes_used_before - freed_bytes; size_t surviving_bytes = _collection_set_bytes_used_before - freed_bytes;
...@@ -1259,44 +1224,15 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) { ...@@ -1259,44 +1224,15 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) {
other_time_ms -= _cur_clear_ct_time_ms; other_time_ms -= _cur_clear_ct_time_ms;
// TraceGen0Time and TraceGen1Time summary info updating. // TraceGen0Time and TraceGen1Time summary info updating.
_all_pause_times_ms->add(elapsed_ms);
if (update_stats) { if (update_stats) {
_summary->record_total_time_ms(elapsed_ms);
_summary->record_other_time_ms(other_time_ms);
MainBodySummary* body_summary = _summary->main_body_summary();
assert(body_summary != NULL, "should not be null!");
body_summary->record_root_region_scan_wait_time_ms(
_root_region_scan_wait_time_ms);
body_summary->record_ext_root_scan_time_ms(ext_root_scan_time);
body_summary->record_satb_filtering_time_ms(satb_filtering_time);
body_summary->record_update_rs_time_ms(update_rs_time);
body_summary->record_scan_rs_time_ms(scan_rs_time);
body_summary->record_obj_copy_time_ms(obj_copy_time);
if (parallel) {
body_summary->record_parallel_time_ms(_cur_collection_par_time_ms);
body_summary->record_termination_time_ms(termination_time);
double parallel_known_time = known_time + termination_time; double parallel_known_time = known_time + termination_time;
double parallel_other_time = _cur_collection_par_time_ms - parallel_known_time; double parallel_other_time = _cur_collection_par_time_ms - parallel_known_time;
body_summary->record_parallel_other_time_ms(parallel_other_time);
}
body_summary->record_clear_ct_time_ms(_cur_clear_ct_time_ms); _trace_gen0_time_data.record_end_collection(
elapsed_ms, other_time_ms, _root_region_scan_wait_time_ms, _cur_collection_par_time_ms,
// We exempt parallel collection from this check because Alloc Buffer ext_root_scan_time, satb_filtering_time, update_rs_time, scan_rs_time, obj_copy_time,
// fragmentation can produce negative collections. Same with evac termination_time, parallel_other_time, _cur_clear_ct_time_ms);
// failure.
// Further, we're now always doing parallel collection. But I'm still
// leaving this here as a placeholder for a more precise assertion later.
// (DLD, 10/05.
assert((true || parallel)
|| _g1->evacuation_failed()
|| surviving_bytes <= _collection_set_bytes_used_before,
"Or else negative collection!");
// this is where we update the allocation rate of the application // this is where we update the allocation rate of the application
double app_time_ms = double app_time_ms =
...@@ -1349,12 +1285,6 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) { ...@@ -1349,12 +1285,6 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) {
} }
} }
for (int i = 0; i < _aux_num; ++i) {
if (_cur_aux_times_set[i]) {
_all_aux_times_ms[i].add(_cur_aux_times_ms[i]);
}
}
if (G1Log::finer()) { if (G1Log::finer()) {
bool print_marking_info = bool print_marking_info =
_g1->mark_in_progress() && !last_pause_included_initial_mark; _g1->mark_in_progress() && !last_pause_included_initial_mark;
...@@ -1436,14 +1366,6 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) { ...@@ -1436,14 +1366,6 @@ void G1CollectorPolicy::record_collection_pause_end(int no_of_gc_threads) {
print_stats(2, "Free CSet", print_stats(2, "Free CSet",
(_recorded_young_free_cset_time_ms + (_recorded_young_free_cset_time_ms +
_recorded_non_young_free_cset_time_ms)); _recorded_non_young_free_cset_time_ms));
for (int i = 0; i < _aux_num; ++i) {
if (_cur_aux_times_set[i]) {
char buffer[96];
sprintf(buffer, "Aux%d", i);
print_stats(1, buffer, _cur_aux_times_ms[i]);
}
}
} }
bool new_in_marking_window = _in_marking_window; bool new_in_marking_window = _in_marking_window;
...@@ -1808,179 +1730,9 @@ void G1CollectorPolicy::count_CS_bytes_used() { ...@@ -1808,179 +1730,9 @@ void G1CollectorPolicy::count_CS_bytes_used() {
_g1->collection_set_iterate(&cs_closure); _g1->collection_set_iterate(&cs_closure);
} }
void G1CollectorPolicy::print_summary(int level,
const char* str,
NumberSeq* seq) const {
double sum = seq->sum();
LineBuffer(level + 1).append_and_print_cr("%-24s = %8.2lf s (avg = %8.2lf ms)",
str, sum / 1000.0, seq->avg());
}
void G1CollectorPolicy::print_summary_sd(int level,
const char* str,
NumberSeq* seq) const {
print_summary(level, str, seq);
LineBuffer(level + 6).append_and_print_cr("(num = %5d, std dev = %8.2lf ms, max = %8.2lf ms)",
seq->num(), seq->sd(), seq->maximum());
}
void G1CollectorPolicy::check_other_times(int level,
NumberSeq* other_times_ms,
NumberSeq* calc_other_times_ms) const {
bool should_print = false;
LineBuffer buf(level + 2);
double max_sum = MAX2(fabs(other_times_ms->sum()),
fabs(calc_other_times_ms->sum()));
double min_sum = MIN2(fabs(other_times_ms->sum()),
fabs(calc_other_times_ms->sum()));
double sum_ratio = max_sum / min_sum;
if (sum_ratio > 1.1) {
should_print = true;
buf.append_and_print_cr("## CALCULATED OTHER SUM DOESN'T MATCH RECORDED ###");
}
double max_avg = MAX2(fabs(other_times_ms->avg()),
fabs(calc_other_times_ms->avg()));
double min_avg = MIN2(fabs(other_times_ms->avg()),
fabs(calc_other_times_ms->avg()));
double avg_ratio = max_avg / min_avg;
if (avg_ratio > 1.1) {
should_print = true;
buf.append_and_print_cr("## CALCULATED OTHER AVG DOESN'T MATCH RECORDED ###");
}
if (other_times_ms->sum() < -0.01) {
buf.append_and_print_cr("## RECORDED OTHER SUM IS NEGATIVE ###");
}
if (other_times_ms->avg() < -0.01) {
buf.append_and_print_cr("## RECORDED OTHER AVG IS NEGATIVE ###");
}
if (calc_other_times_ms->sum() < -0.01) {
should_print = true;
buf.append_and_print_cr("## CALCULATED OTHER SUM IS NEGATIVE ###");
}
if (calc_other_times_ms->avg() < -0.01) {
should_print = true;
buf.append_and_print_cr("## CALCULATED OTHER AVG IS NEGATIVE ###");
}
if (should_print)
print_summary(level, "Other(Calc)", calc_other_times_ms);
}
void G1CollectorPolicy::print_summary(PauseSummary* summary) const {
bool parallel = G1CollectedHeap::use_parallel_gc_threads();
MainBodySummary* body_summary = summary->main_body_summary();
if (summary->get_total_seq()->num() > 0) {
print_summary_sd(0, "Evacuation Pauses", summary->get_total_seq());
if (body_summary != NULL) {
print_summary(1, "Root Region Scan Wait", body_summary->get_root_region_scan_wait_seq());
if (parallel) {
print_summary(1, "Parallel Time", body_summary->get_parallel_seq());
print_summary(2, "Ext Root Scanning", body_summary->get_ext_root_scan_seq());
print_summary(2, "SATB Filtering", body_summary->get_satb_filtering_seq());
print_summary(2, "Update RS", body_summary->get_update_rs_seq());
print_summary(2, "Scan RS", body_summary->get_scan_rs_seq());
print_summary(2, "Object Copy", body_summary->get_obj_copy_seq());
print_summary(2, "Termination", body_summary->get_termination_seq());
print_summary(2, "Parallel Other", body_summary->get_parallel_other_seq());
{
NumberSeq* other_parts[] = {
body_summary->get_ext_root_scan_seq(),
body_summary->get_satb_filtering_seq(),
body_summary->get_update_rs_seq(),
body_summary->get_scan_rs_seq(),
body_summary->get_obj_copy_seq(),
body_summary->get_termination_seq()
};
NumberSeq calc_other_times_ms(body_summary->get_parallel_seq(),
6, other_parts);
check_other_times(2, body_summary->get_parallel_other_seq(),
&calc_other_times_ms);
}
} else {
print_summary(1, "Ext Root Scanning", body_summary->get_ext_root_scan_seq());
print_summary(1, "SATB Filtering", body_summary->get_satb_filtering_seq());
print_summary(1, "Update RS", body_summary->get_update_rs_seq());
print_summary(1, "Scan RS", body_summary->get_scan_rs_seq());
print_summary(1, "Object Copy", body_summary->get_obj_copy_seq());
}
}
print_summary(1, "Clear CT", body_summary->get_clear_ct_seq());
print_summary(1, "Other", summary->get_other_seq());
{
if (body_summary != NULL) {
NumberSeq calc_other_times_ms;
if (parallel) {
// parallel
NumberSeq* other_parts[] = {
body_summary->get_root_region_scan_wait_seq(),
body_summary->get_parallel_seq(),
body_summary->get_clear_ct_seq()
};
calc_other_times_ms = NumberSeq(summary->get_total_seq(),
3, other_parts);
} else {
// serial
NumberSeq* other_parts[] = {
body_summary->get_root_region_scan_wait_seq(),
body_summary->get_update_rs_seq(),
body_summary->get_ext_root_scan_seq(),
body_summary->get_satb_filtering_seq(),
body_summary->get_scan_rs_seq(),
body_summary->get_obj_copy_seq()
};
calc_other_times_ms = NumberSeq(summary->get_total_seq(),
6, other_parts);
}
check_other_times(1, summary->get_other_seq(), &calc_other_times_ms);
}
}
} else {
LineBuffer(1).append_and_print_cr("none");
}
LineBuffer(0).append_and_print_cr("");
}
void G1CollectorPolicy::print_tracing_info() const { void G1CollectorPolicy::print_tracing_info() const {
if (TraceGen0Time) { _trace_gen0_time_data.print();
gclog_or_tty->print_cr("ALL PAUSES"); _trace_gen1_time_data.print();
print_summary_sd(0, "Total", _all_pause_times_ms);
gclog_or_tty->print_cr("");
gclog_or_tty->print_cr("");
gclog_or_tty->print_cr(" Young GC Pauses: %8d", _young_pause_num);
gclog_or_tty->print_cr(" Mixed GC Pauses: %8d", _mixed_pause_num);
gclog_or_tty->print_cr("");
gclog_or_tty->print_cr("EVACUATION PAUSES");
print_summary(_summary);
gclog_or_tty->print_cr("MISC");
print_summary_sd(0, "Stop World", _all_stop_world_times_ms);
print_summary_sd(0, "Yields", _all_yield_times_ms);
for (int i = 0; i < _aux_num; ++i) {
if (_all_aux_times_ms[i].num() > 0) {
char buffer[96];
sprintf(buffer, "Aux%d", i);
print_summary_sd(0, buffer, &_all_aux_times_ms[i]);
}
}
}
if (TraceGen1Time) {
if (_all_full_gc_times_ms->num() > 0) {
gclog_or_tty->print("\n%4d full_gcs: total time = %8.2f s",
_all_full_gc_times_ms->num(),
_all_full_gc_times_ms->sum() / 1000.0);
gclog_or_tty->print_cr(" (avg = %8.2fms).", _all_full_gc_times_ms->avg());
gclog_or_tty->print_cr(" [std. dev = %8.2f ms, max = %8.2f ms]",
_all_full_gc_times_ms->sd(),
_all_full_gc_times_ms->maximum());
}
}
} }
void G1CollectorPolicy::print_yg_surv_rate_info() const { void G1CollectorPolicy::print_yg_surv_rate_info() const {
...@@ -2531,9 +2283,9 @@ void G1CollectorPolicy::finalize_cset(double target_pause_time_ms) { ...@@ -2531,9 +2283,9 @@ void G1CollectorPolicy::finalize_cset(double target_pause_time_ms) {
_last_gc_was_young = gcs_are_young() ? true : false; _last_gc_was_young = gcs_are_young() ? true : false;
if (_last_gc_was_young) { if (_last_gc_was_young) {
++_young_pause_num; _trace_gen0_time_data.increment_young_collection_count();
} else { } else {
++_mixed_pause_num; _trace_gen0_time_data.increment_mixed_collection_count();
} }
// The young list is laid with the survivor regions from the previous // The young list is laid with the survivor regions from the previous
...@@ -2690,3 +2442,133 @@ void G1CollectorPolicy::finalize_cset(double target_pause_time_ms) { ...@@ -2690,3 +2442,133 @@ void G1CollectorPolicy::finalize_cset(double target_pause_time_ms) {
_recorded_non_young_cset_choice_time_ms = _recorded_non_young_cset_choice_time_ms =
(non_young_end_time_sec - non_young_start_time_sec) * 1000.0; (non_young_end_time_sec - non_young_start_time_sec) * 1000.0;
} }
void TraceGen0TimeData::record_start_collection(double time_to_stop_the_world_ms) {
if(TraceGen0Time) {
_all_stop_world_times_ms.add(time_to_stop_the_world_ms);
}
}
void TraceGen0TimeData::record_yield_time(double yield_time_ms) {
if(TraceGen0Time) {
_all_yield_times_ms.add(yield_time_ms);
}
}
void TraceGen0TimeData::record_end_collection(
double total_ms,
double other_ms,
double root_region_scan_wait_ms,
double parallel_ms,
double ext_root_scan_ms,
double satb_filtering_ms,
double update_rs_ms,
double scan_rs_ms,
double obj_copy_ms,
double termination_ms,
double parallel_other_ms,
double clear_ct_ms)
{
if(TraceGen0Time) {
_total.add(total_ms);
_other.add(other_ms);
_root_region_scan_wait.add(root_region_scan_wait_ms);
_parallel.add(parallel_ms);
_ext_root_scan.add(ext_root_scan_ms);
_satb_filtering.add(satb_filtering_ms);
_update_rs.add(update_rs_ms);
_scan_rs.add(scan_rs_ms);
_obj_copy.add(obj_copy_ms);
_termination.add(termination_ms);
_parallel_other.add(parallel_other_ms);
_clear_ct.add(clear_ct_ms);
}
}
void TraceGen0TimeData::increment_young_collection_count() {
if(TraceGen0Time) {
++_young_pause_num;
}
}
void TraceGen0TimeData::increment_mixed_collection_count() {
if(TraceGen0Time) {
++_mixed_pause_num;
}
}
void TraceGen0TimeData::print_summary(int level,
const char* str,
const NumberSeq* seq) const {
double sum = seq->sum();
LineBuffer(level + 1).append_and_print_cr("%-24s = %8.2lf s (avg = %8.2lf ms)",
str, sum / 1000.0, seq->avg());
}
void TraceGen0TimeData::print_summary_sd(int level,
const char* str,
const NumberSeq* seq) const {
print_summary(level, str, seq);
LineBuffer(level + 6).append_and_print_cr("(num = %5d, std dev = %8.2lf ms, max = %8.2lf ms)",
seq->num(), seq->sd(), seq->maximum());
}
void TraceGen0TimeData::print() const {
if (!TraceGen0Time) {
return;
}
gclog_or_tty->print_cr("ALL PAUSES");
print_summary_sd(0, "Total", &_total);
gclog_or_tty->print_cr("");
gclog_or_tty->print_cr("");
gclog_or_tty->print_cr(" Young GC Pauses: %8d", _young_pause_num);
gclog_or_tty->print_cr(" Mixed GC Pauses: %8d", _mixed_pause_num);
gclog_or_tty->print_cr("");
gclog_or_tty->print_cr("EVACUATION PAUSES");
if (_young_pause_num == 0 && _mixed_pause_num == 0) {
gclog_or_tty->print_cr("none");
} else {
print_summary_sd(0, "Evacuation Pauses", &_total);
print_summary(1, "Root Region Scan Wait", &_root_region_scan_wait);
print_summary(1, "Parallel Time", &_parallel);
print_summary(2, "Ext Root Scanning", &_ext_root_scan);
print_summary(2, "SATB Filtering", &_satb_filtering);
print_summary(2, "Update RS", &_update_rs);
print_summary(2, "Scan RS", &_scan_rs);
print_summary(2, "Object Copy", &_obj_copy);
print_summary(2, "Termination", &_termination);
print_summary(2, "Parallel Other", &_parallel_other);
print_summary(1, "Clear CT", &_clear_ct);
print_summary(1, "Other", &_other);
}
gclog_or_tty->print_cr("");
gclog_or_tty->print_cr("MISC");
print_summary_sd(0, "Stop World", &_all_stop_world_times_ms);
print_summary_sd(0, "Yields", &_all_yield_times_ms);
}
void TraceGen1TimeData::record_full_collection(double full_gc_time_ms) {
if (TraceGen1Time) {
_all_full_gc_times.add(full_gc_time_ms);
}
}
void TraceGen1TimeData::print() const {
if (!TraceGen1Time) {
return;
}
if (_all_full_gc_times.num() > 0) {
gclog_or_tty->print("\n%4d full_gcs: total time = %8.2f s",
_all_full_gc_times.num(),
_all_full_gc_times.sum() / 1000.0);
gclog_or_tty->print_cr(" (avg = %8.2fms).", _all_full_gc_times.avg());
gclog_or_tty->print_cr(" [std. dev = %8.2f ms, max = %8.2f ms]",
_all_full_gc_times.sd(),
_all_full_gc_times.maximum());
}
}
...@@ -37,49 +37,62 @@ ...@@ -37,49 +37,62 @@
class HeapRegion; class HeapRegion;
class CollectionSetChooser; class CollectionSetChooser;
// Yes, this is a bit unpleasant... but it saves replicating the same thing // TraceGen0Time collects data on _both_ young and mixed evacuation pauses
// over and over again and introducing subtle problems through small typos and // (the latter may contain non-young regions - i.e. regions that are
// cutting and pasting mistakes. The macros below introduces a number // technically in Gen1) while TraceGen1Time collects data about full GCs.
// sequnce into the following two classes and the methods that access it. class TraceGen0TimeData : public CHeapObj {
private:
#define define_num_seq(name) \ unsigned _young_pause_num;
private: \ unsigned _mixed_pause_num;
NumberSeq _all_##name##_times_ms; \
public: \
void record_##name##_time_ms(double ms) { \
_all_##name##_times_ms.add(ms); \
} \
NumberSeq* get_##name##_seq() { \
return &_all_##name##_times_ms; \
}
class MainBodySummary;
class PauseSummary: public CHeapObj { NumberSeq _all_stop_world_times_ms;
define_num_seq(total) NumberSeq _all_yield_times_ms;
define_num_seq(other)
NumberSeq _total;
NumberSeq _other;
NumberSeq _root_region_scan_wait;
NumberSeq _parallel;
NumberSeq _ext_root_scan;
NumberSeq _satb_filtering;
NumberSeq _update_rs;
NumberSeq _scan_rs;
NumberSeq _obj_copy;
NumberSeq _termination;
NumberSeq _parallel_other;
NumberSeq _clear_ct;
void print_summary (int level, const char* str, const NumberSeq* seq) const;
void print_summary_sd (int level, const char* str, const NumberSeq* seq) const;
public: public:
virtual MainBodySummary* main_body_summary() { return NULL; } TraceGen0TimeData() : _young_pause_num(0), _mixed_pause_num(0) {};
void record_start_collection(double time_to_stop_the_world_ms);
void record_yield_time(double yield_time_ms);
void record_end_collection(
double total_ms,
double other_ms,
double root_region_scan_wait_ms,
double parallel_ms,
double ext_root_scan_ms,
double satb_filtering_ms,
double update_rs_ms,
double scan_rs_ms,
double obj_copy_ms,
double termination_ms,
double parallel_other_ms,
double clear_ct_ms);
void increment_young_collection_count();
void increment_mixed_collection_count();
void print() const;
}; };
class MainBodySummary: public CHeapObj { class TraceGen1TimeData : public CHeapObj {
define_num_seq(root_region_scan_wait) private:
define_num_seq(parallel) // parallel only NumberSeq _all_full_gc_times;
define_num_seq(ext_root_scan)
define_num_seq(satb_filtering)
define_num_seq(update_rs)
define_num_seq(scan_rs)
define_num_seq(obj_copy)
define_num_seq(termination) // parallel only
define_num_seq(parallel_other) // parallel only
define_num_seq(clear_ct)
};
class Summary: public PauseSummary, public:
public MainBodySummary { void record_full_collection(double full_gc_time_ms);
public: void print() const;
virtual MainBodySummary* main_body_summary() { return this; }
}; };
// There are three command line options related to the young gen size: // There are three command line options related to the young gen size:
...@@ -199,19 +212,10 @@ private: ...@@ -199,19 +212,10 @@ private:
TruncatedSeq* _concurrent_mark_remark_times_ms; TruncatedSeq* _concurrent_mark_remark_times_ms;
TruncatedSeq* _concurrent_mark_cleanup_times_ms; TruncatedSeq* _concurrent_mark_cleanup_times_ms;
Summary* _summary; TraceGen0TimeData _trace_gen0_time_data;
TraceGen1TimeData _trace_gen1_time_data;
NumberSeq* _all_pause_times_ms;
NumberSeq* _all_full_gc_times_ms;
double _stop_world_start; double _stop_world_start;
NumberSeq* _all_stop_world_times_ms;
NumberSeq* _all_yield_times_ms;
int _aux_num;
NumberSeq* _all_aux_times_ms;
double* _cur_aux_start_times_ms;
double* _cur_aux_times_ms;
bool* _cur_aux_times_set;
double* _par_last_gc_worker_start_times_ms; double* _par_last_gc_worker_start_times_ms;
double* _par_last_ext_root_scan_times_ms; double* _par_last_ext_root_scan_times_ms;
...@@ -243,9 +247,6 @@ private: ...@@ -243,9 +247,6 @@ private:
bool _last_gc_was_young; bool _last_gc_was_young;
unsigned _young_pause_num;
unsigned _mixed_pause_num;
bool _during_marking; bool _during_marking;
bool _in_marking_window; bool _in_marking_window;
bool _in_marking_window_im; bool _in_marking_window_im;
...@@ -557,15 +558,6 @@ private: ...@@ -557,15 +558,6 @@ private:
void print_par_stats(int level, const char* str, double* data, bool showDecimals = true); void print_par_stats(int level, const char* str, double* data, bool showDecimals = true);
void check_other_times(int level,
NumberSeq* other_times_ms,
NumberSeq* calc_other_times_ms) const;
void print_summary (PauseSummary* stats) const;
void print_summary (int level, const char* str, NumberSeq* seq) const;
void print_summary_sd (int level, const char* str, NumberSeq* seq) const;
double avg_value (double* data); double avg_value (double* data);
double max_value (double* data); double max_value (double* data);
double sum_of_values (double* data); double sum_of_values (double* data);
...@@ -745,10 +737,6 @@ public: ...@@ -745,10 +737,6 @@ public:
return _bytes_in_collection_set_before_gc; return _bytes_in_collection_set_before_gc;
} }
unsigned calc_gc_alloc_time_stamp() {
return _all_pause_times_ms->num() + 1;
}
// This should be called after the heap is resized. // This should be called after the heap is resized.
void record_new_heap_size(uint new_number_of_regions); void record_new_heap_size(uint new_number_of_regions);
...@@ -867,18 +855,6 @@ public: ...@@ -867,18 +855,6 @@ public:
_cur_collection_code_root_fixup_time_ms = ms; _cur_collection_code_root_fixup_time_ms = ms;
} }
void record_aux_start_time(int i) {
guarantee(i < _aux_num, "should be within range");
_cur_aux_start_times_ms[i] = os::elapsedTime() * 1000.0;
}
void record_aux_end_time(int i) {
guarantee(i < _aux_num, "should be within range");
double ms = os::elapsedTime() * 1000.0 - _cur_aux_start_times_ms[i];
_cur_aux_times_set[i] = true;
_cur_aux_times_ms[i] += ms;
}
void record_ref_proc_time(double ms) { void record_ref_proc_time(double ms) {
_cur_ref_proc_time_ms = ms; _cur_ref_proc_time_ms = ms;
} }
......
...@@ -677,11 +677,6 @@ void GenCollectedHeap::do_collection(bool full, ...@@ -677,11 +677,6 @@ void GenCollectedHeap::do_collection(bool full,
#ifdef TRACESPINNING #ifdef TRACESPINNING
ParallelTaskTerminator::print_termination_counts(); ParallelTaskTerminator::print_termination_counts();
#endif #endif
if (ExitAfterGCNum > 0 && total_collections() == ExitAfterGCNum) {
tty->print_cr("Stopping after GC #%d", ExitAfterGCNum);
vm_exit(-1);
}
} }
HeapWord* GenCollectedHeap::satisfy_failed_allocation(size_t size, bool is_tlab) { HeapWord* GenCollectedHeap::satisfy_failed_allocation(size_t size, bool is_tlab) {
......
...@@ -3285,9 +3285,6 @@ class CommandLineFlags { ...@@ -3285,9 +3285,6 @@ class CommandLineFlags {
diagnostic(intx, VerifyGCLevel, 0, \ diagnostic(intx, VerifyGCLevel, 0, \
"Generation level at which to start +VerifyBefore/AfterGC") \ "Generation level at which to start +VerifyBefore/AfterGC") \
\ \
develop(uintx, ExitAfterGCNum, 0, \
"If non-zero, exit after this GC.") \
\
product(intx, MaxTenuringThreshold, 15, \ product(intx, MaxTenuringThreshold, 15, \
"Maximum value for tenuring threshold") \ "Maximum value for tenuring threshold") \
\ \
......
...@@ -115,24 +115,6 @@ bool NumberSeq::check_nums(NumberSeq *total, int n, NumberSeq **parts) { ...@@ -115,24 +115,6 @@ bool NumberSeq::check_nums(NumberSeq *total, int n, NumberSeq **parts) {
return true; return true;
} }
NumberSeq::NumberSeq(NumberSeq *total, int n, NumberSeq **parts) {
guarantee(check_nums(total, n, parts), "all seq lengths should match");
double sum = total->sum();
for (int i = 0; i < n; ++i) {
if (parts[i] != NULL)
sum -= parts[i]->sum();
}
_num = total->num();
_sum = sum;
// we do not calculate these...
_sum_of_squares = -1.0;
_maximum = -1.0;
_davg = -1.0;
_dvariance = -1.0;
}
void NumberSeq::add(double val) { void NumberSeq::add(double val) {
AbsSeq::add(val); AbsSeq::add(val);
......
...@@ -93,7 +93,6 @@ protected: ...@@ -93,7 +93,6 @@ protected:
public: public:
NumberSeq(double alpha = DEFAULT_ALPHA_VALUE); NumberSeq(double alpha = DEFAULT_ALPHA_VALUE);
NumberSeq(NumberSeq* total, int n_parts, NumberSeq** parts);
virtual void add(double val); virtual void add(double val);
virtual double maximum() const { return _maximum; } virtual double maximum() const { return _maximum; }
......
Markdown is supported
0% .
You are about to add 0 people to the discussion. Proceed with caution.
先完成此消息的编辑!
想要评论请 注册