8149035: Make the full_gc_dump() calls be recorded as part of the GC
Reviewed-by: jmasa, sjohanss
--- a/hotspot/src/share/vm/gc/cms/concurrentMarkSweepGeneration.cpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/gc/cms/concurrentMarkSweepGeneration.cpp Fri Feb 05 08:59:36 2016 +0100
@@ -1517,6 +1517,8 @@
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 @@
_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());
--- a/hotspot/src/share/vm/gc/parallel/psMarkSweep.cpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/gc/parallel/psMarkSweep.cpp Fri Feb 05 08:59:36 2016 +0100
@@ -156,8 +156,6 @@
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 @@
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 @@
// 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 @@
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
--- a/hotspot/src/share/vm/gc/parallel/psParallelCompact.cpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/gc/parallel/psParallelCompact.cpp Fri Feb 05 08:59:36 2016 +0100
@@ -1746,8 +1746,6 @@
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 @@
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 @@
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 @@
collection_exit.ticks());
gc_task_manager()->print_task_time_stamps();
- heap->post_full_gc_dump(&_gc_timer);
-
#ifdef TRACESPINNING
ParallelTaskTerminator::print_termination_counts();
#endif
--- a/hotspot/src/share/vm/gc/serial/tenuredGeneration.cpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/gc/serial/tenuredGeneration.cpp Fri Feb 05 08:59:36 2016 +0100
@@ -176,8 +176,12 @@
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());
--- a/hotspot/src/share/vm/gc/shared/collectedHeap.cpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/gc/shared/collectedHeap.cpp Fri Feb 05 08:59:36 2016 +0100
@@ -572,19 +572,16 @@
}
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();
}
--- a/hotspot/src/share/vm/gc/shared/genCollectedHeap.cpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/gc/shared/genCollectedHeap.cpp Fri Feb 05 08:59:36 2016 +0100
@@ -481,8 +481,6 @@
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 @@
// 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);
--- a/hotspot/src/share/vm/logging/logPrefix.hpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/logging/logPrefix.hpp Fri Feb 05 08:59:36 2016 +0100
@@ -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)) \
--- a/hotspot/src/share/vm/memory/heapInspection.cpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/memory/heapInspection.cpp Fri Feb 05 08:59:36 2016 +0100
@@ -226,9 +226,8 @@
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 @@
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 @@
}
// 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);
--- a/hotspot/src/share/vm/memory/heapInspection.hpp Thu Feb 04 23:39:27 2016 +0000
+++ b/hotspot/src/share/vm/memory/heapInspection.hpp Fri Feb 05 08:59:36 2016 +0100
@@ -281,8 +281,6 @@
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 @@
}
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);