< prev index next >
src/share/vm/gc_implementation/g1/g1CollectedHeap.cpp
Print this page
*** 2204,2218 ****
// Clean cards in the hot card cache
G1HotCardCache* hot_card_cache = _cg1r->hot_card_cache();
hot_card_cache->drain(worker_i, g1_rem_set(), into_cset_dcq);
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, n_completed_buffers);
dcqs.clear_n_completed_buffers();
assert(!dcqs.completed_buffers_exist_dirty(), "Completed buffers exist!");
}
--- 2204,2218 ----
// Clean cards in the hot card cache
G1HotCardCache* hot_card_cache = _cg1r->hot_card_cache();
hot_card_cache->drain(worker_i, g1_rem_set(), into_cset_dcq);
DirtyCardQueueSet& dcqs = JavaThread::dirty_card_queue_set();
! size_t n_completed_buffers = 0;
while (dcqs.apply_closure_to_completed_buffer(cl, worker_i, 0, true)) {
n_completed_buffers++;
}
! g1_policy()->phase_times()->record_sub_count(G1GCPhaseTimes::UpdateRS, worker_i, n_completed_buffers);
dcqs.clear_n_completed_buffers();
assert(!dcqs.completed_buffers_exist_dirty(), "Completed buffers exist!");
}
*** 3751,3761 ****
TraceCPUTime tcpu(G1Log::finer(), true, gclog_or_tty);
int active_workers = workers()->active_workers();
double pause_start_sec = os::elapsedTime();
! g1_policy()->phase_times()->note_gc_start(active_workers);
log_gc_header();
TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
TraceMemoryManagerStats tms(false /* fullGC */, gc_cause());
--- 3751,3761 ----
TraceCPUTime tcpu(G1Log::finer(), true, gclog_or_tty);
int active_workers = workers()->active_workers();
double pause_start_sec = os::elapsedTime();
! g1_policy()->phase_times()->note_gc_start(active_workers, mark_in_progress());
log_gc_header();
TraceCollectorStats tcs(g1mm()->incremental_collection_counters());
TraceMemoryManagerStats tms(false /* fullGC */, gc_cause());
*** 4484,4495 ****
};
void work(uint worker_id) {
if (worker_id >= _n_workers) return; // no work needed this round
! double start_time_ms = os::elapsedTime() * 1000.0;
! _g1h->g1_policy()->phase_times()->record_gc_worker_start_time(worker_id, start_time_ms);
{
ResourceMark rm;
HandleMark hm;
--- 4484,4494 ----
};
void work(uint worker_id) {
if (worker_id >= _n_workers) return; // no work needed this round
! _g1h->g1_policy()->phase_times()->record_time_secs(G1GCPhaseTimes::GCWorkerStart, worker_id, os::elapsedTime());
{
ResourceMark rm;
HandleMark hm;
*** 4565,4578 ****
{
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()->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);
if (PrintTerminationStats) {
--- 4564,4578 ----
{
double start = os::elapsedTime();
G1ParEvacuateFollowersClosure evac(_g1h, &pss, _queues, &_terminator);
evac.do_void();
! double elapsed_sec = os::elapsedTime() - start;
! double term_sec = pss.term_time();
! _g1h->g1_policy()->phase_times()->add_time_secs(G1GCPhaseTimes::ObjCopy, worker_id, elapsed_sec - term_sec);
! _g1h->g1_policy()->phase_times()->record_time_secs(G1GCPhaseTimes::Termination, worker_id, term_sec);
! _g1h->g1_policy()->phase_times()->record_sub_count(G1GCPhaseTimes::Termination, worker_id, pss.term_attempts());
}
_g1h->g1_policy()->record_thread_age_table(pss.age_table());
_g1h->update_surviving_young_words(pss.surviving_young_words()+1);
if (PrintTerminationStats) {
*** 4584,4596 ****
// Close the inner scope so that the ResourceMark and HandleMark
// destructors are executed here and are included as part of the
// "GC Worker Time".
}
!
! double end_time_ms = os::elapsedTime() * 1000.0;
! _g1h->g1_policy()->phase_times()->record_gc_worker_end_time(worker_id, end_time_ms);
}
};
// *** Common G1 Evacuation Stuff
--- 4584,4594 ----
// Close the inner scope so that the ResourceMark and HandleMark
// destructors are executed here and are included as part of the
// "GC Worker Time".
}
! _g1h->g1_policy()->phase_times()->record_time_secs(G1GCPhaseTimes::GCWorkerEnd, worker_id, os::elapsedTime());
}
};
// *** Common G1 Evacuation Stuff
*** 4648,4678 ****
buf_scan_non_heap_weak_roots.done();
double obj_copy_time_sec = buf_scan_non_heap_roots.closure_app_seconds()
+ buf_scan_non_heap_weak_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 =
! ((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;
}
}
- g1_policy()->phase_times()->record_satb_filtering_time(worker_i, satb_filtering_ms);
// Now scan the complement of the collection set.
G1CodeBlobClosure scavenge_cs_nmethods(scan_non_heap_weak_roots);
g1_rem_set()->oops_into_collection_set_do(scan_rs, &scavenge_cs_nmethods, worker_i);
--- 4646,4669 ----
buf_scan_non_heap_weak_roots.done();
double obj_copy_time_sec = buf_scan_non_heap_roots.closure_app_seconds()
+ buf_scan_non_heap_weak_roots.closure_app_seconds();
! g1_policy()->phase_times()->record_time_secs(G1GCPhaseTimes::ObjCopy, worker_i, obj_copy_time_sec);
! double ext_root_time_sec = os::elapsedTime() - ext_roots_start - obj_copy_time_sec;
! g1_policy()->phase_times()->record_time_secs(G1GCPhaseTimes::ExtRootScan, worker_i, ext_root_time_sec);
// 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).
! {
! G1GCPhaseTimesTracker x(g1_policy()->phase_times(), G1GCPhaseTimes::SATBFiltering, worker_i);
! if (!_process_strong_tasks->is_task_claimed(G1H_PS_filter_satb_buffers) && mark_in_progress()) {
JavaThread::satb_mark_queue_set().filter_thread_buffers();
}
}
// Now scan the complement of the collection set.
G1CodeBlobClosure scavenge_cs_nmethods(scan_non_heap_weak_roots);
g1_rem_set()->oops_into_collection_set_do(scan_rs, &scavenge_cs_nmethods, worker_i);
*** 5071,5088 ****
DirtyCardQueueSet* _queue;
public:
G1RedirtyLoggedCardsTask(DirtyCardQueueSet* queue) : AbstractGangTask("Redirty Cards"), _queue(queue) { }
virtual void work(uint worker_id) {
! double start_time = os::elapsedTime();
RedirtyLoggedCardTableEntryClosure cl;
_queue->par_apply_closure_to_all_completed_buffers(&cl);
! G1GCPhaseTimes* timer = G1CollectedHeap::heap()->g1_policy()->phase_times();
! timer->record_redirty_logged_cards_time_ms(worker_id, (os::elapsedTime() - start_time) * 1000.0);
! timer->record_redirty_logged_cards_processed_cards(worker_id, cl.num_processed());
}
};
void G1CollectedHeap::redirty_logged_cards() {
double redirty_logged_cards_start = os::elapsedTime();
--- 5062,5078 ----
DirtyCardQueueSet* _queue;
public:
G1RedirtyLoggedCardsTask(DirtyCardQueueSet* queue) : AbstractGangTask("Redirty Cards"), _queue(queue) { }
virtual void work(uint worker_id) {
! G1GCPhaseTimes* timer = G1CollectedHeap::heap()->g1_policy()->phase_times();
! G1GCPhaseTimesTracker x(timer, G1GCPhaseTimes::RedirtyCards, worker_id);
RedirtyLoggedCardTableEntryClosure cl;
_queue->par_apply_closure_to_all_completed_buffers(&cl);
! timer->record_sub_count(G1GCPhaseTimes::RedirtyCards, worker_id, cl.num_processed());
}
};
void G1CollectedHeap::redirty_logged_cards() {
double redirty_logged_cards_start = os::elapsedTime();
< prev index next >