8149035: Make the full_gc_dump() calls be recorded as part of the GC

Reviewed-by: jmasa, sjohanss
This commit is contained in:
Bengt Rutisson 2016-02-05 08:59:36 +01:00
parent d2da0cb052
commit 1322b0fe56
9 changed files with 29 additions and 33 deletions

View File

@ -1517,6 +1517,8 @@ void CMSCollector::do_compaction_work(bool clear_all_soft_refs) {
SerialOldTracer* gc_tracer = GenMarkSweep::gc_tracer();
gc_tracer->report_gc_start(gch->gc_cause(), gc_timer->gc_start());
gch->pre_full_gc_dump(gc_timer);
GCTraceTime(Trace, gc) t("CMS:MSC");
// Temporarily widen the span of the weak reference processing to
@ -1593,6 +1595,8 @@ void CMSCollector::do_compaction_work(bool clear_all_soft_refs) {
_inter_sweep_timer.reset();
_inter_sweep_timer.start();
gch->post_full_gc_dump(gc_timer);
gc_timer->register_gc_end();
gc_tracer->report_gc_end(gc_timer->gc_end(), gc_timer->time_partitions());

View File

@ -156,8 +156,6 @@ bool PSMarkSweep::invoke_no_policy(bool clear_all_softrefs) {
old_gen->verify_object_start_array();
}
heap->pre_full_gc_dump(_gc_timer);
// Filled in below to track the state of the young gen after the collection.
bool eden_empty;
bool survivors_empty;
@ -168,6 +166,9 @@ bool PSMarkSweep::invoke_no_policy(bool clear_all_softrefs) {
GCTraceCPUTime tcpu;
GCTraceTime(Info, gc) t("Pause Full", NULL, gc_cause, true);
heap->pre_full_gc_dump(_gc_timer);
TraceCollectorStats tcs(counters());
TraceMemoryManagerStats tms(true /* Full GC */,gc_cause);
@ -345,6 +346,8 @@ bool PSMarkSweep::invoke_no_policy(bool clear_all_softrefs) {
// Track memory usage and detect low memory
MemoryService::track_memory_usage();
heap->update_counters();
heap->post_full_gc_dump(_gc_timer);
}
if (VerifyAfterGC && heap->total_collections() >= VerifyGCStartAt) {
@ -367,8 +370,6 @@ bool PSMarkSweep::invoke_no_policy(bool clear_all_softrefs) {
heap->print_heap_after_gc();
heap->trace_heap_after_gc(_gc_tracer);
heap->post_full_gc_dump(_gc_timer);
#ifdef TRACESPINNING
ParallelTaskTerminator::print_termination_counts();
#endif

View File

@ -1746,8 +1746,6 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
heap->record_gen_tops_before_GC();
}
heap->pre_full_gc_dump(&_gc_timer);
// Make sure data structures are sane, make the heap parsable, and do other
// miscellaneous bookkeeping.
pre_compact();
@ -1768,6 +1766,9 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
GCTraceCPUTime tcpu;
GCTraceTime(Info, gc) tm("Pause Full", NULL, gc_cause, true);
heap->pre_full_gc_dump(&_gc_timer);
TraceCollectorStats tcs(counters());
TraceMemoryManagerStats tms(true /* Full GC */,gc_cause);
@ -1902,6 +1903,8 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
MemoryService::track_memory_usage();
heap->update_counters();
gc_task_manager()->release_idle_workers();
heap->post_full_gc_dump(&_gc_timer);
}
#ifdef ASSERT
@ -1940,8 +1943,6 @@ bool PSParallelCompact::invoke_no_policy(bool maximum_heap_compaction) {
collection_exit.ticks());
gc_task_manager()->print_task_time_stamps();
heap->post_full_gc_dump(&_gc_timer);
#ifdef TRACESPINNING
ParallelTaskTerminator::print_termination_counts();
#endif

View File

@ -176,8 +176,12 @@ void TenuredGeneration::collect(bool full,
SerialOldTracer* gc_tracer = GenMarkSweep::gc_tracer();
gc_tracer->report_gc_start(gch->gc_cause(), gc_timer->gc_start());
gch->pre_full_gc_dump(gc_timer);
GenMarkSweep::invoke_at_safepoint(ref_processor(), clear_all_soft_refs);
gch->post_full_gc_dump(gc_timer);
gc_timer->register_gc_end();
gc_tracer->report_gc_end(gc_timer->gc_end(), gc_timer->time_partitions());

View File

@ -572,19 +572,16 @@ void CollectedHeap::resize_all_tlabs() {
}
void CollectedHeap::full_gc_dump(GCTimer* timer, bool before) {
assert(timer != NULL, "timer is null");
if ((HeapDumpBeforeFullGC && before) || (HeapDumpAfterFullGC && !before)) {
GCIdMarkAndRestore gc_id_mark;
FormatBuffer<> title("Heap Dump (%s full gc)", before ? "before" : "after");
GCTraceTime(Info, gc) tm(title.buffer(), timer);
GCTraceTime(Info, gc) tm(before ? "Heap Dump (before full gc)" : "Heap Dump (after full gc)", timer);
HeapDumper::dump_heap();
}
LogHandle(gc, classhisto) log;
if (log.is_trace()) {
GCTraceTime(Trace, gc, classhisto) tm(before ? "Class Histogram (before full gc)" : "Class Histogram (after full gc)", timer);
ResourceMark rm;
GCIdMarkAndRestore gc_id_mark;
FormatBuffer<> title("Class Histogram (%s full gc)",
before ? "before" : "after");
GCTraceTime(Trace, gc, classhisto) tm(title.buffer(), timer);
VM_GC_HeapInspection inspector(log.trace_stream(), false /* ! full gc */);
inspector.doit();
}

View File

@ -481,8 +481,6 @@ void GenCollectedHeap::do_collection(bool full,
increment_total_full_collections();
}
pre_full_gc_dump(NULL); // do any pre full gc dumps
if (!prepared_for_verification && run_verification &&
VerifyGCLevel <= 1 && VerifyBeforeGC) {
prepare_for_verify();
@ -507,11 +505,6 @@ void GenCollectedHeap::do_collection(bool full,
// a whole heap collection.
complete = complete || collected_old;
if (complete) { // We did a full collection
// FIXME: See comment at pre_full_gc_dump call
post_full_gc_dump(NULL); // do any post full gc dumps
}
print_heap_change(young_prev_used, old_prev_used);
MetaspaceAux::print_metaspace_change(metadata_prev_used);

View File

@ -43,6 +43,7 @@
LOG_PREFIX(GCId::print_prefix, LOG_TAGS(gc, age)) \
LOG_PREFIX(GCId::print_prefix, LOG_TAGS(gc, alloc)) \
LOG_PREFIX(GCId::print_prefix, LOG_TAGS(gc, barrier)) \
LOG_PREFIX(GCId::print_prefix, LOG_TAGS(gc, classhisto)) \
LOG_PREFIX(GCId::print_prefix, LOG_TAGS(gc, compaction)) \
LOG_PREFIX(GCId::print_prefix, LOG_TAGS(gc, compaction, phases)) \
LOG_PREFIX(GCId::print_prefix, LOG_TAGS(gc, cpu)) \

View File

@ -226,9 +226,8 @@ int KlassInfoHisto::sort_helper(KlassInfoEntry** e1, KlassInfoEntry** e2) {
return (*e1)->compare(*e1,*e2);
}
KlassInfoHisto::KlassInfoHisto(KlassInfoTable* cit, const char* title) :
_cit(cit),
_title(title) {
KlassInfoHisto::KlassInfoHisto(KlassInfoTable* cit) :
_cit(cit) {
_elements = new (ResourceObj::C_HEAP, mtInternal) GrowableArray<KlassInfoEntry*>(_histo_initial_size, true);
}
@ -648,7 +647,8 @@ void KlassInfoHisto::print_histo_on(outputStream* st, bool print_stats,
if (print_stats) {
print_class_stats(st, csv_format, columns);
} else {
st->print_cr("%s",title());
st->print_cr(" num #instances #bytes class name");
st->print_cr("----------------------------------------------");
print_elements(st);
}
}
@ -729,10 +729,7 @@ void HeapInspection::heap_inspection(outputStream* st) {
}
// Sort and print klass instance info
const char *title = "\n"
" num #instances #bytes class name\n"
"----------------------------------------------";
KlassInfoHisto histo(&cit, title);
KlassInfoHisto histo(&cit);
HistoClosure hc(&histo);
cit.iterate(&hc);

View File

@ -281,8 +281,6 @@ class KlassInfoHisto : public StackObj {
KlassInfoTable *_cit;
GrowableArray<KlassInfoEntry*>* _elements;
GrowableArray<KlassInfoEntry*>* elements() const { return _elements; }
const char* _title;
const char* title() const { return _title; }
static int sort_helper(KlassInfoEntry** e1, KlassInfoEntry** e2);
void print_elements(outputStream* st) const;
void print_class_stats(outputStream* st, bool csv_format, const char *columns);
@ -340,7 +338,7 @@ class KlassInfoHisto : public StackObj {
}
public:
KlassInfoHisto(KlassInfoTable* cit, const char* title);
KlassInfoHisto(KlassInfoTable* cit);
~KlassInfoHisto();
void add(KlassInfoEntry* cie);
void print_histo_on(outputStream* st, bool print_class_stats, bool csv_format, const char *columns);