--- a/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Wed Jun 18 12:39:57 2014 -0700
+++ b/hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Thu Jun 19 13:31:14 2014 +0200
@@ -2024,7 +2024,7 @@
SerialOldTracer* gc_tracer = GenMarkSweep::gc_tracer();
gc_tracer->report_gc_start(gch->gc_cause(), gc_timer->gc_start());
- GCTraceTime t("CMS:MSC ", PrintGCDetails && Verbose, true, NULL);
+ GCTraceTime t("CMS:MSC ", PrintGCDetails && Verbose, true, NULL, gc_tracer->gc_id());
if (PrintGC && Verbose && !(GCCause::is_user_requested_gc(gch->gc_cause()))) {
gclog_or_tty->print_cr("Compact ConcurrentMarkSweepGeneration after %d "
"collections passed to foreground collector", _full_gcs_since_conc_gc);
@@ -2534,8 +2534,10 @@
assert(ConcurrentMarkSweepThread::vm_thread_has_cms_token(),
"VM thread should have CMS token");
+ // The gc id is created in register_foreground_gc_start if this collection is synchronous
+ const GCId gc_id = _collectorState == InitialMarking ? GCId::peek() : _gc_tracer_cm->gc_id();
NOT_PRODUCT(GCTraceTime t("CMS:MS (foreground) ", PrintGCDetails && Verbose,
- true, NULL);)
+ true, NULL, gc_id);)
if (UseAdaptiveSizePolicy) {
size_policy()->ms_collection_begin();
}
@@ -3538,6 +3540,7 @@
public:
CMSPhaseAccounting(CMSCollector *collector,
const char *phase,
+ const GCId gc_id,
bool print_cr = true);
~CMSPhaseAccounting();
@@ -3546,6 +3549,7 @@
const char *_phase;
elapsedTimer _wallclock;
bool _print_cr;
+ const GCId _gc_id;
public:
// Not MT-safe; so do not pass around these StackObj's
@@ -3561,15 +3565,15 @@
CMSPhaseAccounting::CMSPhaseAccounting(CMSCollector *collector,
const char *phase,
+ const GCId gc_id,
bool print_cr) :
- _collector(collector), _phase(phase), _print_cr(print_cr) {
+ _collector(collector), _phase(phase), _print_cr(print_cr), _gc_id(gc_id) {
if (PrintCMSStatistics != 0) {
_collector->resetYields();
}
if (PrintGCDetails) {
- gclog_or_tty->date_stamp(PrintGCDateStamps);
- gclog_or_tty->stamp(PrintGCTimeStamps);
+ gclog_or_tty->gclog_stamp(_gc_id);
gclog_or_tty->print_cr("[%s-concurrent-%s-start]",
_collector->cmsGen()->short_name(), _phase);
}
@@ -3583,8 +3587,7 @@
_collector->stopTimer();
_wallclock.stop();
if (PrintGCDetails) {
- gclog_or_tty->date_stamp(PrintGCDateStamps);
- gclog_or_tty->stamp(PrintGCTimeStamps);
+ gclog_or_tty->gclog_stamp(_gc_id);
gclog_or_tty->print("[%s-concurrent-%s: %3.3f/%3.3f secs]",
_collector->cmsGen()->short_name(),
_phase, _collector->timerValue(), _wallclock.seconds());
@@ -3682,7 +3685,7 @@
setup_cms_unloading_and_verification_state();
NOT_PRODUCT(GCTraceTime t("\ncheckpointRootsInitialWork",
- PrintGCDetails && Verbose, true, _gc_timer_cm);)
+ PrintGCDetails && Verbose, true, _gc_timer_cm, _gc_tracer_cm->gc_id());)
if (UseAdaptiveSizePolicy) {
size_policy()->checkpoint_roots_initial_begin();
}
@@ -3799,7 +3802,7 @@
CMSTokenSyncWithLocks ts(true, bitMapLock());
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- CMSPhaseAccounting pa(this, "mark", !PrintGCDetails);
+ CMSPhaseAccounting pa(this, "mark", _gc_tracer_cm->gc_id(), !PrintGCDetails);
res = markFromRootsWork(asynch);
if (res) {
_collectorState = Precleaning;
@@ -4522,7 +4525,7 @@
_start_sampling = false;
}
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- CMSPhaseAccounting pa(this, "preclean", !PrintGCDetails);
+ CMSPhaseAccounting pa(this, "preclean", _gc_tracer_cm->gc_id(), !PrintGCDetails);
preclean_work(CMSPrecleanRefLists1, CMSPrecleanSurvivors1);
}
CMSTokenSync x(true); // is cms thread
@@ -4551,7 +4554,7 @@
// we will never do an actual abortable preclean cycle.
if (get_eden_used() > CMSScheduleRemarkEdenSizeThreshold) {
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- CMSPhaseAccounting pa(this, "abortable-preclean", !PrintGCDetails);
+ CMSPhaseAccounting pa(this, "abortable-preclean", _gc_tracer_cm->gc_id(), !PrintGCDetails);
// We need more smarts in the abortable preclean
// loop below to deal with cases where allocation
// in young gen is very very slow, and our precleaning
@@ -4696,7 +4699,7 @@
GCTimer *gc_timer = NULL; // Currently not tracing concurrent phases
rp->preclean_discovered_references(
rp->is_alive_non_header(), &keep_alive, &complete_trace, &yield_cl,
- gc_timer);
+ gc_timer, _gc_tracer_cm->gc_id());
}
if (clean_survivor) { // preclean the active survivor space(s)
@@ -5039,7 +5042,7 @@
// expect it to be false and set to true
FlagSetting fl(gch->_is_gc_active, false);
NOT_PRODUCT(GCTraceTime t("Scavenge-Before-Remark",
- PrintGCDetails && Verbose, true, _gc_timer_cm);)
+ PrintGCDetails && Verbose, true, _gc_timer_cm, _gc_tracer_cm->gc_id());)
int level = _cmsGen->level() - 1;
if (level >= 0) {
gch->do_collection(true, // full (i.e. force, see below)
@@ -5068,7 +5071,7 @@
void CMSCollector::checkpointRootsFinalWork(bool asynch,
bool clear_all_soft_refs, bool init_mark_was_synchronous) {
- NOT_PRODUCT(GCTraceTime tr("checkpointRootsFinalWork", PrintGCDetails, false, _gc_timer_cm);)
+ NOT_PRODUCT(GCTraceTime tr("checkpointRootsFinalWork", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());)
assert(haveFreelistLocks(), "must have free list locks");
assert_lock_strong(bitMapLock());
@@ -5123,11 +5126,11 @@
// the most recent young generation GC, minus those cleaned up by the
// concurrent precleaning.
if (CMSParallelRemarkEnabled && CollectedHeap::use_parallel_gc_threads()) {
- GCTraceTime t("Rescan (parallel) ", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("Rescan (parallel) ", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
do_remark_parallel();
} else {
GCTraceTime t("Rescan (non-parallel) ", PrintGCDetails, false,
- _gc_timer_cm);
+ _gc_timer_cm, _gc_tracer_cm->gc_id());
do_remark_non_parallel();
}
}
@@ -5140,7 +5143,7 @@
verify_overflow_empty();
{
- NOT_PRODUCT(GCTraceTime ts("refProcessingWork", PrintGCDetails, false, _gc_timer_cm);)
+ NOT_PRODUCT(GCTraceTime ts("refProcessingWork", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());)
refProcessingWork(asynch, clear_all_soft_refs);
}
verify_work_stacks_empty();
@@ -5921,7 +5924,7 @@
NULL, // space is set further below
&_markBitMap, &_markStack, &mrias_cl);
{
- GCTraceTime t("grey object rescan", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("grey object rescan", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
// Iterate over the dirty cards, setting the corresponding bits in the
// mod union table.
{
@@ -5958,7 +5961,7 @@
Universe::verify();
}
{
- GCTraceTime t("root rescan", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("root rescan", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
verify_work_stacks_empty();
@@ -5978,7 +5981,7 @@
}
{
- GCTraceTime t("visit unhandled CLDs", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("visit unhandled CLDs", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
verify_work_stacks_empty();
@@ -5997,7 +6000,7 @@
}
{
- GCTraceTime t("dirty klass scan", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("dirty klass scan", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
verify_work_stacks_empty();
@@ -6199,7 +6202,7 @@
_span, &_markBitMap, &_markStack,
&cmsKeepAliveClosure, false /* !preclean */);
{
- GCTraceTime t("weak refs processing", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("weak refs processing", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
ReferenceProcessorStats stats;
if (rp->processing_is_mt()) {
@@ -6224,13 +6227,15 @@
&cmsKeepAliveClosure,
&cmsDrainMarkingStackClosure,
&task_executor,
- _gc_timer_cm);
+ _gc_timer_cm,
+ _gc_tracer_cm->gc_id());
} else {
stats = rp->process_discovered_references(&_is_alive_closure,
&cmsKeepAliveClosure,
&cmsDrainMarkingStackClosure,
NULL,
- _gc_timer_cm);
+ _gc_timer_cm,
+ _gc_tracer_cm->gc_id());
}
_gc_tracer_cm->report_gc_reference_stats(stats);
@@ -6241,7 +6246,7 @@
if (should_unload_classes()) {
{
- GCTraceTime t("class unloading", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("class unloading", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
// Unload classes and purge the SystemDictionary.
bool purged_class = SystemDictionary::do_unloading(&_is_alive_closure);
@@ -6254,7 +6259,7 @@
}
{
- GCTraceTime t("scrub symbol table", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("scrub symbol table", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
// Clean up unreferenced symbols in symbol table.
SymbolTable::unlink();
}
@@ -6263,7 +6268,7 @@
// CMS doesn't use the StringTable as hard roots when class unloading is turned off.
// Need to check if we really scanned the StringTable.
if ((roots_scanning_options() & SharedHeap::SO_Strings) == 0) {
- GCTraceTime t("scrub string table", PrintGCDetails, false, _gc_timer_cm);
+ GCTraceTime t("scrub string table", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
// Delete entries for dead interned strings.
StringTable::unlink(&_is_alive_closure);
}
@@ -6330,7 +6335,7 @@
_intra_sweep_timer.start();
if (asynch) {
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- CMSPhaseAccounting pa(this, "sweep", !PrintGCDetails);
+ CMSPhaseAccounting pa(this, "sweep", _gc_tracer_cm->gc_id(), !PrintGCDetails);
// First sweep the old gen
{
CMSTokenSyncWithLocks ts(true, _cmsGen->freelistLock(),
@@ -6551,7 +6556,7 @@
// Clear the mark bitmap (no grey objects to start with)
// for the next cycle.
TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
- CMSPhaseAccounting cmspa(this, "reset", !PrintGCDetails);
+ CMSPhaseAccounting cmspa(this, "reset", _gc_tracer_cm->gc_id(), !PrintGCDetails);
HeapWord* curAddr = _markBitMap.startWord();
while (curAddr < _markBitMap.endWord()) {
@@ -6617,7 +6622,7 @@
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);
- GCTraceTime t(GCCauseString("GC", gc_cause), PrintGC, !PrintGCDetails, NULL);
+ GCTraceTime t(GCCauseString("GC", gc_cause), PrintGC, !PrintGCDetails, NULL, _gc_tracer_cm->gc_id());
TraceCollectorStats tcs(counters());
switch (op) {