< prev index next >

src/share/vm/gc/g1/concurrentMark.cpp

Print this page

        

*** 29,40 **** #include "gc/g1/concurrentMark.inline.hpp" #include "gc/g1/concurrentMarkThread.inline.hpp" #include "gc/g1/g1CollectedHeap.inline.hpp" #include "gc/g1/g1CollectorPolicy.hpp" #include "gc/g1/g1CollectorState.hpp" - #include "gc/g1/g1ErgoVerbose.hpp" - #include "gc/g1/g1Log.hpp" #include "gc/g1/g1OopClosures.inline.hpp" #include "gc/g1/g1RemSet.hpp" #include "gc/g1/g1StringDedup.hpp" #include "gc/g1/heapRegion.inline.hpp" #include "gc/g1/heapRegionManager.inline.hpp" --- 29,38 ----
*** 48,57 **** --- 46,56 ---- #include "gc/shared/genOopClosures.inline.hpp" #include "gc/shared/referencePolicy.hpp" #include "gc/shared/strongRootsScope.hpp" #include "gc/shared/taskqueue.inline.hpp" #include "gc/shared/vmGCOperations.hpp" + #include "logging/log.hpp" #include "memory/allocation.hpp" #include "memory/resourceArea.hpp" #include "oops/oop.inline.hpp" #include "runtime/atomic.inline.hpp" #include "runtime/handles.inline.hpp"
*** 277,289 **** assert(isEmpty(), "stack should been emptied while handling overflow"); assert(_capacity <= (jint) MarkStackSizeMax, "stack bigger than permitted"); // Clear expansion flag _should_expand = false; if (_capacity == (jint) MarkStackSizeMax) { ! if (PrintGCDetails && Verbose) { ! gclog_or_tty->print_cr(" (benign) Can't expand marking stack capacity, at max size limit"); ! } return; } // Double capacity if possible jint new_capacity = MIN2(_capacity*2, (jint) MarkStackSizeMax); // Do not give up existing stack until we have managed to --- 276,286 ---- assert(isEmpty(), "stack should been emptied while handling overflow"); assert(_capacity <= (jint) MarkStackSizeMax, "stack bigger than permitted"); // Clear expansion flag _should_expand = false; if (_capacity == (jint) MarkStackSizeMax) { ! log_trace(gc)("(benign) Can't expand marking stack capacity, at max size limit"); return; } // Double capacity if possible jint new_capacity = MIN2(_capacity*2, (jint) MarkStackSizeMax); // Do not give up existing stack until we have managed to
*** 299,315 **** } _base = (oop*)(_virtual_space.low()); _index = 0; _capacity = new_capacity; } else { - if (PrintGCDetails && Verbose) { // Failed to double capacity, continue; ! gclog_or_tty->print(" (benign) Failed to expand marking stack capacity from " ! SIZE_FORMAT "K to " SIZE_FORMAT "K", _capacity / K, new_capacity / K); } - } } void CMMarkStack::set_should_expand() { // If we're resetting the marking state because of an // marking stack overflow, record that we should, if --- 296,309 ---- } _base = (oop*)(_virtual_space.low()); _index = 0; _capacity = new_capacity; } else { // Failed to double capacity, continue; ! log_trace(gc)("(benign) Failed to expand marking stack capacity from " SIZE_FORMAT "K to " SIZE_FORMAT "K", _capacity / K, new_capacity / K); } } void CMMarkStack::set_should_expand() { // If we're resetting the marking state because of an // marking stack overflow, record that we should, if
*** 574,591 **** _cleanup_task_overhead = marking_task_overhead(); } _cleanup_sleep_factor = (1.0 - cleanup_task_overhead()) / cleanup_task_overhead(); - #if 0 - gclog_or_tty->print_cr("Marking Threads %d", parallel_marking_threads()); - gclog_or_tty->print_cr("CM Marking Task Overhead %1.4lf", marking_task_overhead()); - gclog_or_tty->print_cr("CM Sleep Factor %1.4lf", sleep_factor()); - gclog_or_tty->print_cr("CL Marking Task Overhead %1.4lf", cleanup_task_overhead()); - gclog_or_tty->print_cr("CL Sleep Factor %1.4lf", cleanup_sleep_factor()); - #endif - _parallel_workers = new WorkGang("G1 Marker", _max_parallel_marking_threads, false, true); if (_parallel_workers == NULL) { vm_exit_during_initialization("Failed necessary allocation."); } else { --- 568,577 ----
*** 926,939 **** // we exit this method to abort the pause and restart concurrent // marking. reset_marking_state(true /* clear_overflow */); force_overflow()->update(); ! if (G1Log::fine()) { ! gclog_or_tty->gclog_stamp(); ! gclog_or_tty->print_cr("[GC concurrent-mark-reset-for-overflow]"); ! } } } // after this, each task should reset its own data structures then // then go into the second barrier --- 912,922 ---- // we exit this method to abort the pause and restart concurrent // marking. reset_marking_state(true /* clear_overflow */); force_overflow()->update(); ! log_info(gc)("GC concurrent-mark-reset-for-overflow"); } } // after this, each task should reset its own data structures then // then go into the second barrier
*** 1100,1127 **** // scan_in_progress() will have been set to true only if there was // 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(); ! 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"); uint active_workers = MAX2(1U, parallel_marking_threads()); CMRootRegionScanTask task(this); _parallel_workers->set_active_workers(active_workers); _parallel_workers->run_task(&task); ! if (G1Log::fine()) { ! gclog_or_tty->gclog_stamp(); ! 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. root_regions()->scan_finished(); --- 1083,1104 ---- // scan_in_progress() will have been set to true only if there was // 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()) { ! log_info(gc)("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"); uint active_workers = MAX2(1U, parallel_marking_threads()); CMRootRegionScanTask task(this); _parallel_workers->set_active_workers(active_workers); _parallel_workers->run_task(&task); ! log_info(gc)("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. root_regions()->scan_finished();
*** 1154,1179 **** _parallel_workers->set_active_workers(active_workers); _parallel_workers->run_task(&markingTask); print_stats(); } - // Helper class to get rid of some boilerplate code. - class G1CMTraceTime : public StackObj { - GCTraceTimeImpl _gc_trace_time; - static bool doit_and_prepend(bool doit) { - if (doit) { - gclog_or_tty->put(' '); - } - return doit; - } - - public: - G1CMTraceTime(const char* title, bool doit) - : _gc_trace_time(title, doit_and_prepend(doit), false, G1CollectedHeap::heap()->gc_timer_cm()) { - } - }; - void ConcurrentMark::checkpointRootsFinal(bool clear_all_soft_refs) { // world is stopped at this checkpoint assert(SafepointSynchronize::is_at_safepoint(), "world should be stopped"); --- 1131,1140 ----
*** 1188,1199 **** SvcGCMarker sgcm(SvcGCMarker::OTHER); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, ! " VerifyDuringGC:(before)"); } g1h->check_bitmaps("Remark Start"); G1CollectorPolicy* g1p = g1h->g1_policy(); g1p->record_concurrent_mark_remark_start(); --- 1149,1159 ---- SvcGCMarker sgcm(SvcGCMarker::OTHER); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (before)"); } g1h->check_bitmaps("Remark Start"); G1CollectorPolicy* g1p = g1h->g1_policy(); g1p->record_concurrent_mark_remark_start();
*** 1207,1234 **** weakRefsWork(clear_all_soft_refs); if (has_overflown()) { // Oops. We overflowed. Restart concurrent marking. _restart_for_overflow = true; ! if (G1TraceMarkStackOverflow) { ! gclog_or_tty->print_cr("\nRemark led to restart for overflow."); ! } // Verify the heap w.r.t. the previous marking bitmap. if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, ! " VerifyDuringGC:(overflow)"); } // Clear the marking state because we will be restarting // marking due to overflowing the global mark stack. reset_marking_state(); } else { { ! G1CMTraceTime trace("GC aggregate-data", G1Log::finer()); // Aggregate the per-task counting data that we have accumulated // while marking. aggregate_count_data(); } --- 1167,1191 ---- weakRefsWork(clear_all_soft_refs); if (has_overflown()) { // Oops. We overflowed. Restart concurrent marking. _restart_for_overflow = true; ! log_develop(gc)("Remark led to restart for overflow."); // Verify the heap w.r.t. the previous marking bitmap. if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (overflow)"); } // Clear the marking state because we will be restarting // marking due to overflowing the global mark stack. reset_marking_state(); } else { { ! GCTraceTime(Debug, gc) trace("GC aggregate-data", g1h->gc_timer_cm()); // Aggregate the per-task counting data that we have accumulated // while marking. aggregate_count_data(); }
*** 1241,1252 **** true /* expected_active */); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UseNextMarking, ! " VerifyDuringGC:(after)"); } g1h->check_bitmaps("Remark End"); assert(!restart_for_overflow(), "sanity"); // Completely reset the marking state since marking completed set_non_marking_state(); --- 1198,1208 ---- true /* expected_active */); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UseNextMarking, "During GC (after)"); } g1h->check_bitmaps("Remark End"); assert(!restart_for_overflow(), "sanity"); // Completely reset the marking state since marking completed set_non_marking_state();
*** 1789,1800 **** g1h->verify_region_sets_optional(); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, ! " VerifyDuringGC:(before)"); } g1h->check_bitmaps("Cleanup Start"); G1CollectorPolicy* g1p = g1h->g1_policy(); g1p->record_concurrent_mark_cleanup_start(); --- 1745,1755 ---- g1h->verify_region_sets_optional(); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (before)"); } g1h->check_bitmaps("Cleanup Start"); G1CollectorPolicy* g1p = g1h->g1_policy(); g1p->record_concurrent_mark_cleanup_start();
*** 1832,1843 **** double count_end = os::elapsedTime(); double this_final_counting_time = (count_end - start); _total_counting_time += this_final_counting_time; ! if (G1PrintRegionLivenessInfo) { ! G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Marking"); _g1h->heap_region_iterate(&cl); } // Install newly created mark bitMap as "prev". swapMarkBitMaps(); --- 1787,1798 ---- double count_end = os::elapsedTime(); double this_final_counting_time = (count_end - start); _total_counting_time += this_final_counting_time; ! if (Log<LOG_TAGS(gc, liveness)>::is_trace()) { ! G1PrintRegionLivenessInfoClosure cl("Post-Marking"); _g1h->heap_region_iterate(&cl); } // Install newly created mark bitMap as "prev". swapMarkBitMaps();
*** 1876,1898 **** // Statistics. double end = os::elapsedTime(); _cleanup_times.add((end - start) * 1000.0); - if (G1Log::fine()) { - g1h->g1_policy()->print_heap_transition(start_used_bytes); - } - // Clean up will have freed any regions completely full of garbage. // Update the soft reference policy with the new heap occupancy. Universe::update_heap_info_at_gc(); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, ! " VerifyDuringGC:(after)"); } g1h->check_bitmaps("Cleanup End"); g1h->verify_region_sets_optional(); --- 1831,1848 ---- // Statistics. double end = os::elapsedTime(); _cleanup_times.add((end - start) * 1000.0); // Clean up will have freed any regions completely full of garbage. // Update the soft reference policy with the new heap occupancy. Universe::update_heap_info_at_gc(); if (VerifyDuringGC) { HandleMark hm; // handle scope g1h->prepare_for_verify(); ! Universe::verify(VerifyOption_G1UsePrevMarking, "During GC (after)"); } g1h->check_bitmaps("Cleanup End"); g1h->verify_region_sets_optional();
*** 1921,1935 **** G1CollectedHeap* g1h = G1CollectedHeap::heap(); _cleanup_list.verify_optional(); FreeRegionList tmp_free_list("Tmp Free List"); ! if (G1ConcRegionFreeingVerbose) { ! gclog_or_tty->print_cr("G1ConcRegionFreeing [complete cleanup] : " "cleanup list has %u entries", _cleanup_list.length()); - } // No one else should be accessing the _cleanup_list at this point, // so it is not necessary to take any locks while (!_cleanup_list.is_empty()) { HeapRegion* hr = _cleanup_list.remove_region(true /* from_head */); --- 1871,1883 ---- G1CollectedHeap* g1h = G1CollectedHeap::heap(); _cleanup_list.verify_optional(); FreeRegionList tmp_free_list("Tmp Free List"); ! log_develop(gc, freelist)("G1ConcRegionFreeing [complete cleanup] : " "cleanup list has %u entries", _cleanup_list.length()); // No one else should be accessing the _cleanup_list at this point, // so it is not necessary to take any locks while (!_cleanup_list.is_empty()) { HeapRegion* hr = _cleanup_list.remove_region(true /* from_head */);
*** 1943,1959 **** // we do during this process. We'll also append the local list when // _cleanup_list is empty (which means we just removed the last // region from the _cleanup_list). if ((tmp_free_list.length() % G1SecondaryFreeListAppendLength == 0) || _cleanup_list.is_empty()) { ! if (G1ConcRegionFreeingVerbose) { ! gclog_or_tty->print_cr("G1ConcRegionFreeing [complete cleanup] : " "appending %u entries to the secondary_free_list, " "cleanup list still has %u entries", tmp_free_list.length(), _cleanup_list.length()); - } { MutexLockerEx x(SecondaryFreeList_lock, Mutex::_no_safepoint_check_flag); g1h->secondary_free_list_add(&tmp_free_list); SecondaryFreeList_lock->notify_all(); --- 1891,1905 ---- // we do during this process. We'll also append the local list when // _cleanup_list is empty (which means we just removed the last // region from the _cleanup_list). if ((tmp_free_list.length() % G1SecondaryFreeListAppendLength == 0) || _cleanup_list.is_empty()) { ! log_develop(gc, freelist)("G1ConcRegionFreeing [complete cleanup] : " "appending %u entries to the secondary_free_list, " "cleanup list still has %u entries", tmp_free_list.length(), _cleanup_list.length()); { MutexLockerEx x(SecondaryFreeList_lock, Mutex::_no_safepoint_check_flag); g1h->secondary_free_list_add(&tmp_free_list); SecondaryFreeList_lock->notify_all();
*** 2206,2216 **** G1CMIsAliveClosure g1_is_alive(g1h); // Inner scope to exclude the cleaning of the string and symbol // tables from the displayed time. { ! G1CMTraceTime t("GC ref-proc", G1Log::finer()); ReferenceProcessor* rp = g1h->ref_processor_cm(); // See the comment in G1CollectedHeap::ref_processing_init() // about how reference processing currently works in G1. --- 2152,2162 ---- G1CMIsAliveClosure g1_is_alive(g1h); // Inner scope to exclude the cleaning of the string and symbol // tables from the displayed time. { ! GCTraceTime(Debug, gc) trace("GC ref-proc", g1h->gc_timer_cm()); ReferenceProcessor* rp = g1h->ref_processor_cm(); // See the comment in G1CollectedHeap::ref_processing_init() // about how reference processing currently works in G1.
*** 2296,2323 **** assert(_markStack.isEmpty(), "Marking should have completed"); // Unload Klasses, String, Symbols, Code Cache, etc. { ! G1CMTraceTime trace("Unloading", G1Log::finer()); if (ClassUnloadingWithConcurrentMark) { bool purged_classes; { ! G1CMTraceTime trace("System Dictionary Unloading", G1Log::finest()); purged_classes = SystemDictionary::do_unloading(&g1_is_alive, false /* Defer klass cleaning */); } { ! G1CMTraceTime trace("Parallel Unloading", G1Log::finest()); weakRefsWorkParallelPart(&g1_is_alive, purged_classes); } } if (G1StringDedup::is_enabled()) { ! G1CMTraceTime trace("String Deduplication Unlink", G1Log::finest()); G1StringDedup::unlink(&g1_is_alive); } } } --- 2242,2269 ---- assert(_markStack.isEmpty(), "Marking should have completed"); // Unload Klasses, String, Symbols, Code Cache, etc. { ! GCTraceTime(Debug, gc) trace("Unloading", g1h->gc_timer_cm()); if (ClassUnloadingWithConcurrentMark) { bool purged_classes; { ! GCTraceTime(Trace, gc) trace("System Dictionary Unloading", g1h->gc_timer_cm()); purged_classes = SystemDictionary::do_unloading(&g1_is_alive, false /* Defer klass cleaning */); } { ! GCTraceTime(Trace, gc) trace("Parallel Unloading", g1h->gc_timer_cm()); weakRefsWorkParallelPart(&g1_is_alive, purged_classes); } } if (G1StringDedup::is_enabled()) { ! GCTraceTime(Trace, gc) trace("String Deduplication Unlink", g1h->gc_timer_cm()); G1StringDedup::unlink(&g1_is_alive); } } }
*** 2434,2444 **** void ConcurrentMark::checkpointRootsFinalWork() { ResourceMark rm; HandleMark hm; G1CollectedHeap* g1h = G1CollectedHeap::heap(); ! G1CMTraceTime trace("Finalize Marking", G1Log::finer()); g1h->ensure_parsability(false); // this is remark, so we'll use up all active threads uint active_workers = g1h->workers()->active_workers(); --- 2380,2390 ---- void ConcurrentMark::checkpointRootsFinalWork() { ResourceMark rm; HandleMark hm; G1CollectedHeap* g1h = G1CollectedHeap::heap(); ! GCTraceTime(Debug, gc) trace("Finalize Marking", g1h->gc_timer_cm()); g1h->ensure_parsability(false); // this is remark, so we'll use up all active threads uint active_workers = g1h->workers()->active_workers();
*** 2792,2807 **** task_card_bm->clear(); } } void ConcurrentMark::print_stats() { ! if (G1MarkingVerboseLevel > 0) { ! gclog_or_tty->print_cr("---------------------------------------------------------------------"); for (size_t i = 0; i < _active_tasks; ++i) { _tasks[i]->print_stats(); ! gclog_or_tty->print_cr("---------------------------------------------------------------------"); ! } } } // abandon current marking iteration due to a Full GC void ConcurrentMark::abort() { --- 2738,2755 ---- task_card_bm->clear(); } } void ConcurrentMark::print_stats() { ! LogHandle(gc, stats) log; ! if (!log.is_debug()) { ! return; ! } ! log.debug("---------------------------------------------------------------------"); for (size_t i = 0; i < _active_tasks; ++i) { _tasks[i]->print_stats(); ! log.debug("---------------------------------------------------------------------"); } } // abandon current marking iteration due to a Full GC void ConcurrentMark::abort() {
*** 2841,2887 **** _g1h->register_concurrent_cycle_end(); } static void print_ms_time_info(const char* prefix, const char* name, NumberSeq& ns) { ! gclog_or_tty->print_cr("%s%5d %12s: total time = %8.2f s (avg = %8.2f ms).", prefix, ns.num(), name, ns.sum()/1000.0, ns.avg()); if (ns.num() > 0) { ! gclog_or_tty->print_cr("%s [std. dev = %8.2f ms, max = %8.2f ms]", prefix, ns.sd(), ns.maximum()); } } void ConcurrentMark::print_summary_info() { ! gclog_or_tty->print_cr(" Concurrent marking:"); print_ms_time_info(" ", "init marks", _init_times); print_ms_time_info(" ", "remarks", _remark_times); { print_ms_time_info(" ", "final marks", _remark_mark_times); print_ms_time_info(" ", "weak refs", _remark_weak_ref_times); } print_ms_time_info(" ", "cleanups", _cleanup_times); ! gclog_or_tty->print_cr(" Final counting total time = %8.2f s (avg = %8.2f ms).", ! _total_counting_time, ! (_cleanup_times.num() > 0 ? _total_counting_time * 1000.0 / ! (double)_cleanup_times.num() ! : 0.0)); if (G1ScrubRemSets) { ! gclog_or_tty->print_cr(" RS scrub total time = %8.2f s (avg = %8.2f ms).", ! _total_rs_scrub_time, ! (_cleanup_times.num() > 0 ? _total_rs_scrub_time * 1000.0 / ! (double)_cleanup_times.num() ! : 0.0)); ! } ! gclog_or_tty->print_cr(" Total stop_world time = %8.2f s.", ! (_init_times.sum() + _remark_times.sum() + ! _cleanup_times.sum())/1000.0); ! gclog_or_tty->print_cr(" Total concurrent time = %8.2f s " ! "(%8.2f s marking).", ! cmThread()->vtime_accum(), ! cmThread()->vtime_mark_accum()); } void ConcurrentMark::print_worker_threads_on(outputStream* st) const { _parallel_workers->print_worker_threads_on(st); } --- 2789,2831 ---- _g1h->register_concurrent_cycle_end(); } static void print_ms_time_info(const char* prefix, const char* name, NumberSeq& ns) { ! log_trace(gc, marking, stats, exit)("%s%5d %12s: total time = %8.2f s (avg = %8.2f ms).", prefix, ns.num(), name, ns.sum()/1000.0, ns.avg()); if (ns.num() > 0) { ! log_trace(gc, marking, stats, exit)("%s [std. dev = %8.2f ms, max = %8.2f ms]", prefix, ns.sd(), ns.maximum()); } } void ConcurrentMark::print_summary_info() { ! LogHandle(gc, marking, stats, exit) log; ! if (!log.is_trace()) { ! return; ! } ! ! log.trace(" Concurrent marking:"); print_ms_time_info(" ", "init marks", _init_times); print_ms_time_info(" ", "remarks", _remark_times); { print_ms_time_info(" ", "final marks", _remark_mark_times); print_ms_time_info(" ", "weak refs", _remark_weak_ref_times); } print_ms_time_info(" ", "cleanups", _cleanup_times); ! log.trace(" Final counting total time = %8.2f s (avg = %8.2f ms).", ! _total_counting_time, (_cleanup_times.num() > 0 ? _total_counting_time * 1000.0 / (double)_cleanup_times.num() : 0.0)); if (G1ScrubRemSets) { ! log.trace(" RS scrub total time = %8.2f s (avg = %8.2f ms).", ! _total_rs_scrub_time, (_cleanup_times.num() > 0 ? _total_rs_scrub_time * 1000.0 / (double)_cleanup_times.num() : 0.0)); ! } ! log.trace(" Total stop_world time = %8.2f s.", ! (_init_times.sum() + _remark_times.sum() + _cleanup_times.sum())/1000.0); ! log.trace(" Total concurrent time = %8.2f s (%8.2f s marking).", ! cmThread()->vtime_accum(), cmThread()->vtime_mark_accum()); } void ConcurrentMark::print_worker_threads_on(outputStream* st) const { _parallel_workers->print_worker_threads_on(st); }
*** 3259,3276 **** // limits to get the regular clock call early decrease_limits(); } void CMTask::print_stats() { ! gclog_or_tty->print_cr("Marking Stats, task = %u, calls = %d", _worker_id, _calls); ! gclog_or_tty->print_cr(" Elapsed time = %1.2lfms, Termination time = %1.2lfms", _elapsed_time_ms, _termination_time_ms); ! gclog_or_tty->print_cr(" Step Times (cum): num = %d, avg = %1.2lfms, sd = %1.2lfms", _step_times_ms.num(), _step_times_ms.avg(), _step_times_ms.sd()); ! gclog_or_tty->print_cr(" max = %1.2lfms, total = %1.2lfms", _step_times_ms.maximum(), _step_times_ms.sum()); } bool ConcurrentMark::try_stealing(uint worker_id, int* hash_seed, oop& obj) { return _task_queues->steal(worker_id, hash_seed, obj); --- 3203,3220 ---- // limits to get the regular clock call early decrease_limits(); } void CMTask::print_stats() { ! log_debug(gc, stats)("Marking Stats, task = %u, calls = %d", _worker_id, _calls); ! log_debug(gc, stats)(" Elapsed time = %1.2lfms, Termination time = %1.2lfms", _elapsed_time_ms, _termination_time_ms); ! log_debug(gc, stats)(" Step Times (cum): num = %d, avg = %1.2lfms, sd = %1.2lfms", _step_times_ms.num(), _step_times_ms.avg(), _step_times_ms.sd()); ! log_debug(gc, stats)(" max = %1.2lfms, total = %1.2lfms", _step_times_ms.maximum(), _step_times_ms.sum()); } bool ConcurrentMark::try_stealing(uint worker_id, int* hash_seed, oop& obj) { return _task_queues->steal(worker_id, hash_seed, obj);
*** 3776,3806 **** #define G1PPRL_SUM_BYTE_FORMAT(tag) " " tag ": " SIZE_FORMAT #define G1PPRL_SUM_MB_FORMAT(tag) " " tag ": %1.2f MB" #define G1PPRL_SUM_MB_PERC_FORMAT(tag) G1PPRL_SUM_MB_FORMAT(tag) " / %1.2f %%" G1PrintRegionLivenessInfoClosure:: ! G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name) ! : _out(out), ! _total_used_bytes(0), _total_capacity_bytes(0), _total_prev_live_bytes(0), _total_next_live_bytes(0), _hum_used_bytes(0), _hum_capacity_bytes(0), _hum_prev_live_bytes(0), _hum_next_live_bytes(0), _total_remset_bytes(0), _total_strong_code_roots_bytes(0) { G1CollectedHeap* g1h = G1CollectedHeap::heap(); MemRegion g1_reserved = g1h->g1_reserved(); double now = os::elapsedTime(); // Print the header of the output. ! _out->cr(); ! _out->print_cr(G1PPRL_LINE_PREFIX" PHASE %s @ %1.3f", phase_name, now); ! _out->print_cr(G1PPRL_LINE_PREFIX" HEAP" G1PPRL_SUM_ADDR_FORMAT("reserved") G1PPRL_SUM_BYTE_FORMAT("region-size"), p2i(g1_reserved.start()), p2i(g1_reserved.end()), HeapRegion::GrainBytes); ! _out->print_cr(G1PPRL_LINE_PREFIX); ! _out->print_cr(G1PPRL_LINE_PREFIX G1PPRL_TYPE_H_FORMAT G1PPRL_ADDR_BASE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT --- 3720,3748 ---- #define G1PPRL_SUM_BYTE_FORMAT(tag) " " tag ": " SIZE_FORMAT #define G1PPRL_SUM_MB_FORMAT(tag) " " tag ": %1.2f MB" #define G1PPRL_SUM_MB_PERC_FORMAT(tag) G1PPRL_SUM_MB_FORMAT(tag) " / %1.2f %%" G1PrintRegionLivenessInfoClosure:: ! G1PrintRegionLivenessInfoClosure(const char* phase_name) ! : _total_used_bytes(0), _total_capacity_bytes(0), _total_prev_live_bytes(0), _total_next_live_bytes(0), _hum_used_bytes(0), _hum_capacity_bytes(0), _hum_prev_live_bytes(0), _hum_next_live_bytes(0), _total_remset_bytes(0), _total_strong_code_roots_bytes(0) { G1CollectedHeap* g1h = G1CollectedHeap::heap(); MemRegion g1_reserved = g1h->g1_reserved(); double now = os::elapsedTime(); // Print the header of the output. ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX" PHASE %s @ %1.3f", phase_name, now); ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX" HEAP" G1PPRL_SUM_ADDR_FORMAT("reserved") G1PPRL_SUM_BYTE_FORMAT("region-size"), p2i(g1_reserved.start()), p2i(g1_reserved.end()), HeapRegion::GrainBytes); ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX); ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX G1PPRL_TYPE_H_FORMAT G1PPRL_ADDR_BASE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT
*** 3808,3818 **** G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT, "type", "address-range", "used", "prev-live", "next-live", "gc-eff", "remset", "code-roots"); ! _out->print_cr(G1PPRL_LINE_PREFIX G1PPRL_TYPE_H_FORMAT G1PPRL_ADDR_BASE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT --- 3750,3760 ---- G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT, "type", "address-range", "used", "prev-live", "next-live", "gc-eff", "remset", "code-roots"); ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX G1PPRL_TYPE_H_FORMAT G1PPRL_ADDR_BASE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT G1PPRL_BYTE_H_FORMAT
*** 3890,3900 **** _total_next_live_bytes += next_live_bytes; _total_remset_bytes += remset_bytes; _total_strong_code_roots_bytes += strong_code_roots_bytes; // Print a line for this particular region. ! _out->print_cr(G1PPRL_LINE_PREFIX G1PPRL_TYPE_FORMAT G1PPRL_ADDR_BASE_FORMAT G1PPRL_BYTE_FORMAT G1PPRL_BYTE_FORMAT G1PPRL_BYTE_FORMAT --- 3832,3842 ---- _total_next_live_bytes += next_live_bytes; _total_remset_bytes += remset_bytes; _total_strong_code_roots_bytes += strong_code_roots_bytes; // Print a line for this particular region. ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX G1PPRL_TYPE_FORMAT G1PPRL_ADDR_BASE_FORMAT G1PPRL_BYTE_FORMAT G1PPRL_BYTE_FORMAT G1PPRL_BYTE_FORMAT
*** 3910,3921 **** G1PrintRegionLivenessInfoClosure::~G1PrintRegionLivenessInfoClosure() { // add static memory usages to remembered set sizes _total_remset_bytes += HeapRegionRemSet::fl_mem_size() + HeapRegionRemSet::static_mem_size(); // Print the footer of the output. ! _out->print_cr(G1PPRL_LINE_PREFIX); ! _out->print_cr(G1PPRL_LINE_PREFIX " SUMMARY" G1PPRL_SUM_MB_FORMAT("capacity") G1PPRL_SUM_MB_PERC_FORMAT("used") G1PPRL_SUM_MB_PERC_FORMAT("prev-live") G1PPRL_SUM_MB_PERC_FORMAT("next-live") --- 3852,3863 ---- G1PrintRegionLivenessInfoClosure::~G1PrintRegionLivenessInfoClosure() { // add static memory usages to remembered set sizes _total_remset_bytes += HeapRegionRemSet::fl_mem_size() + HeapRegionRemSet::static_mem_size(); // Print the footer of the output. ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX); ! log_trace(gc, liveness)(G1PPRL_LINE_PREFIX " SUMMARY" G1PPRL_SUM_MB_FORMAT("capacity") G1PPRL_SUM_MB_PERC_FORMAT("used") G1PPRL_SUM_MB_PERC_FORMAT("prev-live") G1PPRL_SUM_MB_PERC_FORMAT("next-live")
*** 3928,3934 **** perc(_total_prev_live_bytes, _total_capacity_bytes), bytes_to_mb(_total_next_live_bytes), perc(_total_next_live_bytes, _total_capacity_bytes), bytes_to_mb(_total_remset_bytes), bytes_to_mb(_total_strong_code_roots_bytes)); - _out->cr(); } --- 3870,3875 ----
< prev index next >