--- old/src/share/vm/gc/cms/concurrentMarkSweepGeneration.cpp 2017-06-14 11:45:04.443040476 +0900 +++ new/src/share/vm/gc/cms/concurrentMarkSweepGeneration.cpp 2017-06-14 11:45:04.356038733 +0900 @@ -625,6 +625,7 @@ NOT_PRODUCT(_overflow_counter = CMSMarkStackOverflowInterval;) _gc_counters = new CollectorCounters("CMS", 1); + _cgc_counters = new CollectorCounters("CMS stop-the-world phases", 2); _completed_initialization = true; _inter_sweep_timer.start(); // start of time } @@ -5550,18 +5551,19 @@ void CMSCollector::do_CMS_operation(CMS_op_type op, GCCause::Cause gc_cause) { GCTraceCPUTime tcpu; - TraceCollectorStats tcs(counters()); + TraceCollectorStats tcs(EnableConcGCPerfCounter ? NULL : counters()); + TraceCollectorStats tcs_cgc(cgc_counters()); switch (op) { case CMS_op_checkpointRootsInitial: { GCTraceTime(Info, gc) t("Pause Initial Mark", NULL, GCCause::_no_gc, true); - SvcGCMarker sgcm(SvcGCMarker::OTHER); + SvcGCMarker sgcm(SvcGCMarker::CONCURRENT); checkpointRootsInitial(); break; } case CMS_op_checkpointRootsFinal: { GCTraceTime(Info, gc) t("Pause Remark", NULL, GCCause::_no_gc, true); - SvcGCMarker sgcm(SvcGCMarker::OTHER); + SvcGCMarker sgcm(SvcGCMarker::CONCURRENT); checkpointRootsFinal(); break; } --- old/src/share/vm/gc/cms/concurrentMarkSweepGeneration.hpp 2017-06-14 11:45:04.795047530 +0900 +++ new/src/share/vm/gc/cms/concurrentMarkSweepGeneration.hpp 2017-06-14 11:45:04.709045807 +0900 @@ -554,6 +554,7 @@ // Performance Counters CollectorCounters* _gc_counters; + CollectorCounters* _cgc_counters; // Initialization Errors bool _completed_initialization; @@ -928,7 +929,8 @@ NOT_PRODUCT(bool is_cms_reachable(HeapWord* addr);) // Performance Counter Support - CollectorCounters* counters() { return _gc_counters; } + CollectorCounters* counters() { return _gc_counters; } + CollectorCounters* cgc_counters() { return _cgc_counters; } // Timer stuff void startTimer() { assert(!_timer.is_active(), "Error"); _timer.start(); } --- old/src/share/vm/gc/g1/g1ConcurrentMark.cpp 2017-06-14 11:45:05.081053262 +0900 +++ new/src/share/vm/gc/g1/g1ConcurrentMark.cpp 2017-06-14 11:45:04.992051478 +0900 @@ -1103,8 +1103,6 @@ return; } - SvcGCMarker sgcm(SvcGCMarker::OTHER); - if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); --- old/src/share/vm/gc/g1/g1MonitoringSupport.cpp 2017-06-14 11:45:05.368059013 +0900 +++ new/src/share/vm/gc/g1/g1MonitoringSupport.cpp 2017-06-14 11:45:05.285057350 +0900 @@ -76,6 +76,7 @@ _g1h(g1h), _incremental_collection_counters(NULL), _full_collection_counters(NULL), + _conc_collection_counters(NULL), _old_collection_counters(NULL), _old_space_counters(NULL), _young_collection_counters(NULL), @@ -104,6 +105,10 @@ // old generation collection. _full_collection_counters = new CollectorCounters("G1 stop-the-world full collections", 1); + // name "collector.2". In a generational collector this would be the + // STW phases in concurrent collection. + _conc_collection_counters = + new CollectorCounters("G1 stop-the-world phases", 2); // timer sampling for all counters supporting sampling only update the // used value. See the take_sample() method. G1 requires both used and --- old/src/share/vm/gc/g1/g1MonitoringSupport.hpp 2017-06-14 11:45:05.639064444 +0900 +++ new/src/share/vm/gc/g1/g1MonitoringSupport.hpp 2017-06-14 11:45:05.542062500 +0900 @@ -122,6 +122,8 @@ CollectorCounters* _incremental_collection_counters; // full stop-the-world collections CollectorCounters* _full_collection_counters; + // stop-the-world phases in G1 + CollectorCounters* _conc_collection_counters; // young collection set counters. The _eden_counters, // _from_counters, and _to_counters are associated with // this "generational" counter. @@ -210,6 +212,9 @@ CollectorCounters* full_collection_counters() { return _full_collection_counters; } + CollectorCounters* conc_collection_counters() { + return _conc_collection_counters; + } GenerationCounters* young_collection_counters() { return _young_collection_counters; } --- old/src/share/vm/gc/g1/vm_operations_g1.cpp 2017-06-14 11:45:05.932070316 +0900 +++ new/src/share/vm/gc/g1/vm_operations_g1.cpp 2017-06-14 11:45:05.840068472 +0900 @@ -209,6 +209,8 @@ GCTraceCPUTime tcpu; G1CollectedHeap* g1h = G1CollectedHeap::heap(); GCTraceTime(Info, gc) t(_printGCMessage, g1h->concurrent_mark()->gc_timer_cm(), GCCause::_no_gc, true); + TraceCollectorStats tcs(g1h->g1mm()->conc_collection_counters()); + SvcGCMarker sgcm(SvcGCMarker::CONCURRENT); IsGCActiveMark x; _cl->do_void(); } --- old/src/share/vm/gc/shared/collectorCounters.hpp 2017-06-14 11:45:06.192075526 +0900 +++ new/src/share/vm/gc/shared/collectorCounters.hpp 2017-06-14 11:45:06.107073822 +0900 @@ -71,16 +71,19 @@ public: inline TraceCollectorStats(CollectorCounters* c) : - PerfTraceTimedEvent(c->time_counter(), c->invocation_counter()), + PerfTraceTimedEvent((c == NULL) ? NULL : c->time_counter(), + (c == NULL) ? NULL : c->invocation_counter()), _c(c) { - if (UsePerfData) { + if (UsePerfData && (_c != NULL)) { _c->last_entry_counter()->set_value(os::elapsed_counter()); } } inline ~TraceCollectorStats() { - if (UsePerfData) _c->last_exit_counter()->set_value(os::elapsed_counter()); + if (UsePerfData && (_c != NULL)) { + _c->last_exit_counter()->set_value(os::elapsed_counter()); + } } }; --- old/src/share/vm/gc/shared/vmGCOperations.hpp 2017-06-14 11:45:06.448080656 +0900 +++ new/src/share/vm/gc/shared/vmGCOperations.hpp 2017-06-14 11:45:06.363078953 +0900 @@ -227,7 +227,7 @@ private: JvmtiGCMarker _jgcm; public: - typedef enum { MINOR, FULL, OTHER } reason_type; + typedef enum { MINOR, FULL, CONCURRENT, OTHER } reason_type; SvcGCMarker(reason_type reason ) { VM_GC_Operation::notify_gc_begin(reason == FULL); --- old/src/share/vm/runtime/globals.hpp 2017-06-14 11:45:06.713085967 +0900 +++ new/src/share/vm/runtime/globals.hpp 2017-06-14 11:45:06.620084103 +0900 @@ -3834,6 +3834,9 @@ "0=off, 1=conservative, 2=aggressive") \ range(0, 2) \ \ + product(bool, EnableConcGCPerfCounter, false, \ + "Enable PerfCounter for STW in CMS GC") \ + \ /* Serviceability Support */ \ \ product(bool, ManagementServer, false, \ --- old/src/share/vm/runtime/perfData.hpp 2017-06-14 11:45:07.037092460 +0900 +++ new/src/share/vm/runtime/perfData.hpp 2017-06-14 11:45:06.952090756 +0900 @@ -916,22 +916,22 @@ public: inline PerfTraceTime(PerfLongCounter* timerp) : _timerp(timerp), _recursion_counter(NULL) { - if (!UsePerfData) return; + if (!UsePerfData || (_timerp == NULL)) return; _t.start(); } inline PerfTraceTime(PerfLongCounter* timerp, int* recursion_counter) : _timerp(timerp), _recursion_counter(recursion_counter) { - if (!UsePerfData || (_recursion_counter != NULL && - (*_recursion_counter)++ > 0)) return; + if (!UsePerfData || (_timerp == NULL) || + (_recursion_counter != NULL && (*_recursion_counter)++ > 0)) return; _t.start(); } - inline void suspend() { if (!UsePerfData) return; _t.stop(); } - inline void resume() { if (!UsePerfData) return; _t.start(); } + inline void suspend() { if (!UsePerfData || (_timerp == NULL)) return; _t.stop(); } + inline void resume() { if (!UsePerfData || (_timerp == NULL)) return; _t.start(); } inline ~PerfTraceTime() { - if (!UsePerfData || (_recursion_counter != NULL && - --(*_recursion_counter) > 0)) return; + if (!UsePerfData || (_timerp == NULL) || + (_recursion_counter != NULL && --(*_recursion_counter) > 0)) return; _t.stop(); _timerp->inc(_t.ticks()); } @@ -963,12 +963,12 @@ public: inline PerfTraceTimedEvent(PerfLongCounter* timerp, PerfLongCounter* eventp): PerfTraceTime(timerp), _eventp(eventp) { - if (!UsePerfData) return; + if (!UsePerfData || (timerp == NULL)) return; _eventp->inc(); } inline PerfTraceTimedEvent(PerfLongCounter* timerp, PerfLongCounter* eventp, int* recursion_counter): PerfTraceTime(timerp, recursion_counter), _eventp(eventp) { - if (!UsePerfData) return; + if (!UsePerfData || (timerp == NULL)) return; _eventp->inc(); } }; --- old/test/serviceability/tmtools/jstat/utils/JstatGcCauseResults.java 2017-06-14 11:45:07.312097971 +0900 +++ new/test/serviceability/tmtools/jstat/utils/JstatGcCauseResults.java 2017-06-14 11:45:07.224096207 +0900 @@ -25,8 +25,8 @@ * Results of running the JstatGcTool ("jstat -gccause ") * * Output example: - * S0 S1 E O M CCS YGC YGCT FGC FGCT GCT LGCC GCC - * 0.00 6.25 46.19 0.34 57.98 54.63 15305 1270.551 0 0.000 1270.551 Allocation Failure No GC + * S0 S1 E O M CCS YGC YGCT FGC FGCT CGC CGCT GCT LGCC GCC + * 0.00 6.25 46.19 0.34 57.98 54.63 15305 1270.551 0 0.000 0 0.00 1270.551 Allocation Failure No GC * Output description: * S0 Survivor space 0 utilization as a percentage of the space's current capacity. @@ -39,6 +39,8 @@ * YGCT Young generation garbage collection time. * FGC Number of full GC events. * FGCT Full garbage collection time. + * CGC Concurrent Collections (STW phase) + * CGCT Concurrent Garbage Collection Time (STW phase) * GCT Total garbage collection time. * LGCC Cause of last Garbage Collection. * GCC Cause of current Garbage Collection. @@ -72,6 +74,13 @@ assertThat(GCT >= 0, "Incorrect time value for GCT"); assertThat(GCT >= YGCT, "GCT < YGCT (total garbage collection time < young generation garbage collection time)"); + int CGC = getIntValue("CGC"); + float CGCT = getFloatValue("CGCT"); + assertThat(CGCT >= 0, "Incorrect time value for CGCT"); + if (CGC > 0) { + assertThat(CGCT > 0, "Number of concurrent GC events is " + CGC + ", but CGCT is 0"); + } + int FGC = getIntValue("FGC"); float FGCT = getFloatValue("FGCT"); assertThat(FGCT >= 0, "Incorrect time value for FGCT"); @@ -81,7 +90,7 @@ assertThat(GCT >= FGCT, "GCT < YGCT (total garbage collection time < full generation garbage collection time)"); - assertThat(checkFloatIsSum(GCT, YGCT, FGCT), "GCT != (YGCT + FGCT) " + "(GCT = " + GCT + ", YGCT = " + YGCT - + ", FGCT = " + FGCT + ", (YCGT + FGCT) = " + (YGCT + FGCT) + ")"); + assertThat(checkFloatIsSum(GCT, YGCT, CGCT, FGCT), "GCT != (YGCT + CGCT + FGCT) " + "(GCT = " + GCT + ", YGCT = " + YGCT + + ", CGCT = " + CGCT + ", FGCT = " + FGCT + ", (YCGT + CGCT + FGCT) = " + (YGCT + CGCT + FGCT) + ")"); } } --- old/test/serviceability/tmtools/jstat/utils/JstatGcResults.java 2017-06-14 11:45:07.572103181 +0900 +++ new/test/serviceability/tmtools/jstat/utils/JstatGcResults.java 2017-06-14 11:45:07.485101438 +0900 @@ -25,8 +25,8 @@ * Results of running the JstatGcTool ("jstat -gc ") * * Output example: - * (S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT - * 512.0 512.0 32.0 0.0 288768.0 168160.6 83968.0 288.1 4864.0 2820.3 512.0 279.7 18510 1559.208 0 0.000 1559.208 + * S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT CGC CGCT GCT + * 512.0 512.0 32.0 0.0 288768.0 168160.6 83968.0 288.1 4864.0 2820.3 512.0 279.7 18510 1559.208 0 0.000 0 0.0 1559.208 * * Output description: * S0C Current survivor space 0 capacity (KB). @@ -45,6 +45,8 @@ * YGCT Young generation garbage collection time. * FGC Number of full GC events. * FGCT Full garbage collection time. + * CGC Concurrent Collections (STW phase) + * CGCT Concurrent Garbage Collection Time (STW phase) * GCT Total garbage collection time. * */ @@ -101,6 +103,13 @@ assertThat(GCT >= 0, "Incorrect time value for GCT"); assertThat(GCT >= YGCT, "GCT < YGCT (total garbage collection time < young generation garbage collection time)"); + int CGC = getIntValue("CGC"); + float CGCT = getFloatValue("CGCT"); + assertThat(CGCT >= 0, "Incorrect time value for CGCT"); + if (CGC > 0) { + assertThat(CGCT > 0, "Number of concurrent GC events is " + CGC + ", but CGCT is 0"); + } + int FGC = getIntValue("FGC"); float FGCT = getFloatValue("FGCT"); assertThat(FGCT >= 0, "Incorrect time value for FGCT"); @@ -110,7 +119,7 @@ assertThat(GCT >= FGCT, "GCT < YGCT (total garbage collection time < full generation garbage collection time)"); - assertThat(checkFloatIsSum(GCT, YGCT, FGCT), "GCT != (YGCT + FGCT) " + "(GCT = " + GCT + ", YGCT = " + YGCT - + ", FGCT = " + FGCT + ", (YCGT + FGCT) = " + (YGCT + FGCT) + ")"); + assertThat(checkFloatIsSum(GCT, YGCT, CGCT, FGCT), "GCT != (YGCT + CGCT + FGCT) " + "(GCT = " + GCT + ", YGCT = " + YGCT + + ", CGCT = " + CGCT + ", FGCT = " + FGCT + ", (YCGT + CGCT + FGCT) = " + (YGCT + CGCT + FGCT) + ")"); } }