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

comparison src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp @ 6628:bb3f6194fedb

7178363: G1: Remove the serial code for PrintGCDetails and make it a special case of the parallel code Summary: Also reviewed by vitalyd@gmail.com. Introduced the WorkerDataArray class. Fixed some minor logging bugs. Reviewed-by: johnc, mgerdin

author	brutisso
date	Thu, 23 Aug 2012 10:21:12 +0200
parents	7383557659bd
children	c9814fadeb38

comparison

equal deleted inserted replaced

-:153776c4cb6f
+:bb3f6194fedb
 void G1CollectedHeap::print_hrs_post_compaction() {
 PostCompactionPrinterClosure cl(hr_printer());
 heap_region_iterate(&cl);
 }
+double G1CollectedHeap::verify(bool guard, const char* msg) {
+double verify_time_ms = 0.0;
+if (guard && total_collections() >= VerifyGCStartAt) {
+double verify_start = os::elapsedTime();
+HandleMark hm;  // Discard invalid handles created during verification
+gclog_or_tty->print(msg);
+prepare_for_verify();
+Universe::verify(false /* silent */, VerifyOption_G1UsePrevMarking);
+verify_time_ms = (os::elapsedTime() - verify_start) * 1000;
+}
+return verify_time_ms;
+}
+void G1CollectedHeap::verify_before_gc() {
+double verify_time_ms = verify(VerifyBeforeGC, " VerifyBeforeGC:");
+g1_policy()->phase_times()->record_verify_before_time_ms(verify_time_ms);
+}
+void G1CollectedHeap::verify_after_gc() {
+double verify_time_ms = verify(VerifyAfterGC, " VerifyAfterGC:");
+g1_policy()->phase_times()->record_verify_after_time_ms(verify_time_ms);
+}
 bool G1CollectedHeap::do_collection(bool explicit_gc,
 bool clear_all_soft_refs,
 size_t word_size) {
 assert_at_safepoint(true /* should_be_vm_thread */);
 increment_old_marking_cycles_started();
 size_t g1h_prev_used = used();
 assert(used() == recalculate_used(), "Should be equal");
-if (VerifyBeforeGC && total_collections() >= VerifyGCStartAt) {
+verify_before_gc();
-HandleMark hm;  // Discard invalid handles created during verification
-gclog_or_tty->print(" VerifyBeforeGC:");
-prepare_for_verify();
-Universe::verify(/* silent      */ false,
-/* option      */ VerifyOption_G1UsePrevMarking);
-}
 pre_full_gc_dump();
 COMPILER2_PRESENT(DerivedPointerTable::clear());
 // Disable discovery and empty the discovered lists
 COMPILER2_PRESENT(DerivedPointerTable::update_pointers());
 MemoryService::track_memory_usage();
-if (VerifyAfterGC && total_collections() >= VerifyGCStartAt) {
+verify_after_gc();
-HandleMark hm;  // Discard invalid handles created during verification
-gclog_or_tty->print(" VerifyAfterGC:");
-prepare_for_verify();
-Universe::verify(/* silent      */ false,
-/* option      */ VerifyOption_G1UsePrevMarking);
-}
 assert(!ref_processor_stw()->discovery_enabled(), "Postcondition");
 ref_processor_stw()->verify_no_references_recorded();
 // Note: since we've just done a full GC, concurrent
 DirtyCardQueueSet& dcqs = JavaThread::dirty_card_queue_set();
 int n_completed_buffers = 0;
 while (dcqs.apply_closure_to_completed_buffer(cl, worker_i, 0, true)) {
 n_completed_buffers++;
 }
-g1_policy()->phase_times()->record_update_rs_processed_buffers(worker_i,
+g1_policy()->phase_times()->record_update_rs_processed_buffers(worker_i, n_completed_buffers);
-(double) n_completed_buffers);
 dcqs.clear_n_completed_buffers();
 assert(!dcqs.completed_buffers_exist_dirty(), "Completed buffers exist!");
 }
 gclog_or_tty->date_stamp(G1Log::fine() && PrintGCDateStamps);
 TraceCPUTime tcpu(G1Log::finer(), true, gclog_or_tty);
 int active_workers = (G1CollectedHeap::use_parallel_gc_threads() ?
 workers()->active_workers() : 1);
-g1_policy()->phase_times()->note_gc_start(os::elapsedTime(), active_workers,
+double pause_start_sec = os::elapsedTime();
-g1_policy()->gcs_are_young(), g1_policy()->during_initial_mark_pause(), gc_cause());
+g1_policy()->phase_times()->note_gc_start(active_workers);
+bool initial_mark_gc = g1_policy()->during_initial_mark_pause();
 TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
 TraceMemoryManagerStats tms(false /* fullGC */, gc_cause());
 // If the secondary_free_list is not empty, append it to the
 gc_prologue(false);
 increment_total_collections(false /* full gc */);
 increment_gc_time_stamp();
-if (VerifyBeforeGC && total_collections() >= VerifyGCStartAt) {
+verify_before_gc();
-HandleMark hm;  // Discard invalid handles created during verification
-gclog_or_tty->print(" VerifyBeforeGC:");
-prepare_for_verify();
-Universe::verify(/* silent      */ false,
-/* option      */ VerifyOption_G1UsePrevMarking);
-}
 COMPILER2_PRESENT(DerivedPointerTable::clear());
 // Please see comment in g1CollectedHeap.hpp and
 // G1CollectedHeap::ref_processing_init() to see how
 _cm->verify_no_cset_oops(true  /* verify_stacks */,
 true  /* verify_enqueued_buffers */,
 true  /* verify_thread_buffers */,
 true  /* verify_fingers */);
 _cm->note_end_of_gc();
-// Collect thread local data to allow the ergonomics to use
-// the collected information
-g1_policy()->phase_times()->collapse_par_times();
 // This timing is only used by the ergonomics to handle our pause target.
 // It is unclear why this should not include the full pause. We will
 // investigate this in CR 7178365.
 double sample_end_time_sec = os::elapsedTime();
 // during concurrent refinement. So we don't need the
 // is_gc_active() check to decided which top to use when
 // scanning cards (see CR 7039627).
 increment_gc_time_stamp();
-if (VerifyAfterGC && total_collections() >= VerifyGCStartAt) {
+verify_after_gc();
-HandleMark hm;  // Discard invalid handles created during verification
-gclog_or_tty->print(" VerifyAfterGC:");
-prepare_for_verify();
-Universe::verify(/* silent      */ false,
-/* option      */ VerifyOption_G1UsePrevMarking);
-}
 assert(!ref_processor_stw()->discovery_enabled(), "Postcondition");
 ref_processor_stw()->verify_no_references_recorded();
 // CM reference discovery will be re-enabled if necessary.
 ParallelTaskTerminator::print_termination_counts();
 #endif
 gc_epilogue(false);
-g1_policy()->phase_times()->note_gc_end(os::elapsedTime());
+if (G1Log::fine()) {
+if (PrintGCTimeStamps) {
-// We have to do this after we decide whether to expand the heap or not.
+gclog_or_tty->stamp();
+gclog_or_tty->print(": ");
+}
+GCCauseString gc_cause_str = GCCauseString("GC pause", gc_cause())
+.append(g1_policy()->gcs_are_young() ? " (young)" : " (mixed)")
+.append(initial_mark_gc ? " (initial-mark)" : "");
+double pause_time_sec = os::elapsedTime() - pause_start_sec;
+if (G1Log::finer()) {
+if (evacuation_failed()) {
+gc_cause_str.append(" (to-space exhausted)");
+}
+gclog_or_tty->print_cr("[%s, %3.7f secs]", (const char*)gc_cause_str, pause_time_sec);
+g1_policy()->phase_times()->note_gc_end();
+g1_policy()->phase_times()->print(pause_time_sec);
+g1_policy()->print_detailed_heap_transition();
+} else {
+if (evacuation_failed()) {
+gc_cause_str.append("--");
+}
+gclog_or_tty->print("[%s", (const char*)gc_cause_str);
 g1_policy()->print_heap_transition();
+gclog_or_tty->print_cr(", %3.7f secs]", pause_time_sec);
+}
+}
 }
 // It is not yet to safe to tell the concurrent mark to
 // start as we have some optional output below. We don't want the
 // output from the concurrent mark thread interfering with this
 double start = os::elapsedTime();
 G1ParEvacuateFollowersClosure evac(_g1h, &pss, _queues, &_terminator);
 evac.do_void();
 double elapsed_ms = (os::elapsedTime()-start)*1000.0;
 double term_ms = pss.term_time()*1000.0;
-_g1h->g1_policy()->phase_times()->record_obj_copy_time(worker_id, elapsed_ms-term_ms);
+_g1h->g1_policy()->phase_times()->add_obj_copy_time(worker_id, elapsed_ms-term_ms);
 _g1h->g1_policy()->phase_times()->record_termination(worker_id, term_ms, pss.term_attempts());
 }
 _g1h->g1_policy()->record_thread_age_table(pss.age_table());
 _g1h->update_surviving_young_words(pss.surviving_young_words()+1);
 // Finish up any enqueued closure apps (attributed as object copy time).
 buf_scan_non_heap_roots.done();
 buf_scan_perm.done();
-double ext_roots_end = os::elapsedTime();
-g1_policy()->phase_times()->reset_obj_copy_time(worker_i);
 double obj_copy_time_sec = buf_scan_perm.closure_app_seconds() +
 buf_scan_non_heap_roots.closure_app_seconds();
 g1_policy()->phase_times()->record_obj_copy_time(worker_i, obj_copy_time_sec * 1000.0);
 double ext_root_time_ms =
-((ext_roots_end - ext_roots_start) - obj_copy_time_sec) * 1000.0;
+((os::elapsedTime() - ext_roots_start) - obj_copy_time_sec) * 1000.0;
 g1_policy()->phase_times()->record_ext_root_scan_time(worker_i, ext_root_time_ms);
 // During conc marking we have to filter the per-thread SATB buffers
 // to make sure we remove any oops into the CSet (which will show up
 // as implicitly live).
+double satb_filtering_ms = 0.0;
 if (!_process_strong_tasks->is_task_claimed(G1H_PS_filter_satb_buffers)) {
 if (mark_in_progress()) {
+double satb_filter_start = os::elapsedTime();
 JavaThread::satb_mark_queue_set().filter_thread_buffers();
-}
-}
+satb_filtering_ms = (os::elapsedTime() - satb_filter_start) * 1000.0;
-double satb_filtering_ms = (os::elapsedTime() - ext_roots_end) * 1000.0;
+}
+}
 g1_policy()->phase_times()->record_satb_filtering_time(worker_i, satb_filtering_ms);
 // Now scan the complement of the collection set.
 if (scan_rs != NULL) {
 g1_rem_set()->oops_into_collection_set_do(scan_rs, worker_i);
 finalize_for_evac_failure();
 if (evacuation_failed()) {
 remove_self_forwarding_pointers();
-if (G1Log::finer()) {
-gclog_or_tty->print(" (to-space exhausted)");
-} else if (G1Log::fine()) {
-gclog_or_tty->print("--");
-}
 }
 // Enqueue any remaining references remaining on the STW
 // reference processor's discovered lists. We need to do
 // this after the card table is cleaned (and verified) as

Mercurial > hg > truffle

comparison src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp @ 6628:bb3f6194fedb