Mercurial > hg > shenandoah-preopenjdk-archive > openjdk8 > hotspot
changeset 7449:ac5d21fb6715
Improve summary output: include full-gc, final evacuation and final update-refs pauses, and concurrent mark timing. Only print heap regions when Verbose.
author | Roman Kennke <rkennke@redhat.com> |
---|---|
date | Fri, 16 Jan 2015 12:30:35 +0100 |
parents | 5d8c71ac66b0 |
children | 557818193d0e |
files | src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.cpp src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.hpp src/share/vm/gc_implementation/shenandoah/shenandoahConcurrentMark.cpp src/share/vm/gc_implementation/shenandoah/shenandoahMarkCompact.cpp src/share/vm/gc_implementation/shenandoah/vm_operations_shenandoah.cpp |
diffstat | 5 files changed, 132 insertions(+), 1 deletions(-) [+] |
line wrap: on
line diff
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.cpp Wed Jan 21 13:16:36 2015 +0100 +++ b/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.cpp Fri Jan 16 12:30:35 2015 +0100 @@ -6,7 +6,12 @@ private: NumberSeq _init_mark_ms; NumberSeq _final_mark_ms; - NumberSeq _concurrent_marking_times_ms; + NumberSeq _final_evac_ms; + NumberSeq _final_uprefs_ms; + + NumberSeq _fullgc_ms; + + NumberSeq _concurrent_mark_times_ms; NumberSeq _concurrent_evacuation_times_ms; NumberSeq _allocation_rate_bytes; @@ -15,11 +20,18 @@ double _init_mark_start; double _concurrent_mark_start; double _final_mark_start; + double _final_evac_start; + double _final_uprefs_start; double _concurrent_evacuation_start; + double _fullgc_start; int _init_mark_count; int _final_mark_count; + int _final_evac_count; + int _final_uprefs_count; int _concurrent_evacuation_count; + int _concurrent_mark_count; + int _fullgc_count; size_t _bytes_allocated_since_CM; size_t _bytes_reclaimed_this_cycle; @@ -34,8 +46,14 @@ void record_concurrent_mark_end(); void record_final_mark_start(); void record_final_mark_end(); + void record_final_evacuation_start(); + void record_final_evacuation_end(); + void record_final_update_refs_start(); + void record_final_update_refs_end(); void record_concurrent_evacuation_start(); void record_concurrent_evacuation_end(); + void record_fullgc_start(); + void record_fullgc_end(); void record_bytes_allocated(size_t bytes); void record_bytes_reclaimed(size_t bytes); @@ -50,11 +68,18 @@ _init_mark_start(0), _concurrent_mark_start(0), _final_mark_start(0), + _final_evac_start(0), + _final_uprefs_start(0), _concurrent_evacuation_start(0), + _fullgc_start(0), _bytes_allocated_since_CM(0), _bytes_reclaimed_this_cycle(0), _init_mark_count(0), _final_mark_count(0), + _final_evac_count(0), + _final_uprefs_count(0), + _fullgc_count(0), + _concurrent_mark_count(0), _concurrent_evacuation_count(0) { if (PrintGCDetails) @@ -85,6 +110,29 @@ tty->print_cr("PolicyPrint: FinalMark %d took %lf ms", _final_mark_count++, elapsed * 1000); } +void ShenandoahHeuristics::record_final_evacuation_start() { + _final_evac_start = os::elapsedTime(); +} + +void ShenandoahHeuristics::record_final_evacuation_end() { + double elapsed = os::elapsedTime() - _final_evac_start; + _final_evac_ms.add(elapsed * 1000); + if (ShenandoahGCVerbose && PrintGCDetails) { + tty->print_cr("PolicyPrint: FinalEvacuation "INT32_FORMAT" took %lf ms", _final_evac_count++, elapsed * 1000); + } +} + +void ShenandoahHeuristics::record_final_update_refs_start() { + _final_uprefs_start = os::elapsedTime(); +} + +void ShenandoahHeuristics::record_final_update_refs_end() { + double elapsed = os::elapsedTime() - _final_uprefs_start; + _final_uprefs_ms.add(elapsed * 1000); + if (ShenandoahGCVerbose && PrintGCDetails) + tty->print_cr("PolicyPrint: FinalUpdateRefs "INT32_FORMAT" took %lf ms", _final_uprefs_count++, elapsed * 1000); +} + void ShenandoahHeuristics::record_concurrent_evacuation_start() { _concurrent_evacuation_start = os::elapsedTime(); } @@ -97,6 +145,30 @@ _concurrent_evacuation_count++, elapsed * 1000); } +void ShenandoahHeuristics::record_concurrent_mark_start() { + _concurrent_mark_start = os::elapsedTime(); +} + +void ShenandoahHeuristics::record_concurrent_mark_end() { + double elapsed = os::elapsedTime() - _concurrent_mark_start; + _concurrent_mark_times_ms.add(elapsed * 1000); + if (ShenandoahGCVerbose && PrintGCDetails) + tty->print_cr("PolicyPrint: Concurrent Marking "INT32_FORMAT" took %lf ms", + _concurrent_mark_count++, elapsed * 1000); +} + +void ShenandoahHeuristics::record_fullgc_start() { + _fullgc_start = os::elapsedTime(); +} + +void ShenandoahHeuristics::record_fullgc_end() { + double elapsed = os::elapsedTime() - _fullgc_start; + _fullgc_ms.add(elapsed * 1000); + if (ShenandoahGCVerbose && PrintGCDetails) + tty->print_cr("PolicyPrint: Full GC "INT32_FORMAT" took %lf ms", + _fullgc_count++, elapsed * 1000); +} + void ShenandoahHeuristics::record_bytes_allocated(size_t bytes) { _bytes_allocated_since_CM = bytes; _allocation_rate_bytes.add(bytes); @@ -511,6 +583,22 @@ _heuristics->record_final_mark_end(); } +void ShenandoahCollectorPolicy::record_final_evacuation_start() { + _heuristics->record_final_evacuation_start(); +} + +void ShenandoahCollectorPolicy::record_final_evacuation_end() { + _heuristics->record_final_evacuation_end(); +} + +void ShenandoahCollectorPolicy::record_final_update_refs_start() { + _heuristics->record_final_update_refs_start(); +} + +void ShenandoahCollectorPolicy::record_final_update_refs_end() { + _heuristics->record_final_update_refs_end(); +} + void ShenandoahCollectorPolicy::record_concurrent_evacuation_start() { _heuristics->record_concurrent_evacuation_start(); } @@ -519,6 +607,22 @@ _heuristics->record_concurrent_evacuation_end(); } +void ShenandoahCollectorPolicy::record_concurrent_mark_start() { + _heuristics->record_concurrent_mark_start(); +} + +void ShenandoahCollectorPolicy::record_concurrent_mark_end() { + _heuristics->record_concurrent_mark_end(); +} + +void ShenandoahCollectorPolicy::record_fullgc_start() { + _heuristics->record_fullgc_start(); +} + +void ShenandoahCollectorPolicy::record_fullgc_end() { + _heuristics->record_fullgc_end(); +} + void ShenandoahCollectorPolicy::record_bytes_allocated(size_t bytes) { _heuristics->record_bytes_allocated(bytes); } @@ -560,6 +664,12 @@ void ShenandoahHeuristics::print_tracing_info() { print_summary_sd("Initial Mark Pauses", &_init_mark_ms); print_summary_sd("Final Mark Pauses", &_final_mark_ms); + print_summary_sd("Final Evacuation Pauses", &_final_evac_ms); + print_summary_sd("Final Update Refs Pauses", &_final_uprefs_ms); + print_summary_sd("Concurrent Marking Times", + &_concurrent_mark_times_ms); print_summary_sd("Concurrent Evacuation Times", &_concurrent_evacuation_times_ms); + print_summary_sd("Full GC Times", + &_fullgc_ms); }
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.hpp Wed Jan 21 13:16:36 2015 +0100 +++ b/src/share/vm/gc_implementation/shenandoah/shenandoahCollectorPolicy.hpp Fri Jan 16 12:30:35 2015 +0100 @@ -43,8 +43,14 @@ void record_concurrent_mark_end(); void record_final_mark_start(); void record_final_mark_end(); + void record_final_evacuation_start(); + void record_final_evacuation_end(); + void record_final_update_refs_start(); + void record_final_update_refs_end(); void record_concurrent_evacuation_start(); void record_concurrent_evacuation_end(); + void record_fullgc_start(); + void record_fullgc_end(); void record_bytes_allocated(size_t bytes); void record_bytes_reclaimed(size_t bytes); bool should_start_concurrent_mark(size_t used, size_t capacity);
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahConcurrentMark.cpp Wed Jan 21 13:16:36 2015 +0100 +++ b/src/share/vm/gc_implementation/shenandoah/shenandoahConcurrentMark.cpp Fri Jan 16 12:30:35 2015 +0100 @@ -386,7 +386,11 @@ tty->print_cr("STOPPING THE WORLD: before marking"); tty->print_cr("Starting markFromRoots"); } + ShenandoahHeap* sh = (ShenandoahHeap *) Universe::heap(); + + sh->shenandoahPolicy()->record_concurrent_mark_start(); + uint max_workers = full_gc ? _max_worker_id : _max_conc_worker_id; ParallelTaskTerminator terminator(max_workers, _task_queues); ReferenceProcessor* rp = sh->ref_processor_cm(); @@ -410,6 +414,7 @@ TASKQUEUE_STATS_ONLY(reset_taskqueue_stats()); } + sh->shenandoahPolicy()->record_concurrent_mark_end(); } class FinishDrainSATBBuffersTask : public AbstractGangTask {
--- a/src/share/vm/gc_implementation/shenandoah/shenandoahMarkCompact.cpp Wed Jan 21 13:16:36 2015 +0100 +++ b/src/share/vm/gc_implementation/shenandoah/shenandoahMarkCompact.cpp Fri Jan 16 12:30:35 2015 +0100 @@ -31,6 +31,8 @@ assert(!_heap->is_evacuation_in_progress(), "can't do full-GC while evacuation is in progress"); assert(!_heap->is_update_references_in_progress(), "can't do full-GC while updating of references is in progress"); + _heap->shenandoahPolicy()->record_fullgc_start(); + if (ShenandoahVerify) { // Full GC should only be called between regular concurrent cycles, therefore // those verifications should be valid. @@ -66,6 +68,8 @@ } _heap->reset_mark_bitmap(); + + _heap->shenandoahPolicy()->record_fullgc_end(); } void ShenandoahMarkCompact::phase1_mark_heap() {
--- a/src/share/vm/gc_implementation/shenandoah/vm_operations_shenandoah.cpp Wed Jan 21 13:16:36 2015 +0100 +++ b/src/share/vm/gc_implementation/shenandoah/vm_operations_shenandoah.cpp Fri Jan 16 12:30:35 2015 +0100 @@ -202,6 +202,9 @@ tty->print("vm_ShenandoahUpdateRootRefs\n"); ShenandoahHeap *sh = ShenandoahHeap::heap(); + + sh->shenandoahPolicy()->record_final_update_refs_start(); + sh->update_roots(); if (ShenandoahVerify) { @@ -216,6 +219,7 @@ sh->reset_mark_bitmap(); + sh->shenandoahPolicy()->record_final_update_refs_end(); } VM_Operation::VMOp_Type VM_ShenandoahUpdateRefs::type() const { @@ -231,7 +235,9 @@ tty->print("vm_ShenandoahUpdateRefs\n"); ShenandoahHeap *sh = ShenandoahHeap::heap(); + sh->shenandoahPolicy()->record_final_evacuation_start(); sh->set_evacuation_in_progress(false); sh->prepare_for_update_references(); assert(ShenandoahConcurrentUpdateRefs, "only do this when concurrent update references is turned on"); + sh->shenandoahPolicy()->record_final_evacuation_end(); }