7166894: Add gc cause to GC logging for all collectors
Reviewed-by: mgerdin, johnc
--- a/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Tue May 15 10:25:06 2012 +0200
@@ -6332,10 +6332,10 @@
)
}
-void CMSCollector::do_CMS_operation(CMS_op_type op) {
+void CMSCollector::do_CMS_operation(CMS_op_type op, GCCause::Cause gc_cause) {
gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- TraceTime t("GC", PrintGC, !PrintGCDetails, gclog_or_tty);
+ TraceTime t(GCCauseString("GC", gc_cause), PrintGC, !PrintGCDetails, gclog_or_tty);
TraceCollectorStats tcs(counters());
switch (op) {
--- a/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.hpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.hpp Tue May 15 10:25:06 2012 +0200
@@ -717,7 +717,7 @@
CMS_op_checkpointRootsFinal
};
- void do_CMS_operation(CMS_op_type op);
+ void do_CMS_operation(CMS_op_type op, GCCause::Cause gc_cause);
bool stop_world_and_do(CMS_op_type op);
OopTaskQueueSet* task_queues() { return _task_queues; }
--- a/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/vmCMSOperations.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/vmCMSOperations.cpp Tue May 15 10:25:06 2012 +0200
@@ -146,7 +146,7 @@
VM_CMS_Operation::verify_before_gc();
IsGCActiveMark x; // stop-world GC active
- _collector->do_CMS_operation(CMSCollector::CMS_op_checkpointRootsInitial);
+ _collector->do_CMS_operation(CMSCollector::CMS_op_checkpointRootsInitial, gch->gc_cause());
VM_CMS_Operation::verify_after_gc();
#ifndef USDT2
@@ -178,7 +178,7 @@
VM_CMS_Operation::verify_before_gc();
IsGCActiveMark x; // stop-world GC active
- _collector->do_CMS_operation(CMSCollector::CMS_op_checkpointRootsFinal);
+ _collector->do_CMS_operation(CMSCollector::CMS_op_checkpointRootsFinal, gch->gc_cause());
VM_CMS_Operation::verify_after_gc();
#ifndef USDT2
--- a/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp Tue May 15 10:25:06 2012 +0200
@@ -1252,10 +1252,7 @@
gclog_or_tty->date_stamp(G1Log::fine() && PrintGCDateStamps);
TraceCPUTime tcpu(G1Log::finer(), true, gclog_or_tty);
- char verbose_str[128];
- sprintf(verbose_str, "Full GC (%s)", GCCause::to_string(gc_cause()));
- TraceTime t(verbose_str, G1Log::fine(), true, gclog_or_tty);
-
+ TraceTime t(GCCauseString("Full GC", gc_cause()), G1Log::fine(), true, gclog_or_tty);
TraceCollectorStats tcs(g1mm()->full_collection_counters());
TraceMemoryManagerStats tms(true /* fullGC */, gc_cause());
@@ -3600,12 +3597,10 @@
gclog_or_tty->date_stamp(G1Log::fine() && PrintGCDateStamps);
TraceCPUTime tcpu(G1Log::finer(), true, gclog_or_tty);
- char verbose_str[128];
- sprintf(verbose_str, "GC pause (%s) (%s)%s",
- GCCause::to_string(gc_cause()),
- g1_policy()->gcs_are_young() ? "young" : "mixed",
- g1_policy()->during_initial_mark_pause() ? " (initial-mark)" : "");
- TraceTime t(verbose_str, G1Log::fine() && !G1Log::finer(), true, gclog_or_tty);
+ GCCauseString gc_cause_str = GCCauseString("GC pause", gc_cause())
+ .append(g1_policy()->gcs_are_young() ? " (young)" : " (mixed)")
+ .append(g1_policy()->during_initial_mark_pause() ? " (initial-mark)" : "");
+ TraceTime t(gc_cause_str, G1Log::fine() && !G1Log::finer(), true, gclog_or_tty);
TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
TraceMemoryManagerStats tms(false /* fullGC */, gc_cause());
--- a/hotspot/src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/g1/g1CollectorPolicy.cpp Tue May 15 10:25:06 2012 +0200
@@ -886,9 +886,8 @@
size_t start_used) {
if (G1Log::finer()) {
gclog_or_tty->stamp(PrintGCTimeStamps);
- gclog_or_tty->print("[GC pause (%s) (%s)",
- GCCause::to_string(_g1->gc_cause()),
- gcs_are_young() ? "young" : "mixed");
+ gclog_or_tty->print("[%s", (const char*)GCCauseString("GC pause", _g1->gc_cause())
+ .append(gcs_are_young() ? " (young)" : " (mixed)"));
}
// We only need to do this here as the policy will only be applied
--- a/hotspot/src/share/vm/gc_implementation/parNew/parNewGeneration.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/parNew/parNewGeneration.cpp Tue May 15 10:25:06 2012 +0200
@@ -916,7 +916,7 @@
size_policy->minor_collection_begin();
}
- TraceTime t1("GC", PrintGC && !PrintGCDetails, true, gclog_or_tty);
+ TraceTime t1(GCCauseString("GC", gch->gc_cause()), PrintGC && !PrintGCDetails, true, gclog_or_tty);
// Capture heap used before collection (for printing).
size_t gch_prev_used = gch->used();
--- a/hotspot/src/share/vm/gc_implementation/parallelScavenge/psMarkSweep.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/parallelScavenge/psMarkSweep.cpp Tue May 15 10:25:06 2012 +0200
@@ -160,16 +160,10 @@
{
HandleMark hm;
- const bool is_system_gc = gc_cause == GCCause::_java_lang_system_gc;
- // This is useful for debugging but don't change the output the
- // the customer sees.
- const char* gc_cause_str = "Full GC";
- if (is_system_gc && PrintGCDetails) {
- gc_cause_str = "Full GC (System)";
- }
+
gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- TraceTime t1(gc_cause_str, PrintGC, !PrintGCDetails, gclog_or_tty);
+ TraceTime t1(GCCauseString("Full GC", gc_cause), PrintGC, !PrintGCDetails, gclog_or_tty);
TraceCollectorStats tcs(counters());
TraceMemoryManagerStats tms(true /* Full GC */,gc_cause);
--- a/hotspot/src/share/vm/gc_implementation/parallelScavenge/psParallelCompact.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/parallelScavenge/psParallelCompact.cpp Tue May 15 10:25:06 2012 +0200
@@ -2047,17 +2047,9 @@
gc_task_manager()->task_idle_workers();
heap->set_par_threads(gc_task_manager()->active_workers());
- const bool is_system_gc = gc_cause == GCCause::_java_lang_system_gc;
-
- // This is useful for debugging but don't change the output the
- // the customer sees.
- const char* gc_cause_str = "Full GC";
- if (is_system_gc && PrintGCDetails) {
- gc_cause_str = "Full GC (System)";
- }
gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- TraceTime t1(gc_cause_str, PrintGC, !PrintGCDetails, gclog_or_tty);
+ TraceTime t1(GCCauseString("Full GC", gc_cause), PrintGC, !PrintGCDetails, gclog_or_tty);
TraceCollectorStats tcs(counters());
TraceMemoryManagerStats tms(true /* Full GC */,gc_cause);
@@ -2090,7 +2082,8 @@
}
#endif // #ifndef PRODUCT
- bool max_on_system_gc = UseMaximumCompactionOnSystemGC && is_system_gc;
+ bool max_on_system_gc = UseMaximumCompactionOnSystemGC
+ && gc_cause == GCCause::_java_lang_system_gc;
summary_phase(vmthread_cm, maximum_heap_compaction || max_on_system_gc);
COMPILER2_PRESENT(assert(DerivedPointerTable::is_active(), "Sanity"));
--- a/hotspot/src/share/vm/gc_implementation/parallelScavenge/psScavenge.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_implementation/parallelScavenge/psScavenge.cpp Tue May 15 10:25:06 2012 +0200
@@ -325,7 +325,7 @@
gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- TraceTime t1("GC", PrintGC, !PrintGCDetails, gclog_or_tty);
+ TraceTime t1(GCCauseString("GC", gc_cause), PrintGC, !PrintGCDetails, gclog_or_tty);
TraceCollectorStats tcs(counters());
TraceMemoryManagerStats tms(false /* not full GC */,gc_cause);
--- a/hotspot/src/share/vm/gc_interface/gcCause.hpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/gc_interface/gcCause.hpp Tue May 15 10:25:06 2012 +0200
@@ -88,4 +88,36 @@
static const char* to_string(GCCause::Cause cause);
};
+// Helper class for doing logging that includes the GC Cause
+// as a string.
+class GCCauseString : StackObj {
+ private:
+ static const int _length = 128;
+ char _buffer[_length];
+ int _position;
+
+ public:
+ GCCauseString(const char* prefix, GCCause::Cause cause) {
+ if (PrintGCCause) {
+ _position = jio_snprintf(_buffer, _length, "%s (%s)", prefix, GCCause::to_string(cause));
+ } else {
+ _position = jio_snprintf(_buffer, _length, "%s", prefix);
+ }
+ assert(_position >= 0 && _position <= _length,
+ err_msg("Need to increase the buffer size in GCCauseString? %d", _position));
+ }
+
+ GCCauseString& append(const char* str) {
+ int res = jio_snprintf(_buffer + _position, _length - _position, "%s", str);
+ _position += res;
+ assert(res >= 0 && _position <= _length,
+ err_msg("Need to increase the buffer size in GCCauseString? %d", res));
+ return *this;
+ }
+
+ operator const char*() {
+ return _buffer;
+ }
+};
+
#endif // SHARE_VM_GC_INTERFACE_GCCAUSE_HPP
--- a/hotspot/src/share/vm/memory/defNewGeneration.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/memory/defNewGeneration.cpp Tue May 15 10:25:06 2012 +0200
@@ -548,7 +548,7 @@
init_assuming_no_promotion_failure();
- TraceTime t1("GC", PrintGC && !PrintGCDetails, true, gclog_or_tty);
+ TraceTime t1(GCCauseString("GC", gch->gc_cause()), PrintGC && !PrintGCDetails, true, gclog_or_tty);
// Capture heap used before collection (for printing).
size_t gch_prev_used = gch->used();
--- a/hotspot/src/share/vm/memory/genCollectedHeap.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/memory/genCollectedHeap.cpp Tue May 15 10:25:06 2012 +0200
@@ -480,26 +480,15 @@
const size_t perm_prev_used = perm_gen()->used();
print_heap_before_gc();
- if (Verbose) {
- gclog_or_tty->print_cr("GC Cause: %s", GCCause::to_string(gc_cause()));
- }
{
FlagSetting fl(_is_gc_active, true);
bool complete = full && (max_level == (n_gens()-1));
- const char* gc_cause_str = "GC ";
- if (complete) {
- GCCause::Cause cause = gc_cause();
- if (cause == GCCause::_java_lang_system_gc) {
- gc_cause_str = "Full GC (System) ";
- } else {
- gc_cause_str = "Full GC ";
- }
- }
+ const char* gc_cause_prefix = complete ? "Full GC" : "GC";
gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- TraceTime t(gc_cause_str, PrintGCDetails, false, gclog_or_tty);
+ TraceTime t(GCCauseString(gc_cause_prefix, gc_cause()), PrintGCDetails, false, gclog_or_tty);
gc_prologue(complete);
increment_total_collections(complete);
--- a/hotspot/src/share/vm/memory/genMarkSweep.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/memory/genMarkSweep.cpp Tue May 15 10:25:06 2012 +0200
@@ -76,7 +76,7 @@
_ref_processor = rp;
rp->setup_policy(clear_all_softrefs);
- TraceTime t1("Full GC", PrintGC && !PrintGCDetails, true, gclog_or_tty);
+ TraceTime t1(GCCauseString("Full GC", gch->gc_cause()), PrintGC && !PrintGCDetails, true, gclog_or_tty);
// When collecting the permanent generation methodOops may be moving,
// so we either have to flush all bcp data or convert it into bci.
--- a/hotspot/src/share/vm/runtime/arguments.cpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/runtime/arguments.cpp Tue May 15 10:25:06 2012 +0200
@@ -3092,6 +3092,14 @@
PrintGC = true;
}
+ if (!JDK_Version::is_gte_jdk18x_version()) {
+ // To avoid changing the log format for 7 updates this flag is only
+ // true by default in JDK8 and above.
+ if (FLAG_IS_DEFAULT(PrintGCCause)) {
+ FLAG_SET_DEFAULT(PrintGCCause, false);
+ }
+ }
+
// Set object alignment values.
set_object_alignment();
--- a/hotspot/src/share/vm/runtime/globals.hpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/runtime/globals.hpp Tue May 15 10:25:06 2012 +0200
@@ -3902,7 +3902,10 @@
" of this flag is true for JDK 6 and earlier") \
\
diagnostic(bool, WhiteBoxAPI, false, \
- "Enable internal testing APIs")
+ "Enable internal testing APIs") \
+ \
+ product(bool, PrintGCCause, true, \
+ "Include GC cause in GC logging")
/*
* Macros for factoring of globals
--- a/hotspot/src/share/vm/runtime/java.hpp Tue May 15 22:26:37 2012 +0200
+++ b/hotspot/src/share/vm/runtime/java.hpp Tue May 15 10:25:06 2012 +0200
@@ -206,6 +206,10 @@
return current().compare_major(7) == 0;
}
+ static bool is_jdk18x_version() {
+ return current().compare_major(8) == 0;
+ }
+
static bool is_gte_jdk13x_version() {
return current().compare_major(3) >= 0;
}
@@ -225,6 +229,10 @@
static bool is_gte_jdk17x_version() {
return current().compare_major(7) >= 0;
}
+
+ static bool is_gte_jdk18x_version() {
+ return current().compare_major(8) >= 0;
+ }
};
#endif // SHARE_VM_RUNTIME_JAVA_HPP