# HG changeset patch # User brutisso # Date 1435151067 -7200 # Node ID 317650db0f1cafb1c22116d0e25dfcf4d9825aee # Parent c8e4926f1d2cbcede8cb6170a6c65219f93499b5# Parent c9cc3289b80cebfd52ac8460949cf3b38f4c0438 Merge diff -r c8e4926f1d2c -r 317650db0f1c hotspot/src/share/vm/gc/g1/concurrentMark.cpp --- a/hotspot/src/share/vm/gc/g1/concurrentMark.cpp Wed Jun 24 13:26:12 2015 +0200 +++ b/hotspot/src/share/vm/gc/g1/concurrentMark.cpp Wed Jun 24 15:04:27 2015 +0200 @@ -1179,6 +1179,8 @@ }; void ConcurrentMark::scanRootRegions() { + double scan_start = os::elapsedTime(); + // Start of concurrent marking. ClassLoaderDataGraph::clear_claimed_marks(); @@ -1186,6 +1188,11 @@ // at least one root region to scan. So, if it's false, we // should not attempt to do any further work. if (root_regions()->scan_in_progress()) { + if (G1Log::fine()) { + gclog_or_tty->gclog_stamp(concurrent_gc_id()); + gclog_or_tty->print_cr("[GC concurrent-root-region-scan-start]"); + } + _parallel_marking_threads = calc_parallel_marking_threads(); assert(parallel_marking_threads() <= max_parallel_marking_threads(), "Maximum number of marking threads exceeded"); @@ -1195,6 +1202,11 @@ _parallel_workers->set_active_workers(active_workers); _parallel_workers->run_task(&task); + if (G1Log::fine()) { + gclog_or_tty->gclog_stamp(concurrent_gc_id()); + gclog_or_tty->print_cr("[GC concurrent-root-region-scan-end, %1.7lf secs]", os::elapsedTime() - scan_start); + } + // It's possible that has_aborted() is true here without actually // aborting the survivor scan earlier. This is OK as it's // mainly used for sanity checking. @@ -2993,6 +3005,11 @@ // abandon current marking iteration due to a Full GC void ConcurrentMark::abort() { + if (!cmThread()->during_cycle() || _has_aborted) { + // We haven't started a concurrent cycle or we have already aborted it. No need to do anything. + return; + } + // Clear all marks in the next bitmap for the next marking cycle. This will allow us to skip the next // concurrent bitmap clearing. _nextMarkBitMap->clearAll(); @@ -3010,12 +3027,8 @@ } _first_overflow_barrier_sync.abort(); _second_overflow_barrier_sync.abort(); - const GCId& gc_id = _g1h->gc_tracer_cm()->gc_id(); - if (!gc_id.is_undefined()) { - // We can do multiple full GCs before ConcurrentMarkThread::run() gets a chance - // to detect that it was aborted. Only keep track of the first GC id that we aborted. - _aborted_gc_id = gc_id; - } + _aborted_gc_id = _g1h->gc_tracer_cm()->gc_id(); + assert(!_aborted_gc_id.is_undefined(), "ConcurrentMark::abort() executed more than once?"); _has_aborted = true; SATBMarkQueueSet& satb_mq_set = JavaThread::satb_mark_queue_set(); diff -r c8e4926f1d2c -r 317650db0f1c hotspot/src/share/vm/gc/g1/concurrentMarkThread.cpp --- a/hotspot/src/share/vm/gc/g1/concurrentMarkThread.cpp Wed Jun 24 13:26:12 2015 +0200 +++ b/hotspot/src/share/vm/gc/g1/concurrentMarkThread.cpp Wed Jun 24 15:04:27 2015 +0200 @@ -78,7 +78,19 @@ } }; - +// We want to avoid that the logging from the concurrent thread is mixed +// with the logging from a STW GC. So, if necessary join the STS to ensure +// that the logging is done either before or after the STW logging. +void ConcurrentMarkThread::cm_log(bool doit, bool join_sts, const char* fmt, ...) { + if (doit) { + SuspendibleThreadSetJoiner sts_joiner(join_sts); + va_list args; + va_start(args, fmt); + gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); + gclog_or_tty->vprint_cr(fmt, args); + va_end(args); + } +} void ConcurrentMarkThread::run() { initialize_in_thread(); @@ -110,28 +122,12 @@ // without the root regions have been scanned which would be a // correctness issue. - double scan_start = os::elapsedTime(); if (!cm()->has_aborted()) { - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-root-region-scan-start]"); - } - _cm->scanRootRegions(); - - double scan_end = os::elapsedTime(); - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-root-region-scan-end, %1.7lf secs]", - scan_end - scan_start); - } } double mark_start_sec = os::elapsedTime(); - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-mark-start]"); - } + cm_log(G1Log::fine(), true, "[GC concurrent-mark-start]"); int iter = 0; do { @@ -151,25 +147,15 @@ os::sleep(current_thread, sleep_time_ms, false); } - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-mark-end, %1.7lf secs]", - mark_end_sec - mark_start_sec); - } + cm_log(G1Log::fine(), true, "[GC concurrent-mark-end, %1.7lf secs]", mark_end_sec - mark_start_sec); CMCheckpointRootsFinalClosure final_cl(_cm); VM_CGC_Operation op(&final_cl, "GC remark", true /* needs_pll */); VMThread::execute(&op); } if (cm()->restart_for_overflow()) { - if (G1TraceMarkStackOverflow) { - gclog_or_tty->print_cr("Restarting conc marking because of MS overflow " - "in remark (restart #%d).", iter); - } - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-mark-restart-for-overflow]"); - } + cm_log(G1TraceMarkStackOverflow, true, "Restarting conc marking because of MS overflow in remark (restart #%d).", iter); + cm_log(G1Log::fine(), true, "[GC concurrent-mark-restart-for-overflow]"); } } while (cm()->restart_for_overflow()); @@ -209,10 +195,7 @@ // reclaimed by cleanup. double cleanup_start_sec = os::elapsedTime(); - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-cleanup-start]"); - } + cm_log(G1Log::fine(), true, "[GC concurrent-cleanup-start]"); // Now do the concurrent cleanup operation. _cm->completeCleanup(); @@ -229,11 +212,7 @@ g1h->reset_free_regions_coming(); double cleanup_end_sec = os::elapsedTime(); - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-cleanup-end, %1.7lf secs]", - cleanup_end_sec - cleanup_start_sec); - } + cm_log(G1Log::fine(), true, "[GC concurrent-cleanup-end, %1.7lf secs]", cleanup_end_sec - cleanup_start_sec); } guarantee(cm()->cleanup_list_is_empty(), "at this point there should be no regions on the cleanup list"); @@ -266,13 +245,8 @@ SuspendibleThreadSetJoiner sts_join; if (!cm()->has_aborted()) { g1_policy->record_concurrent_mark_cleanup_completed(); - } - } - - if (cm()->has_aborted()) { - if (G1Log::fine()) { - gclog_or_tty->gclog_stamp(cm()->concurrent_gc_id()); - gclog_or_tty->print_cr("[GC concurrent-mark-abort]"); + } else { + cm_log(G1Log::fine(), false, "[GC concurrent-mark-abort]"); } } diff -r c8e4926f1d2c -r 317650db0f1c hotspot/src/share/vm/gc/g1/concurrentMarkThread.hpp --- a/hotspot/src/share/vm/gc/g1/concurrentMarkThread.hpp Wed Jun 24 13:26:12 2015 +0200 +++ b/hotspot/src/share/vm/gc/g1/concurrentMarkThread.hpp Wed Jun 24 15:04:27 2015 +0200 @@ -40,6 +40,7 @@ double _vtime_accum; // Accumulated virtual time. double _vtime_mark_accum; + void cm_log(bool doit, bool join_sts, const char* fmt, ...) ATTRIBUTE_PRINTF(4, 5); public: virtual void run(); diff -r c8e4926f1d2c -r 317650db0f1c hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp --- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Wed Jun 24 13:26:12 2015 +0200 +++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Wed Jun 24 15:04:27 2015 +0200 @@ -3867,6 +3867,21 @@ gclog_or_tty->flush(); } +void G1CollectedHeap::wait_for_root_region_scanning() { + double scan_wait_start = os::elapsedTime(); + // We have to wait until the CM threads finish scanning the + // root regions as it's the only way to ensure that all the + // objects on them have been correctly scanned before we start + // moving them during the GC. + bool waited = _cm->root_regions()->wait_until_scan_finished(); + double wait_time_ms = 0.0; + if (waited) { + double scan_wait_end = os::elapsedTime(); + wait_time_ms = (scan_wait_end - scan_wait_start) * 1000.0; + } + g1_policy()->phase_times()->record_root_region_scan_wait_time(wait_time_ms); +} + bool G1CollectedHeap::do_collection_pause_at_safepoint(double target_pause_time_ms) { assert_at_safepoint(true /* should_be_vm_thread */); @@ -3883,6 +3898,8 @@ SvcGCMarker sgcm(SvcGCMarker::MINOR); ResourceMark rm; + wait_for_root_region_scanning(); + G1Log::update_level(); print_heap_before_gc(); trace_heap_before_gc(_gc_tracer_stw); @@ -4004,19 +4021,6 @@ g1_policy()->record_collection_pause_start(sample_start_time_sec); - double scan_wait_start = os::elapsedTime(); - // We have to wait until the CM threads finish scanning the - // root regions as it's the only way to ensure that all the - // objects on them have been correctly scanned before we start - // moving them during the GC. - bool waited = _cm->root_regions()->wait_until_scan_finished(); - double wait_time_ms = 0.0; - if (waited) { - double scan_wait_end = os::elapsedTime(); - wait_time_ms = (scan_wait_end - scan_wait_start) * 1000.0; - } - g1_policy()->phase_times()->record_root_region_scan_wait_time(wait_time_ms); - #if YOUNG_LIST_VERBOSE gclog_or_tty->print_cr("\nAfter recording pause start.\nYoung_list:"); _young_list->print(); diff -r c8e4926f1d2c -r 317650db0f1c hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp --- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp Wed Jun 24 13:26:12 2015 +0200 +++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.hpp Wed Jun 24 15:04:27 2015 +0200 @@ -805,6 +805,8 @@ bool* succeeded, GCCause::Cause gc_cause); + void wait_for_root_region_scanning(); + // The guts of the incremental collection pause, executed by the vm // thread. It returns false if it is unable to do the collection due // to the GC locker being active, true otherwise