archive/jdk
1
0
Fork 0
mirror of https://github.com/openjdk/jdk.git synced 2025-08-28 15:24:43 +02:00
Code Issues Projects Releases Packages Wiki Activity Actions

8043607: Add a GC id as a log decoration similar to PrintGCTimeStamps

Browse source 
Reviewed-by: jwilhelm, ehelin, tschatzl
This commit is contained in:
Bengt Rutisson 2014-06-19 13:31:14 +02:00
parent ad2e593b80
commit 9672a26d51
32 changed files with 404 additions and 174 deletions
Download patch file Download diff file Expand all files Collapse all files

65
hotspot/src/share/vm/gc_implementation/concurrentMarkSweep/concurrentMarkSweepGeneration.cpp
View file

@ -2024,7 +2024,7 @@ void CMSCollector::do_compaction_work(bool clear_all_soft_refs) {
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 @@ void CMSCollector::collect_in_foreground(bool clear_all_soft_refs, GCCause::Caus
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 @@ class CMSPhaseAccounting: public StackObj {
public:
CMSPhaseAccounting(CMSCollector *collector,
const char *phase,
const GCId gc_id,
bool print_cr = true);
~CMSPhaseAccounting();
@ -3546,6 +3549,7 @@ class CMSPhaseAccounting: public StackObj {
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 @@ class CMSPhaseAccounting: public StackObj {
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 @@ CMSPhaseAccounting::~CMSPhaseAccounting() {
_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 @@ void CMSCollector::checkpointRootsInitialWork(bool asynch) {
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 @@ bool CMSCollector::markFromRoots(bool asynch) {
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 @@ void CMSCollector::preclean() {
_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 @@ void CMSCollector::abortable_preclean() {
// 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 @@ size_t CMSCollector::preclean_work(bool clean_refs, bool clean_survivor) {
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 @@ void CMSCollector::checkpointRootsFinal(bool asynch,
// 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::checkpointRootsFinal(bool asynch,
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 @@ void CMSCollector::checkpointRootsFinalWork(bool asynch,
// 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 @@ void CMSCollector::checkpointRootsFinalWork(bool asynch,
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 @@ void CMSCollector::do_remark_non_parallel() {
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 @@ void CMSCollector::do_remark_non_parallel() {
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 @@ void CMSCollector::do_remark_non_parallel() {
}
{
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 @@ void CMSCollector::do_remark_non_parallel() {
}
{
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 @@ void CMSCollector::refProcessingWork(bool asynch, bool clear_all_soft_refs) {
_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 @@ void CMSCollector::refProcessingWork(bool asynch, bool clear_all_soft_refs) {
&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 @@ void CMSCollector::refProcessingWork(bool asynch, bool clear_all_soft_refs) {
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 @@ void CMSCollector::refProcessingWork(bool asynch, bool clear_all_soft_refs) {
}
{
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 @@ void CMSCollector::refProcessingWork(bool asynch, bool clear_all_soft_refs) {
// 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 @@ void CMSCollector::sweep(bool asynch) {
_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 @@ void CMSCollector::reset(bool asynch) {
// 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::reset(bool asynch) {
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) {