truffle: src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp comparison

comparison src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp @ 838:0316eac49d5a

6855834: G1: minimize the output when -XX:+PrintHeapAtGC is set Summary: Changing the behavior of -XX:+PrintHeapAtGC for G1 from printing lengthy, per-region information to instead printing a concise summary. Reviewed-by: ysr, apetrusenko, jcoomes

author	tonyp
date	Tue, 07 Jul 2009 14:23:00 -0400
parents	830ca2573896
children	df6caf649ff7

comparison

equal deleted inserted replaced

-:e7d5557ad624
+:0316eac49d5a
 void G1CollectedHeap::do_collection(bool full, bool clear_all_soft_refs,
 size_t word_size) {
 ResourceMark rm;
+if (PrintHeapAtGC) {
+Universe::print_heap_before_gc();
+}
 if (full && DisableExplicitGC) {
 gclog_or_tty->print("\n\n\nDisabling Explicit GC\n\n\n");
 return;
 }
 double start = os::elapsedTime();
 GCOverheadReporter::recordSTWStart(start);
 g1_policy()->record_full_collection_start();
 gc_prologue(true);
-increment_total_collections();
+increment_total_collections(true /* full gc */);
 size_t g1h_prev_used = used();
 assert(used() == recalculate_used(), "Should be equal");
 if (VerifyBeforeGC && total_collections() >= VerifyGCStartAt) {
 if (g1_policy()->in_young_gc_mode()) {
 _young_list->reset_sampled_info();
 assert( check_young_list_empty(false, false),
 "young list should be empty at this point");
+}
+if (PrintHeapAtGC) {
+Universe::print_heap_after_gc();
 }
 }
 void G1CollectedHeap::do_full_collection(bool clear_all_soft_refs) {
 do_collection(true, clear_all_soft_refs, 0);
 r->print_on(_st);
 return false;
 }
 };
-void G1CollectedHeap::print() const { print_on(gclog_or_tty); }
+void G1CollectedHeap::print() const { print_on(tty); }
 void G1CollectedHeap::print_on(outputStream* st) const {
+print_on(st, PrintHeapAtGCExtended);
+}
+void G1CollectedHeap::print_on(outputStream* st, bool extended) const {
+st->print(" %-20s", "garbage-first heap");
+st->print(" total " SIZE_FORMAT "K, used " SIZE_FORMAT "K",
+capacity()/K, used()/K);
+st->print(" [" INTPTR_FORMAT ", " INTPTR_FORMAT ", " INTPTR_FORMAT ")",
+_g1_storage.low_boundary(),
+_g1_storage.high(),
+_g1_storage.high_boundary());
+st->cr();
+st->print("  region size " SIZE_FORMAT "K, ",
+HeapRegion::GrainBytes/K);
+size_t young_regions = _young_list->length();
+st->print(SIZE_FORMAT " young (" SIZE_FORMAT "K), ",
+young_regions, young_regions * HeapRegion::GrainBytes / K);
+size_t survivor_regions = g1_policy()->recorded_survivor_regions();
+st->print(SIZE_FORMAT " survivors (" SIZE_FORMAT "K)",
+survivor_regions, survivor_regions * HeapRegion::GrainBytes / K);
+st->cr();
+perm()->as_gen()->print_on(st);
+if (extended) {
+print_on_extended(st);
+}
+}
+void G1CollectedHeap::print_on_extended(outputStream* st) const {
 PrintRegionClosure blk(st);
 _hrs->iterate(&blk);
 }
 class PrintOnThreadsClosure : public ThreadClosure {
 "not a garbage-first heap");
 return _g1h;
 }
 void G1CollectedHeap::gc_prologue(bool full /* Ignored */) {
-if (PrintHeapAtGC){
-gclog_or_tty->print_cr(" {Heap before GC collections=%d:", total_collections());
-Universe::print();
-}
 assert(InlineCacheBuffer::is_empty(), "should have cleaned up ICBuffer");
 // Call allocation profiler
 AllocationProfiler::iterate_since_last_gc();
 // Fill TLAB's and such
 ensure_parsability(true);
 // FIXME: what is this about?
 // I'm ignoring the "fill_newgen()" call if "alloc_event_enabled"
 // is set.
 COMPILER2_PRESENT(assert(DerivedPointerTable::is_empty(),
 "derived pointer present"));
-if (PrintHeapAtGC){
-gclog_or_tty->print_cr(" Heap after GC collections=%d:", total_collections());
-Universe::print();
-gclog_or_tty->print("} ");
-}
 }
 void G1CollectedHeap::do_collection_pause() {
 // Read the GC count while holding the Heap_lock
 // we need to do this _before_ wait_for_cleanup_complete(), to
 // </NEW PREDICTION>
 void
 G1CollectedHeap::do_collection_pause_at_safepoint() {
-char verbose_str[128];
+if (PrintHeapAtGC) {
-sprintf(verbose_str, "GC pause ");
+Universe::print_heap_before_gc();
-if (g1_policy()->in_young_gc_mode()) {
+}
-if (g1_policy()->full_young_gcs())
-strcat(verbose_str, "(young)");
+{
-else
+char verbose_str[128];
-strcat(verbose_str, "(partial)");
+sprintf(verbose_str, "GC pause ");
-}
+if (g1_policy()->in_young_gc_mode()) {
-if (g1_policy()->should_initiate_conc_mark())
+if (g1_policy()->full_young_gcs())
-strcat(verbose_str, " (initial-mark)");
+strcat(verbose_str, "(young)");
+else
-GCCauseSetter x(this, GCCause::_g1_inc_collection_pause);
+strcat(verbose_str, "(partial)");
+}
-// if PrintGCDetails is on, we'll print long statistics information
+if (g1_policy()->should_initiate_conc_mark())
-// in the collector policy code, so let's not print this as the output
+strcat(verbose_str, " (initial-mark)");
-// is messy if we do.
-gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
+GCCauseSetter x(this, GCCause::_g1_inc_collection_pause);
-TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
-TraceTime t(verbose_str, PrintGC && !PrintGCDetails, true, gclog_or_tty);
+// if PrintGCDetails is on, we'll print long statistics information
+// in the collector policy code, so let's not print this as the output
-ResourceMark rm;
+// is messy if we do.
-assert(SafepointSynchronize::is_at_safepoint(), "should be at safepoint");
+gclog_or_tty->date_stamp(PrintGC && PrintGCDateStamps);
-assert(Thread::current() == VMThread::vm_thread(), "should be in vm thread");
+TraceCPUTime tcpu(PrintGCDetails, true, gclog_or_tty);
-guarantee(!is_gc_active(), "collection is not reentrant");
+TraceTime t(verbose_str, PrintGC && !PrintGCDetails, true, gclog_or_tty);
-assert(regions_accounted_for(), "Region leakage!");
+ResourceMark rm;
-increment_gc_time_stamp();
+assert(SafepointSynchronize::is_at_safepoint(), "should be at safepoint");
+assert(Thread::current() == VMThread::vm_thread(), "should be in vm thread");
-if (g1_policy()->in_young_gc_mode()) {
+guarantee(!is_gc_active(), "collection is not reentrant");
-assert(check_young_list_well_formed(),
+assert(regions_accounted_for(), "Region leakage!");
-"young list should be well formed");
-}
+increment_gc_time_stamp();
-if (GC_locker::is_active()) {
+if (g1_policy()->in_young_gc_mode()) {
-return; // GC is disabled (e.g. JNI GetXXXCritical operation)
+assert(check_young_list_well_formed(),
-}
+"young list should be well formed");
+}
-bool abandoned = false;
-{ // Call to jvmpi::post_class_unload_events must occur outside of active GC
+if (GC_locker::is_active()) {
-IsGCActiveMark x;
+return; // GC is disabled (e.g. JNI GetXXXCritical operation)
+}
-gc_prologue(false);
-increment_total_collections();
+bool abandoned = false;
+{ // Call to jvmpi::post_class_unload_events must occur outside of active GC
+IsGCActiveMark x;
+gc_prologue(false);
+increment_total_collections(false /* full gc */);
 #if G1_REM_SET_LOGGING
 gclog_or_tty->print_cr("\nJust chose CS, heap:");
-print();
-#endif
-if (VerifyBeforeGC && total_collections() >= VerifyGCStartAt) {
-HandleMark hm;  // Discard invalid handles created during verification
-prepare_for_verify();
-gclog_or_tty->print(" VerifyBeforeGC:");
-Universe::verify(false);
-}
-COMPILER2_PRESENT(DerivedPointerTable::clear());
-// We want to turn off ref discovery, if necessary, and turn it back on
-// on again later if we do.
-bool was_enabled = ref_processor()->discovery_enabled();
-if (was_enabled) ref_processor()->disable_discovery();
-// Forget the current alloc region (we might even choose it to be part
-// of the collection set!).
-abandon_cur_alloc_region();
-// The elapsed time induced by the start time below deliberately elides
-// the possible verification above.
-double start_time_sec = os::elapsedTime();
-GCOverheadReporter::recordSTWStart(start_time_sec);
-size_t start_used_bytes = used();
-if (!G1ConcMark) {
-do_sync_mark();
-}
-g1_policy()->record_collection_pause_start(start_time_sec,
-start_used_bytes);
-guarantee(_in_cset_fast_test == NULL, "invariant");
-guarantee(_in_cset_fast_test_base == NULL, "invariant");
-_in_cset_fast_test_length = max_regions();
-_in_cset_fast_test_base =
-NEW_C_HEAP_ARRAY(bool, _in_cset_fast_test_length);
-memset(_in_cset_fast_test_base, false,
-_in_cset_fast_test_length * sizeof(bool));
-// We're biasing _in_cset_fast_test to avoid subtracting the
-// beginning of the heap every time we want to index; basically
-// it's the same with what we do with the card table.
-_in_cset_fast_test = _in_cset_fast_test_base -
-((size_t) _g1_reserved.start() >> HeapRegion::LogOfHRGrainBytes);
-#if SCAN_ONLY_VERBOSE
-_young_list->print();
-#endif // SCAN_ONLY_VERBOSE
-if (g1_policy()->should_initiate_conc_mark()) {
-concurrent_mark()->checkpointRootsInitialPre();
-}
-save_marks();
-// We must do this before any possible evacuation that should propagate
-// marks.
-if (mark_in_progress()) {
-double start_time_sec = os::elapsedTime();
-_cm->drainAllSATBBuffers();
-double finish_mark_ms = (os::elapsedTime() - start_time_sec) * 1000.0;
-g1_policy()->record_satb_drain_time(finish_mark_ms);
-}
-// Record the number of elements currently on the mark stack, so we
-// only iterate over these.  (Since evacuation may add to the mark
-// stack, doing more exposes race conditions.)  If no mark is in
-// progress, this will be zero.
-_cm->set_oops_do_bound();
-assert(regions_accounted_for(), "Region leakage.");
-if (mark_in_progress())
-concurrent_mark()->newCSet();
-// Now choose the CS.
-g1_policy()->choose_collection_set();
-// We may abandon a pause if we find no region that will fit in the MMU
-// pause.
-bool abandoned = (g1_policy()->collection_set() == NULL);
-// Nothing to do if we were unable to choose a collection set.
-if (!abandoned) {
-#if G1_REM_SET_LOGGING
-gclog_or_tty->print_cr("\nAfter pause, heap:");
 print();
 #endif
-setup_surviving_young_words();
+if (VerifyBeforeGC && total_collections() >= VerifyGCStartAt) {
+HandleMark hm;  // Discard invalid handles created during verification
-// Set up the gc allocation regions.
+prepare_for_verify();
-get_gc_alloc_regions();
+gclog_or_tty->print(" VerifyBeforeGC:");
+Universe::verify(false);
-// Actually do the work...
+}
-evacuate_collection_set();
-free_collection_set(g1_policy()->collection_set());
+COMPILER2_PRESENT(DerivedPointerTable::clear());
-g1_policy()->clear_collection_set();
+// We want to turn off ref discovery, if necessary, and turn it back on
-FREE_C_HEAP_ARRAY(bool, _in_cset_fast_test_base);
+// on again later if we do.
-// this is more for peace of mind; we're nulling them here and
+bool was_enabled = ref_processor()->discovery_enabled();
-// we're expecting them to be null at the beginning of the next GC
+if (was_enabled) ref_processor()->disable_discovery();
-_in_cset_fast_test = NULL;
-_in_cset_fast_test_base = NULL;
+// Forget the current alloc region (we might even choose it to be part
+// of the collection set!).
-release_gc_alloc_regions(false /* totally */);
+abandon_cur_alloc_region();
-cleanup_surviving_young_words();
+// The elapsed time induced by the start time below deliberately elides
+// the possible verification above.
-if (g1_policy()->in_young_gc_mode()) {
+double start_time_sec = os::elapsedTime();
-_young_list->reset_sampled_info();
+GCOverheadReporter::recordSTWStart(start_time_sec);
-assert(check_young_list_empty(true),
+size_t start_used_bytes = used();
-"young list should be empty");
+if (!G1ConcMark) {
+do_sync_mark();
+}
+g1_policy()->record_collection_pause_start(start_time_sec,
+start_used_bytes);
+guarantee(_in_cset_fast_test == NULL, "invariant");
+guarantee(_in_cset_fast_test_base == NULL, "invariant");
+_in_cset_fast_test_length = max_regions();
+_in_cset_fast_test_base =
+NEW_C_HEAP_ARRAY(bool, _in_cset_fast_test_length);
+memset(_in_cset_fast_test_base, false,
+_in_cset_fast_test_length * sizeof(bool));
+// We're biasing _in_cset_fast_test to avoid subtracting the
+// beginning of the heap every time we want to index; basically
+// it's the same with what we do with the card table.
+_in_cset_fast_test = _in_cset_fast_test_base -
+((size_t) _g1_reserved.start() >> HeapRegion::LogOfHRGrainBytes);
 #if SCAN_ONLY_VERBOSE
 _young_list->print();
 #endif // SCAN_ONLY_VERBOSE
-g1_policy()->record_survivor_regions(_young_list->survivor_length(),
+if (g1_policy()->should_initiate_conc_mark()) {
-_young_list->first_survivor_region(),
+concurrent_mark()->checkpointRootsInitialPre();
-_young_list->last_survivor_region());
-_young_list->reset_auxilary_lists();
 }
-} else {
+save_marks();
-COMPILER2_PRESENT(DerivedPointerTable::update_pointers());
-}
+// We must do this before any possible evacuation that should propagate
+// marks.
-if (evacuation_failed()) {
+if (mark_in_progress()) {
-_summary_bytes_used = recalculate_used();
+double start_time_sec = os::elapsedTime();
-} else {
-// The "used" of the the collection set have already been subtracted
+_cm->drainAllSATBBuffers();
-// when they were freed.  Add in the bytes evacuated.
+double finish_mark_ms = (os::elapsedTime() - start_time_sec) * 1000.0;
-_summary_bytes_used += g1_policy()->bytes_in_to_space();
+g1_policy()->record_satb_drain_time(finish_mark_ms);
 }
+// Record the number of elements currently on the mark stack, so we
-if (g1_policy()->in_young_gc_mode() &&
+// only iterate over these.  (Since evacuation may add to the mark
-g1_policy()->should_initiate_conc_mark()) {
+// stack, doing more exposes race conditions.)  If no mark is in
-concurrent_mark()->checkpointRootsInitialPost();
+// progress, this will be zero.
-set_marking_started();
+_cm->set_oops_do_bound();
-doConcurrentMark();
-}
+assert(regions_accounted_for(), "Region leakage.");
+if (mark_in_progress())
+concurrent_mark()->newCSet();
+// Now choose the CS.
+g1_policy()->choose_collection_set();
+// We may abandon a pause if we find no region that will fit in the MMU
+// pause.
+bool abandoned = (g1_policy()->collection_set() == NULL);
+// Nothing to do if we were unable to choose a collection set.
+if (!abandoned) {
+#if G1_REM_SET_LOGGING
+gclog_or_tty->print_cr("\nAfter pause, heap:");
+print();
+#endif
+setup_surviving_young_words();
+// Set up the gc allocation regions.
+get_gc_alloc_regions();
+// Actually do the work...
+evacuate_collection_set();
+free_collection_set(g1_policy()->collection_set());
+g1_policy()->clear_collection_set();
+FREE_C_HEAP_ARRAY(bool, _in_cset_fast_test_base);
+// this is more for peace of mind; we're nulling them here and
+// we're expecting them to be null at the beginning of the next GC
+_in_cset_fast_test = NULL;
+_in_cset_fast_test_base = NULL;
+release_gc_alloc_regions(false /* totally */);
+cleanup_surviving_young_words();
+if (g1_policy()->in_young_gc_mode()) {
+_young_list->reset_sampled_info();
+assert(check_young_list_empty(true),
+"young list should be empty");
 #if SCAN_ONLY_VERBOSE
 _young_list->print();
 #endif // SCAN_ONLY_VERBOSE
-double end_time_sec = os::elapsedTime();
+g1_policy()->record_survivor_regions(_young_list->survivor_length(),
-double pause_time_ms = (end_time_sec - start_time_sec) * MILLIUNITS;
+_young_list->first_survivor_region(),
-g1_policy()->record_pause_time_ms(pause_time_ms);
+_young_list->last_survivor_region());
-GCOverheadReporter::recordSTWEnd(end_time_sec);
+_young_list->reset_auxilary_lists();
-g1_policy()->record_collection_pause_end(abandoned);
+}
+} else {
-assert(regions_accounted_for(), "Region leakage.");
+COMPILER2_PRESENT(DerivedPointerTable::update_pointers());
-if (VerifyAfterGC && total_collections() >= VerifyGCStartAt) {
-HandleMark hm;  // Discard invalid handles created during verification
-gclog_or_tty->print(" VerifyAfterGC:");
-prepare_for_verify();
-Universe::verify(false);
-}
-if (was_enabled) ref_processor()->enable_discovery();
-{
-size_t expand_bytes = g1_policy()->expansion_amount();
-if (expand_bytes > 0) {
-size_t bytes_before = capacity();
-expand(expand_bytes);
 }
-}
+if (evacuation_failed()) {
-if (mark_in_progress()) {
+_summary_bytes_used = recalculate_used();
-concurrent_mark()->update_g1_committed();
+} else {
-}
+// The "used" of the the collection set have already been subtracted
+// when they were freed.  Add in the bytes evacuated.
+_summary_bytes_used += g1_policy()->bytes_in_to_space();
+}
+if (g1_policy()->in_young_gc_mode() &&
+g1_policy()->should_initiate_conc_mark()) {
+concurrent_mark()->checkpointRootsInitialPost();
+set_marking_started();
+doConcurrentMark();
+}
+#if SCAN_ONLY_VERBOSE
+_young_list->print();
+#endif // SCAN_ONLY_VERBOSE
+double end_time_sec = os::elapsedTime();
+double pause_time_ms = (end_time_sec - start_time_sec) * MILLIUNITS;
+g1_policy()->record_pause_time_ms(pause_time_ms);
+GCOverheadReporter::recordSTWEnd(end_time_sec);
+g1_policy()->record_collection_pause_end(abandoned);
+assert(regions_accounted_for(), "Region leakage.");
+if (VerifyAfterGC && total_collections() >= VerifyGCStartAt) {
+HandleMark hm;  // Discard invalid handles created during verification
+gclog_or_tty->print(" VerifyAfterGC:");
+prepare_for_verify();
+Universe::verify(false);
+}
+if (was_enabled) ref_processor()->enable_discovery();
+{
+size_t expand_bytes = g1_policy()->expansion_amount();
+if (expand_bytes > 0) {
+size_t bytes_before = capacity();
+expand(expand_bytes);
+}
+}
+if (mark_in_progress()) {
+concurrent_mark()->update_g1_committed();
+}
 #ifdef TRACESPINNING
 ParallelTaskTerminator::print_termination_counts();
 #endif
 gc_epilogue(false);
 }
 assert(verify_region_lists(), "Bad region lists.");
 if (ExitAfterGCNum > 0 && total_collections() == ExitAfterGCNum) {
 gclog_or_tty->print_cr("Stopping after GC #%d", ExitAfterGCNum);
 print_tracing_info();
 vm_exit(-1);
+}
+}
+if (PrintHeapAtGC) {
+Universe::print_heap_after_gc();
 }
 }
 void G1CollectedHeap::set_gc_alloc_region(int purpose, HeapRegion* r) {
 assert(purpose >= 0 && purpose < GCAllocPurposeCount, "invalid purpose");
 "Postconditions of loop.")
 while (pop_free_region_list_locked() != NULL) ;
 assert(_free_region_list == NULL, "Postcondition of loop.");
 if (_free_region_list_size != 0) {
 gclog_or_tty->print_cr("Size is %d.", _free_region_list_size);
-print();
+print_on(gclog_or_tty, true /* extended */);
 }
 assert(_free_region_list_size == 0, "Postconditions of loop.");
 }

Mercurial > hg > truffle

comparison src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp @ 838:0316eac49d5a