1.1 --- a/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Wed Jun 25 15:51:15 2014 -0700
1.2 +++ b/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp Thu Jun 19 13:31:14 2014 +0200
1.3 @@ -1999,7 +1999,7 @@
1.4 SerialOldTracer* gc_tracer = GenMarkSweep::gc_tracer();
1.5 gc_tracer->report_gc_start(gch->gc_cause(), gc_timer->gc_start());
1.6
1.7 - GCTraceTime t("CMS:MSC ", PrintGCDetails && Verbose, true, NULL);
1.8 + GCTraceTime t("CMS:MSC ", PrintGCDetails && Verbose, true, NULL, gc_tracer->gc_id());
1.9 if (PrintGC && Verbose && !(GCCause::is_user_requested_gc(gch->gc_cause()))) {
1.10 gclog_or_tty->print_cr("Compact ConcurrentMarkSweepGeneration after %d "
1.11 "collections passed to foreground collector", _full_gcs_since_conc_gc);
1.12 @@ -2509,8 +2509,10 @@
1.13 assert(ConcurrentMarkSweepThread::vm_thread_has_cms_token(),
1.14 "VM thread should have CMS token");
1.15
1.16 + // The gc id is created in register_foreground_gc_start if this collection is synchronous
1.17 + const GCId gc_id = _collectorState == InitialMarking ? GCId::peek() : _gc_tracer_cm->gc_id();
1.18 NOT_PRODUCT(GCTraceTime t("CMS:MS (foreground) ", PrintGCDetails && Verbose,
1.19 - true, NULL);)
1.20 + true, NULL, gc_id);)
1.21 if (UseAdaptiveSizePolicy) {
1.22 size_policy()->ms_collection_begin();
1.23 }
1.24 @@ -3527,6 +3529,7 @@
1.25 public:
1.26 CMSPhaseAccounting(CMSCollector *collector,
1.27 const char *phase,
1.28 + const GCId gc_id,
1.29 bool print_cr = true);
1.30 ~CMSPhaseAccounting();
1.31
1.32 @@ -3535,6 +3538,7 @@
1.33 const char *_phase;
1.34 elapsedTimer _wallclock;
1.35 bool _print_cr;
1.36 + const GCId _gc_id;
1.37
1.38 public:
1.39 // Not MT-safe; so do not pass around these StackObj's
1.40 @@ -3550,15 +3554,15 @@
1.41
1.42 CMSPhaseAccounting::CMSPhaseAccounting(CMSCollector *collector,
1.43 const char *phase,
1.44 + const GCId gc_id,
1.45 bool print_cr) :
1.46 - _collector(collector), _phase(phase), _print_cr(print_cr) {
1.47 + _collector(collector), _phase(phase), _print_cr(print_cr), _gc_id(gc_id) {
1.48
1.49 if (PrintCMSStatistics != 0) {
1.50 _collector->resetYields();
1.51 }
1.52 if (PrintGCDetails) {
1.53 - gclog_or_tty->date_stamp(PrintGCDateStamps);
1.54 - gclog_or_tty->stamp(PrintGCTimeStamps);
1.55 + gclog_or_tty->gclog_stamp(_gc_id);
1.56 gclog_or_tty->print_cr("[%s-concurrent-%s-start]",
1.57 _collector->cmsGen()->short_name(), _phase);
1.58 }
1.59 @@ -3572,8 +3576,7 @@
1.60 _collector->stopTimer();
1.61 _wallclock.stop();
1.62 if (PrintGCDetails) {
1.63 - gclog_or_tty->date_stamp(PrintGCDateStamps);
1.64 - gclog_or_tty->stamp(PrintGCTimeStamps);
1.65 + gclog_or_tty->gclog_stamp(_gc_id);
1.66 gclog_or_tty->print("[%s-concurrent-%s: %3.3f/%3.3f secs]",
1.67 _collector->cmsGen()->short_name(),
1.68 _phase, _collector->timerValue(), _wallclock.seconds());
1.69 @@ -3671,7 +3674,7 @@
1.70 setup_cms_unloading_and_verification_state();
1.71
1.72 NOT_PRODUCT(GCTraceTime t("\ncheckpointRootsInitialWork",
1.73 - PrintGCDetails && Verbose, true, _gc_timer_cm);)
1.74 + PrintGCDetails && Verbose, true, _gc_timer_cm, _gc_tracer_cm->gc_id());)
1.75 if (UseAdaptiveSizePolicy) {
1.76 size_policy()->checkpoint_roots_initial_begin();
1.77 }
1.78 @@ -3796,7 +3799,7 @@
1.79
1.80 CMSTokenSyncWithLocks ts(true, bitMapLock());
1.81 TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
1.82 - CMSPhaseAccounting pa(this, "mark", !PrintGCDetails);
1.83 + CMSPhaseAccounting pa(this, "mark", _gc_tracer_cm->gc_id(), !PrintGCDetails);
1.84 res = markFromRootsWork(asynch);
1.85 if (res) {
1.86 _collectorState = Precleaning;
1.87 @@ -4519,7 +4522,7 @@
1.88 _start_sampling = false;
1.89 }
1.90 TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
1.91 - CMSPhaseAccounting pa(this, "preclean", !PrintGCDetails);
1.92 + CMSPhaseAccounting pa(this, "preclean", _gc_tracer_cm->gc_id(), !PrintGCDetails);
1.93 preclean_work(CMSPrecleanRefLists1, CMSPrecleanSurvivors1);
1.94 }
1.95 CMSTokenSync x(true); // is cms thread
1.96 @@ -4548,7 +4551,7 @@
1.97 // we will never do an actual abortable preclean cycle.
1.98 if (get_eden_used() > CMSScheduleRemarkEdenSizeThreshold) {
1.99 TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
1.100 - CMSPhaseAccounting pa(this, "abortable-preclean", !PrintGCDetails);
1.101 + CMSPhaseAccounting pa(this, "abortable-preclean", _gc_tracer_cm->gc_id(), !PrintGCDetails);
1.102 // We need more smarts in the abortable preclean
1.103 // loop below to deal with cases where allocation
1.104 // in young gen is very very slow, and our precleaning
1.105 @@ -4693,7 +4696,7 @@
1.106 GCTimer *gc_timer = NULL; // Currently not tracing concurrent phases
1.107 rp->preclean_discovered_references(
1.108 rp->is_alive_non_header(), &keep_alive, &complete_trace, &yield_cl,
1.109 - gc_timer);
1.110 + gc_timer, _gc_tracer_cm->gc_id());
1.111 }
1.112
1.113 if (clean_survivor) { // preclean the active survivor space(s)
1.114 @@ -5036,7 +5039,7 @@
1.115 // expect it to be false and set to true
1.116 FlagSetting fl(gch->_is_gc_active, false);
1.117 NOT_PRODUCT(GCTraceTime t("Scavenge-Before-Remark",
1.118 - PrintGCDetails && Verbose, true, _gc_timer_cm);)
1.119 + PrintGCDetails && Verbose, true, _gc_timer_cm, _gc_tracer_cm->gc_id());)
1.120 int level = _cmsGen->level() - 1;
1.121 if (level >= 0) {
1.122 gch->do_collection(true, // full (i.e. force, see below)
1.123 @@ -5065,7 +5068,7 @@
1.124 void CMSCollector::checkpointRootsFinalWork(bool asynch,
1.125 bool clear_all_soft_refs, bool init_mark_was_synchronous) {
1.126
1.127 - NOT_PRODUCT(GCTraceTime tr("checkpointRootsFinalWork", PrintGCDetails, false, _gc_timer_cm);)
1.128 + NOT_PRODUCT(GCTraceTime tr("checkpointRootsFinalWork", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());)
1.129
1.130 assert(haveFreelistLocks(), "must have free list locks");
1.131 assert_lock_strong(bitMapLock());
1.132 @@ -5120,11 +5123,11 @@
1.133 // the most recent young generation GC, minus those cleaned up by the
1.134 // concurrent precleaning.
1.135 if (CMSParallelRemarkEnabled && CollectedHeap::use_parallel_gc_threads()) {
1.136 - GCTraceTime t("Rescan (parallel) ", PrintGCDetails, false, _gc_timer_cm);
1.137 + GCTraceTime t("Rescan (parallel) ", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.138 do_remark_parallel();
1.139 } else {
1.140 GCTraceTime t("Rescan (non-parallel) ", PrintGCDetails, false,
1.141 - _gc_timer_cm);
1.142 + _gc_timer_cm, _gc_tracer_cm->gc_id());
1.143 do_remark_non_parallel();
1.144 }
1.145 }
1.146 @@ -5137,7 +5140,7 @@
1.147 verify_overflow_empty();
1.148
1.149 {
1.150 - NOT_PRODUCT(GCTraceTime ts("refProcessingWork", PrintGCDetails, false, _gc_timer_cm);)
1.151 + NOT_PRODUCT(GCTraceTime ts("refProcessingWork", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());)
1.152 refProcessingWork(asynch, clear_all_soft_refs);
1.153 }
1.154 verify_work_stacks_empty();
1.155 @@ -5922,7 +5925,7 @@
1.156 NULL, // space is set further below
1.157 &_markBitMap, &_markStack, &mrias_cl);
1.158 {
1.159 - GCTraceTime t("grey object rescan", PrintGCDetails, false, _gc_timer_cm);
1.160 + GCTraceTime t("grey object rescan", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.161 // Iterate over the dirty cards, setting the corresponding bits in the
1.162 // mod union table.
1.163 {
1.164 @@ -5959,7 +5962,7 @@
1.165 Universe::verify();
1.166 }
1.167 {
1.168 - GCTraceTime t("root rescan", PrintGCDetails, false, _gc_timer_cm);
1.169 + GCTraceTime t("root rescan", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.170
1.171 verify_work_stacks_empty();
1.172
1.173 @@ -5981,7 +5984,7 @@
1.174 }
1.175
1.176 {
1.177 - GCTraceTime t("visit unhandled CLDs", PrintGCDetails, false, _gc_timer_cm);
1.178 + GCTraceTime t("visit unhandled CLDs", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.179
1.180 verify_work_stacks_empty();
1.181
1.182 @@ -6000,7 +6003,7 @@
1.183 }
1.184
1.185 {
1.186 - GCTraceTime t("dirty klass scan", PrintGCDetails, false, _gc_timer_cm);
1.187 + GCTraceTime t("dirty klass scan", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.188
1.189 verify_work_stacks_empty();
1.190
1.191 @@ -6202,7 +6205,7 @@
1.192 _span, &_markBitMap, &_markStack,
1.193 &cmsKeepAliveClosure, false /* !preclean */);
1.194 {
1.195 - GCTraceTime t("weak refs processing", PrintGCDetails, false, _gc_timer_cm);
1.196 + GCTraceTime t("weak refs processing", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.197
1.198 ReferenceProcessorStats stats;
1.199 if (rp->processing_is_mt()) {
1.200 @@ -6227,13 +6230,15 @@
1.201 &cmsKeepAliveClosure,
1.202 &cmsDrainMarkingStackClosure,
1.203 &task_executor,
1.204 - _gc_timer_cm);
1.205 + _gc_timer_cm,
1.206 + _gc_tracer_cm->gc_id());
1.207 } else {
1.208 stats = rp->process_discovered_references(&_is_alive_closure,
1.209 &cmsKeepAliveClosure,
1.210 &cmsDrainMarkingStackClosure,
1.211 NULL,
1.212 - _gc_timer_cm);
1.213 + _gc_timer_cm,
1.214 + _gc_tracer_cm->gc_id());
1.215 }
1.216 _gc_tracer_cm->report_gc_reference_stats(stats);
1.217
1.218 @@ -6244,7 +6249,7 @@
1.219
1.220 if (should_unload_classes()) {
1.221 {
1.222 - GCTraceTime t("class unloading", PrintGCDetails, false, _gc_timer_cm);
1.223 + GCTraceTime t("class unloading", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.224
1.225 // Unload classes and purge the SystemDictionary.
1.226 bool purged_class = SystemDictionary::do_unloading(&_is_alive_closure);
1.227 @@ -6257,7 +6262,7 @@
1.228 }
1.229
1.230 {
1.231 - GCTraceTime t("scrub symbol table", PrintGCDetails, false, _gc_timer_cm);
1.232 + GCTraceTime t("scrub symbol table", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.233 // Clean up unreferenced symbols in symbol table.
1.234 SymbolTable::unlink();
1.235 }
1.236 @@ -6266,7 +6271,7 @@
1.237 // CMS doesn't use the StringTable as hard roots when class unloading is turned off.
1.238 // Need to check if we really scanned the StringTable.
1.239 if ((roots_scanning_options() & SharedHeap::SO_Strings) == 0) {
1.240 - GCTraceTime t("scrub string table", PrintGCDetails, false, _gc_timer_cm);
1.241 + GCTraceTime t("scrub string table", PrintGCDetails, false, _gc_timer_cm, _gc_tracer_cm->gc_id());
1.242 // Delete entries for dead interned strings.
1.243 StringTable::unlink(&_is_alive_closure);
1.244 }
1.245 @@ -6333,7 +6338,7 @@
1.246 _intra_sweep_timer.start();
1.247 if (asynch) {
1.248 TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
1.249 - CMSPhaseAccounting pa(this, "sweep", !PrintGCDetails);
1.250 + CMSPhaseAccounting pa(this, "sweep", _gc_tracer_cm->gc_id(), !PrintGCDetails);
1.251 // First sweep the old gen
1.252 {
1.253 CMSTokenSyncWithLocks ts(true, _cmsGen->freelistLock(),
1.254 @@ -6554,7 +6559,7 @@
1.255 // Clear the mark bitmap (no grey objects to start with)
1.256 // for the next cycle.
1.257 TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
1.258 - CMSPhaseAccounting cmspa(this, "reset", !PrintGCDetails);
1.259 + CMSPhaseAccounting cmspa(this, "reset", _gc_tracer_cm->gc_id(), !PrintGCDetails);
1.260
1.261 HeapWord* curAddr = _markBitMap.startWord();
1.262 while (curAddr < _markBitMap.endWord()) {
1.263 @@ -6620,7 +6625,7 @@
1.264 void CMSCollector::do_CMS_operation(CMS_op_type op, GCCause::Cause gc_cause) {
1.265 gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
1.266 TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
1.267 - GCTraceTime t(GCCauseString("GC", gc_cause), PrintGC, !PrintGCDetails, NULL);
1.268 + GCTraceTime t(GCCauseString("GC", gc_cause), PrintGC, !PrintGCDetails, NULL, _gc_tracer_cm->gc_id());
1.269 TraceCollectorStats tcs(counters());
1.270
1.271 switch (op) {
