8149035: Make the full_gc_dump() calls be recorded as part of the GC
authorbrutisso
Fri, 05 Feb 2016 08:59:36 +0100
changeset 35939 05df7e64ecfc
parent 35938 a734965f7634
child 35940 b6335181f2c6
child 35941 be5a3f551026
child 35943 e726308008c0
8149035: Make the full_gc_dump() calls be recorded as part of the GC Reviewed-by: jmasa, sjohanss
hotspot/src/share/vm/gc/cms/concurrentMarkSweepGeneration.cpp
hotspot/src/share/vm/gc/parallel/psMarkSweep.cpp
hotspot/src/share/vm/gc/parallel/psParallelCompact.cpp
hotspot/src/share/vm/gc/serial/tenuredGeneration.cpp
hotspot/src/share/vm/gc/shared/collectedHeap.cpp
hotspot/src/share/vm/gc/shared/genCollectedHeap.cpp
hotspot/src/share/vm/logging/logPrefix.hpp
hotspot/src/share/vm/memory/heapInspection.cpp
hotspot/src/share/vm/memory/heapInspection.hpp
--- 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);