8005849: JEP 167: Event-Based JVM Tracing

Co-authored-by: Karen Kinnear <karen.kinnear@oracle.com>
Co-authored-by: Bengt Rutisson <bengt.rutisson@oracle.com>
Co-authored-by: Calvin Cheung <calvin.cheung@oracle.com>
Co-authored-by: Erik Gahlin <erik.gahlin@oracle.com>
Co-authored-by: Erik Helin <erik.helin@oracle.com>
Co-authored-by: Jesper Wilhelmsson <jesper.wilhelmsson@oracle.com>
Co-authored-by: Keith McGuigan <keith.mcguigan@oracle.com>
Co-authored-by: Mattias Tobiasson <mattias.tobiasson@oracle.com>
Co-authored-by: Markus Gronlund <markus.gronlund@oracle.com>
Co-authored-by: Mikael Auno <mikael.auno@oracle.com>
Co-authored-by: Nils Eliasson <nils.eliasson@oracle.com>
Co-authored-by: Nils Loodin <nils.loodin@oracle.com>
Co-authored-by: Rickard Backman <rickard.backman@oracle.com>
Co-authored-by: Stefan Karlsson <stefan.karlsson@oracle.com>
Co-authored-by: Yekaterina Kantserova <yekaterina.kantserova@oracle.com>
Reviewed-by: acorn, coleenp, sla
This commit is contained in:
Staffan Larsen 2013-06-10 11:30:51 +02:00
parent 6b2c468c35
commit 718f3252f6
195 changed files with 7628 additions and 1484 deletions

View file

@ -39,6 +39,10 @@
#include "gc_implementation/parallelScavenge/psPromotionManager.inline.hpp"
#include "gc_implementation/parallelScavenge/psScavenge.hpp"
#include "gc_implementation/parallelScavenge/psYoungGen.hpp"
#include "gc_implementation/shared/gcHeapSummary.hpp"
#include "gc_implementation/shared/gcTimer.hpp"
#include "gc_implementation/shared/gcTrace.hpp"
#include "gc_implementation/shared/gcTraceTime.hpp"
#include "gc_implementation/shared/isGCActiveMark.hpp"
#include "gc_interface/gcCause.hpp"
#include "memory/gcLocker.inline.hpp"
@ -799,6 +803,8 @@ void ParallelCompactData::verify_clear()
}
#endif // #ifdef ASSERT
STWGCTimer PSParallelCompact::_gc_timer;
ParallelOldTracer PSParallelCompact::_gc_tracer;
elapsedTimer PSParallelCompact::_accumulated_time;
unsigned int PSParallelCompact::_total_invocations = 0;
unsigned int PSParallelCompact::_maximum_compaction_gc_num = 0;
@ -972,7 +978,7 @@ void PSParallelCompact::pre_compact(PreGCValues* pre_gc_values)
// at each young gen gc. Do the update unconditionally (even though a
// promotion failure does not swap spaces) because an unknown number of minor
// collections will have swapped the spaces an unknown number of times.
TraceTime tm("pre compact", print_phases(), true, gclog_or_tty);
GCTraceTime tm("pre compact", print_phases(), true, &_gc_timer);
ParallelScavengeHeap* heap = gc_heap();
_space_info[from_space_id].set_space(heap->young_gen()->from_space());
_space_info[to_space_id].set_space(heap->young_gen()->to_space());
@ -989,6 +995,7 @@ void PSParallelCompact::pre_compact(PreGCValues* pre_gc_values)
_total_invocations++;
heap->print_heap_before_gc();
heap->trace_heap_before_gc(&_gc_tracer);
// Fill in TLABs
heap->accumulate_statistics_all_tlabs();
@ -1014,7 +1021,7 @@ void PSParallelCompact::pre_compact(PreGCValues* pre_gc_values)
void PSParallelCompact::post_compact()
{
TraceTime tm("post compact", print_phases(), true, gclog_or_tty);
GCTraceTime tm("post compact", print_phases(), true, &_gc_timer);
for (unsigned int id = old_space_id; id < last_space_id; ++id) {
// Clear the marking bitmap, summary data and split info.
@ -1840,7 +1847,7 @@ void PSParallelCompact::summary_phase_msg(SpaceId dst_space_id,
void PSParallelCompact::summary_phase(ParCompactionManager* cm,
bool maximum_compaction)
{
TraceTime tm("summary phase", print_phases(), true, gclog_or_tty);
GCTraceTime tm("summary phase", print_phases(), true, &_gc_timer);
// trace("2");
#ifdef ASSERT
@ -1998,11 +2005,15 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
return false;
}
ParallelScavengeHeap* heap = gc_heap();
_gc_timer.register_gc_start(os::elapsed_counter());
_gc_tracer.report_gc_start(heap->gc_cause(), _gc_timer.gc_start());
TimeStamp marking_start;
TimeStamp compaction_start;
TimeStamp collection_exit;
ParallelScavengeHeap* heap = gc_heap();
GCCause::Cause gc_cause = heap->gc_cause();
PSYoungGen* young_gen = heap->young_gen();
PSOldGen* old_gen = heap->old_gen();
@ -2018,7 +2029,7 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
heap->record_gen_tops_before_GC();
}
heap->pre_full_gc_dump();
heap->pre_full_gc_dump(&_gc_timer);
_print_phases = PrintGCDetails && PrintParallelOldGCPhaseTimes;
@ -2045,7 +2056,7 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
TraceTime t1(GCCauseString("Full GC", gc_cause), PrintGC, !PrintGCDetails, gclog_or_tty);
GCTraceTime t1(GCCauseString("Full GC", gc_cause), PrintGC, !PrintGCDetails, NULL);
TraceCollectorStats tcs(counters());
TraceMemoryManagerStats tms(true /* Full GC */,gc_cause);
@ -2065,7 +2076,7 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
bool marked_for_unloading = false;
marking_start.update();
marking_phase(vmthread_cm, maximum_heap_compaction);
marking_phase(vmthread_cm, maximum_heap_compaction, &_gc_tracer);
bool max_on_system_gc = UseMaximumCompactionOnSystemGC
&& gc_cause == GCCause::_java_lang_system_gc;
@ -2218,6 +2229,8 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
collection_exit.update();
heap->print_heap_after_gc();
heap->trace_heap_after_gc(&_gc_tracer);
if (PrintGCTaskTimeStamps) {
gclog_or_tty->print_cr("VM-Thread " INT64_FORMAT " " INT64_FORMAT " "
INT64_FORMAT,
@ -2226,12 +2239,17 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
gc_task_manager()->print_task_time_stamps();
}
heap->post_full_gc_dump();
heap->post_full_gc_dump(&_gc_timer);
#ifdef TRACESPINNING
ParallelTaskTerminator::print_termination_counts();
#endif
_gc_timer.register_gc_end(os::elapsed_counter());
_gc_tracer.report_dense_prefix(dense_prefix(old_space_id));
_gc_tracer.report_gc_end(_gc_timer.gc_end(), _gc_timer.time_partitions());
return true;
}
@ -2330,9 +2348,10 @@ GCTaskManager* const PSParallelCompact::gc_task_manager() {
}
void PSParallelCompact::marking_phase(ParCompactionManager* cm,
bool maximum_heap_compaction) {
bool maximum_heap_compaction,
ParallelOldTracer *gc_tracer) {
// Recursively traverse all live objects and mark them
TraceTime tm("marking phase", print_phases(), true, gclog_or_tty);
GCTraceTime tm("marking phase", print_phases(), true, &_gc_timer);
ParallelScavengeHeap* heap = gc_heap();
uint parallel_gc_threads = heap->gc_task_manager()->workers();
@ -2347,7 +2366,8 @@ void PSParallelCompact::marking_phase(ParCompactionManager* cm,
ClassLoaderDataGraph::clear_claimed_marks();
{
TraceTime tm_m("par mark", print_phases(), true, gclog_or_tty);
GCTraceTime tm_m("par mark", print_phases(), true, &_gc_timer);
ParallelScavengeHeap::ParStrongRootsScope psrs;
GCTaskQueue* q = GCTaskQueue::create();
@ -2375,19 +2395,24 @@ void PSParallelCompact::marking_phase(ParCompactionManager* cm,
// Process reference objects found during marking
{
TraceTime tm_r("reference processing", print_phases(), true, gclog_or_tty);
GCTraceTime tm_r("reference processing", print_phases(), true, &_gc_timer);
ReferenceProcessorStats stats;
if (ref_processor()->processing_is_mt()) {
RefProcTaskExecutor task_executor;
ref_processor()->process_discovered_references(
stats = ref_processor()->process_discovered_references(
is_alive_closure(), &mark_and_push_closure, &follow_stack_closure,
&task_executor);
&task_executor, &_gc_timer);
} else {
ref_processor()->process_discovered_references(
is_alive_closure(), &mark_and_push_closure, &follow_stack_closure, NULL);
stats = ref_processor()->process_discovered_references(
is_alive_closure(), &mark_and_push_closure, &follow_stack_closure, NULL,
&_gc_timer);
}
gc_tracer->report_gc_reference_stats(stats);
}
TraceTime tm_c("class unloading", print_phases(), true, gclog_or_tty);
GCTraceTime tm_c("class unloading", print_phases(), true, &_gc_timer);
// This is the point where the entire marking should have completed.
assert(cm->marking_stacks_empty(), "Marking should have completed");
@ -2406,6 +2431,7 @@ void PSParallelCompact::marking_phase(ParCompactionManager* cm,
// Clean up unreferenced symbols in symbol table.
SymbolTable::unlink();
_gc_tracer.report_object_count_after_gc(is_alive_closure());
}
void PSParallelCompact::follow_klass(ParCompactionManager* cm, Klass* klass) {
@ -2446,7 +2472,7 @@ static PSAlwaysTrueClosure always_true;
void PSParallelCompact::adjust_roots() {
// Adjust the pointers to reflect the new locations
TraceTime tm("adjust roots", print_phases(), true, gclog_or_tty);
GCTraceTime tm("adjust roots", print_phases(), true, &_gc_timer);
// Need new claim bits when tracing through and adjusting pointers.
ClassLoaderDataGraph::clear_claimed_marks();
@ -2482,7 +2508,7 @@ void PSParallelCompact::adjust_roots() {
void PSParallelCompact::enqueue_region_draining_tasks(GCTaskQueue* q,
uint parallel_gc_threads)
{
TraceTime tm("drain task setup", print_phases(), true, gclog_or_tty);
GCTraceTime tm("drain task setup", print_phases(), true, &_gc_timer);
// Find the threads that are active
unsigned int which = 0;
@ -2556,7 +2582,7 @@ void PSParallelCompact::enqueue_region_draining_tasks(GCTaskQueue* q,
void PSParallelCompact::enqueue_dense_prefix_tasks(GCTaskQueue* q,
uint parallel_gc_threads) {
TraceTime tm("dense prefix task setup", print_phases(), true, gclog_or_tty);
GCTraceTime tm("dense prefix task setup", print_phases(), true, &_gc_timer);
ParallelCompactData& sd = PSParallelCompact::summary_data();
@ -2638,7 +2664,7 @@ void PSParallelCompact::enqueue_region_stealing_tasks(
GCTaskQueue* q,
ParallelTaskTerminator* terminator_ptr,
uint parallel_gc_threads) {
TraceTime tm("steal task setup", print_phases(), true, gclog_or_tty);
GCTraceTime tm("steal task setup", print_phases(), true, &_gc_timer);
// Once a thread has drained it's stack, it should try to steal regions from
// other threads.
@ -2686,7 +2712,7 @@ void PSParallelCompact::write_block_fill_histogram(outputStream* const out)
void PSParallelCompact::compact() {
// trace("5");
TraceTime tm("compaction phase", print_phases(), true, gclog_or_tty);
GCTraceTime tm("compaction phase", print_phases(), true, &_gc_timer);
ParallelScavengeHeap* heap = (ParallelScavengeHeap*)Universe::heap();
assert(heap->kind() == CollectedHeap::ParallelScavengeHeap, "Sanity");
@ -2703,7 +2729,7 @@ void PSParallelCompact::compact() {
enqueue_region_stealing_tasks(q, &terminator, active_gc_threads);
{
TraceTime tm_pc("par compact", print_phases(), true, gclog_or_tty);
GCTraceTime tm_pc("par compact", print_phases(), true, &_gc_timer);
gc_task_manager()->execute_and_wait(q);
@ -2717,7 +2743,7 @@ void PSParallelCompact::compact() {
{
// Update the deferred objects, if any. Any compaction manager can be used.
TraceTime tm_du("deferred updates", print_phases(), true, gclog_or_tty);
GCTraceTime tm_du("deferred updates", print_phases(), true, &_gc_timer);
ParCompactionManager* cm = ParCompactionManager::manager_array(0);
for (unsigned int id = old_space_id; id < last_space_id; ++id) {
update_deferred_objects(cm, SpaceId(id));