archive/jdk
1
0
Fork 0
mirror of https://github.com/openjdk/jdk.git synced 2025-09-20 11:04:34 +02:00
Code Issues Projects Releases Packages Wiki Activity Actions

8148734: G1: Make G1GCPhaseTimes keep track of the start GC time

Browse source 
Reviewed-by: sjohanss, tschatzl
This commit is contained in:
Bengt Rutisson 2016-02-02 10:50:08 +01:00
parent de76c23ff5
commit a5e2b096bc
6 changed files with 15 additions and 12 deletions
Download patch file Download diff file Expand all files Collapse all files

8
hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp
View file

@ -3169,13 +3169,12 @@ void G1CollectedHeap::reset_taskqueue_stats() {
}
#endif // TASKQUEUE_STATS
void G1CollectedHeap::log_gc_footer(jlong pause_time_counter) {
void G1CollectedHeap::log_gc_footer() {
if (evacuation_failed()) {
log_info(gc)("To-space exhausted");
}
double pause_time_ms = TimeHelper::counter_to_millis(pause_time_counter);
g1_policy()->print_phases(pause_time_ms);
g1_policy()->print_phases();
g1_policy()->print_detailed_heap_transition();
}
@ -3267,7 +3266,6 @@ G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) {
}
GCTraceTime(Info, gc) tm(gc_string, NULL, gc_cause(), true);
jlong pause_start_counter = os::elapsed_counter();
g1_policy()->note_gc_start(active_workers);
TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
@ -3529,7 +3527,7 @@ G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) {
}
// Print the remainder of the GC log output.
log_gc_footer(os::elapsed_counter() - pause_start_counter);
log_gc_footer();
// It is not yet to safe to tell the concurrent mark to
// start as we have some optional output below. We don't want the

2
hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp
View file

@ -291,7 +291,7 @@ private:
size_t size,
size_t translation_factor);
void log_gc_footer(jlong pause_time_counter);
void log_gc_footer();
void trace_heap(GCWhen::Type when, const GCTracer* tracer);

4
hotspot/src/share/vm/gc/g1/g1CollectorPolicy.cpp
View file

@ -1303,8 +1303,8 @@ void G1CollectorPolicy::print_detailed_heap_transition() const {
MetaspaceAux::print_metaspace_change(_metaspace_used_bytes_before_gc);
}
void G1CollectorPolicy::print_phases(double pause_time_ms) {
phase_times()->print(pause_time_ms);
void G1CollectorPolicy::print_phases() {
phase_times()->print();
}
void G1CollectorPolicy::adjust_concurrent_refinement(double update_rs_time,

2
hotspot/src/share/vm/gc/g1/g1CollectorPolicy.hpp
View file

@ -662,7 +662,7 @@ public:
void print_detailed_heap_transition() const;
virtual void print_phases(double pause_time_ms);
virtual void print_phases();
void record_stop_world_start();
void record_concurrent_pause();

7
hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp
View file

@ -30,6 +30,7 @@
#include "gc/g1/workerDataArray.inline.hpp"
#include "memory/allocation.hpp"
#include "logging/log.hpp"
#include "runtime/timer.hpp"
#include "runtime/os.hpp"
// Helper class for avoiding interleaved logging
@ -133,6 +134,7 @@ G1GCPhaseTimes::G1GCPhaseTimes(uint max_gc_threads) :
void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) {
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");
_gc_start_counter = os::elapsed_counter();
_active_gc_threads = active_gc_threads;
_cur_expand_heap_time_ms = 0.0;
_external_accounted_time_ms = 0.0;
@ -146,6 +148,7 @@ void G1GCPhaseTimes::note_gc_start(uint active_gc_threads) {
}
void G1GCPhaseTimes::note_gc_end() {
_gc_pause_time_ms = TimeHelper::counter_to_millis(os::elapsed_counter() - _gc_start_counter);
for (uint i = 0; i < _active_gc_threads; i++) {
double worker_time = _gc_par_phases[GCWorkerEnd]->get(i) - _gc_par_phases[GCWorkerStart]->get(i);
record_time_secs(GCWorkerTotal, i , worker_time);
@ -349,7 +352,7 @@ class G1GCParPhasePrinter : public StackObj {
}
};
void G1GCPhaseTimes::print(double pause_time_ms) {
void G1GCPhaseTimes::print() {
note_gc_end();
G1GCParPhasePrinter par_phase_printer(this);
@ -373,7 +376,7 @@ void G1GCPhaseTimes::print(double pause_time_ms) {
}
print_stats(Indents[1], "Clear CT", _cur_clear_ct_time_ms);
print_stats(Indents[1], "Expand Heap After Collection", _cur_expand_heap_time_ms);
double misc_time_ms = pause_time_ms - accounted_time_ms();
double misc_time_ms = _gc_pause_time_ms - accounted_time_ms();
print_stats(Indents[1], "Other", misc_time_ms);
if (_cur_verify_before_time_ms > 0.0) {
print_stats(Indents[2], "Verify Before", _cur_verify_before_time_ms);

4
hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp
View file

@ -36,6 +36,8 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
uint _active_gc_threads;
uint _max_gc_threads;
jlong _gc_start_counter;
double _gc_pause_time_ms;
public:
enum GCParPhases {
@ -126,7 +128,7 @@ class G1GCPhaseTimes : public CHeapObj<mtGC> {
public:
G1GCPhaseTimes(uint max_gc_threads);
void note_gc_start(uint active_gc_threads);
void print(double pause_time_ms);
void print();
// record the time a phase took in seconds
void record_time_secs(GCParPhases phase, uint worker_i, double secs);