@@ -135,14 +135,26 @@ G1ConcurrentRefineSweepState::~G1ConcurrentRefineSweepState() {
135135 delete _sweep_table;
136136}
137137
138- void G1ConcurrentRefineSweepState::set_state_start_time () {
139- _state_start[static_cast <uint>(_state)] = Ticks::now ();
138+ void G1ConcurrentRefineSweepState::enter_state (State state, Ticks timestamp) {
139+ assert (state > State::Idle, " precondition" );
140+ assert (state != State::Last, " preconditon" );
141+ assert (_state == State (static_cast <uint>(state) - 1 ),
142+ " must come from previous state but is %s" , state_name (_state));
143+
144+ _state_start[static_cast <uint>(state)] = timestamp;
145+ _state = state;
140146}
141147
142- Tickspan G1ConcurrentRefineSweepState::get_duration (State start, State end) {
148+ Tickspan G1ConcurrentRefineSweepState::get_duration (State start, State end) const {
149+ assert (end >= start, " precondition" );
143150 return _state_start[static_cast <uint>(end)] - _state_start[static_cast <uint>(start)];
144151}
145152
153+ Tickspan G1ConcurrentRefineSweepState::time_since_start (Ticks completion_time) const {
154+ assert (_state >= State::SwapGlobalCT, " precondition" );
155+ return completion_time - _state_start[static_cast <uint>(State::SwapGlobalCT)];
156+ }
157+
146158void G1ConcurrentRefineSweepState::reset_stats () {
147159 stats ()->reset ();
148160}
@@ -151,35 +163,11 @@ void G1ConcurrentRefineSweepState::add_yield_during_sweep_duration(jlong duratio
151163 stats ()->inc_yield_during_sweep_duration (duration);
152164}
153165
154- bool G1ConcurrentRefineSweepState::advance_state (State next_state) {
155- bool result = is_in_progress ();
156- if (result) {
157- _state = next_state;
158- } else {
159- _state = State::Idle;
160- }
161- return result;
162- }
163-
164- void G1ConcurrentRefineSweepState::assert_state (State expected) {
165- assert (_state == expected, " must be %s but is %s" , state_name (expected), state_name (_state));
166- }
167-
168- void G1ConcurrentRefineSweepState::start_work () {
169- assert_state (State::Idle);
170-
171- set_state_start_time ();
172-
173- _stats.reset ();
174-
175- _state = State::SwapGlobalCT;
176- }
177-
178166bool G1ConcurrentRefineSweepState::swap_global_card_table () {
179- assert_state (State::SwapGlobalCT);
167+ enter_state (State::SwapGlobalCT, Ticks::now ());
168+ _stats.reset ();
180169
181170 GCTraceTime (Info, gc, refine) tm (" Concurrent Refine Global Card Table Swap" );
182- set_state_start_time ();
183171
184172 {
185173 // We can't have any new threads being in the process of created while we
@@ -190,22 +178,20 @@ bool G1ConcurrentRefineSweepState::swap_global_card_table() {
190178
191179 MutexLocker mu (Threads_lock);
192180 // A GC that advanced the epoch might have happened, which already switched
193- // The global card table. Do nothing.
181+ // the global card table. Do nothing.
194182 if (is_in_progress ()) {
195183 G1BarrierSet::g1_barrier_set ()->swap_global_card_table ();
196184 }
197185 }
198186
199- return advance_state (State::SwapJavaThreadsCT );
187+ return is_in_progress ( );
200188}
201189
202190bool G1ConcurrentRefineSweepState::swap_java_threads_ct () {
203- assert_state (State::SwapJavaThreadsCT);
191+ enter_state (State::SwapJavaThreadsCT, Ticks::now () );
204192
205193 GCTraceTime (Info, gc, refine) tm (" Concurrent Refine Java Thread CT swap" );
206194
207- set_state_start_time ();
208-
209195 {
210196 // Need to leave the STS to avoid potential deadlock in the handshake.
211197 SuspendibleThreadSetLeaver sts;
@@ -222,16 +208,14 @@ bool G1ConcurrentRefineSweepState::swap_java_threads_ct() {
222208 Handshake::execute (&cl);
223209 }
224210
225- return advance_state (State::SynchronizeGCThreads );
226- }
211+ return is_in_progress ( );
212+ }
227213
228214bool G1ConcurrentRefineSweepState::swap_gc_threads_ct () {
229- assert_state (State::SynchronizeGCThreads);
215+ enter_state (State::SynchronizeGCThreads, Ticks::now () );
230216
231217 GCTraceTime (Info, gc, refine) tm (" Concurrent Refine GC Thread CT swap" );
232218
233- set_state_start_time ();
234-
235219 {
236220 class RendezvousGCThreads : public VM_Operation {
237221 public:
@@ -265,93 +249,148 @@ bool G1ConcurrentRefineSweepState::swap_gc_threads_ct() {
265249 VMThread::execute (&op);
266250 }
267251
268- return advance_state (State::SnapshotHeap );
252+ return is_in_progress ( );
269253}
270254
271- void G1ConcurrentRefineSweepState::snapshot_heap (bool concurrent) {
272- if (concurrent) {
273- GCTraceTime (Info, gc, refine) tm (" Concurrent Refine Snapshot Heap" );
255+ void G1ConcurrentRefineSweepState::snapshot_heap () {
256+ enter_state (State::SnapshotHeap, Ticks::now ());
274257
275- assert_state (State::SnapshotHeap );
258+ GCTraceTime (Info, gc, refine) tm ( " Concurrent Refine Snapshot Heap " );
276259
277- set_state_start_time ();
260+ snapshot_heap_inner ();
261+ }
278262
279- snapshot_heap_inner ();
263+ bool G1ConcurrentRefineSweepState::sweep_refinement_table (jlong& total_yield_duration) {
264+ enter_state (State::SweepRT, Ticks::now ());
280265
281- advance_state (State::SweepRT);
282- } else {
283- assert_state (State::Idle);
284- assert_at_safepoint ();
266+ while (true ) {
267+ {
268+ GCTraceTime (Info, gc, refine) tm (" Concurrent Refine Table Step" );
285269
286- snapshot_heap_inner ();
287- }
288- }
270+ G1ConcurrentRefine* cr = G1CollectedHeap::heap ()->concurrent_refine ();
271+
272+ G1ConcurrentRefineSweepTask task (_sweep_table, &_stats, cr->num_threads_wanted ());
273+ cr->run_with_refinement_workers (&task);
289274
290- void G1ConcurrentRefineSweepState::sweep_refinement_table_start () {
291- assert_state (State::SweepRT);
275+ assert (is_in_progress (), " inv" );
276+ if (task.sweep_completed ()) {
277+ return true ;
278+ }
279+ }
292280
293- set_state_start_time ();
281+ assert (SuspendibleThreadSet::should_yield (), " must be" );
282+ // Interrupted by safepoint request.
283+ {
284+ jlong yield_start = os::elapsed_counter ();
285+ SuspendibleThreadSet::yield ();
286+
287+ if (!is_in_progress ()) {
288+ return false ;
289+ } else {
290+ jlong yield_during_sweep_duration = os::elapsed_counter () - yield_start;
291+ log_trace (gc, refine)(" Yielded from card table sweeping for %.2fms, no GC inbetween, continue" ,
292+ TimeHelper::counter_to_millis (yield_during_sweep_duration));
293+ total_yield_duration += yield_during_sweep_duration;
294+ }
295+ }
296+ }
294297}
295298
296- bool G1ConcurrentRefineSweepState::sweep_refinement_table_step () {
297- assert_state (State::SweepRT);
299+ static void print_refinement_stats (const Tickspan& total_duration,
300+ const Tickspan& pre_sweep_duration,
301+ const G1ConcurrentRefineStats* stats) {
302+ assert (total_duration >= Tickspan (), " must be non-negative" );
303+ assert (pre_sweep_duration >= Tickspan (), " must be non-negative" );
304+ assert (pre_sweep_duration <= total_duration, " must be bounded by total duration" );
305+
306+ log_debug (gc, refine)(" Refinement took %.2fms (pre-sweep %.2fms card refine %.2fms) "
307+ " (scanned %zu clean %zu (%.2f%%) not_clean %zu (%.2f%%) not_parsable %zu "
308+ " refers_to_cset %zu (%.2f%%) still_refers_to_cset %zu (%.2f%%) no_cross_region %zu pending %zu)" ,
309+ total_duration.seconds () * 1000.0 ,
310+ pre_sweep_duration.seconds () * 1000.0 ,
311+ TimeHelper::counter_to_millis (stats->refine_duration ()),
312+ stats->cards_scanned (),
313+ stats->cards_clean (),
314+ percent_of (stats->cards_clean (), stats->cards_scanned ()),
315+ stats->cards_not_clean (),
316+ percent_of (stats->cards_not_clean (), stats->cards_scanned ()),
317+ stats->cards_not_parsable (),
318+ stats->cards_refer_to_cset (),
319+ percent_of (stats->cards_refer_to_cset (), stats->cards_not_clean ()),
320+ stats->cards_already_refer_to_cset (),
321+ percent_of (stats->cards_already_refer_to_cset (), stats->cards_not_clean ()),
322+ stats->cards_no_cross_region (),
323+ stats->cards_pending ()
324+ );
325+ }
326+
327+ void G1ConcurrentRefineSweepState::handle_ongoing_refinement_at_safepoint () {
328+ assert_at_safepoint ();
329+ if (!is_in_progress ()) {
330+ return ;
331+ }
332+
333+ const Ticks completion_time = Ticks::now ();
298334
299- GCTraceTime (Info, gc, refine) tm (" Concurrent Refine Table Step" );
335+ const Tickspan total_duration = time_since_start (completion_time);
336+ const Tickspan pre_sweep_duration = get_duration (State::SwapGlobalCT, MIN2 (_state, State::SweepRT));
300337
301- G1ConcurrentRefine* cr = G1CollectedHeap::heap ()-> concurrent_refine ( );
338+ print_refinement_stats (total_duration, pre_sweep_duration, &_stats );
302339
303- G1ConcurrentRefineSweepTask task (_sweep_table, &_stats, cr->num_threads_wanted ());
304- cr->run_with_refinement_workers (&task);
340+ const bool is_in_sweep_rt = _state == State::SweepRT;
305341
306- if (task.sweep_completed ()) {
307- advance_state (State::CompleteRefineWork);
308- return true ;
342+ if (!is_in_sweep_rt) {
343+ // Refinement has been interrupted without having a snapshot. There may
344+ // be a mix of already swapped and not-swapped card tables assigned to threads,
345+ // so they might have already dirtied the swapped card tables.
346+ // Conservatively scan all (non-free, non-committed) region's card tables,
347+ // creating the snapshot right now.
348+ log_debug (gc, refine)(" Create work from scratch" );
349+ snapshot_heap_inner ();
309350 } else {
310- return false ;
351+ log_debug (gc, refine)( " Continue existing work " ) ;
311352 }
353+
354+ _state = State::Idle;
312355}
313356
314- bool G1ConcurrentRefineSweepState::complete_work (bool concurrent, bool print_log) {
315- if (concurrent) {
316- assert_state (State::CompleteRefineWork);
317- } else {
318- // May have been forced to complete at any other time.
319- assert (is_in_progress () && _state != State::CompleteRefineWork, " must be but is %s" , state_name (_state));
320- }
357+ void G1ConcurrentRefineSweepState::cancel_refinement () {
358+ _state = State::Idle;
359+ }
321360
322- set_state_start_time ();
323-
324- if (print_log) {
325- G1ConcurrentRefineStats* s = &_stats;
326-
327- State state_bounded_by_sweeprt = (_state == State::SweepRT || _state == State::CompleteRefineWork)
328- ? State::SweepRT : _state;
329-
330- log_debug (gc, refine)(" Refinement took %.2fms (pre-sweep %.2fms card refine %.2fms) "
331- " (scanned %zu clean %zu (%.2f%%) not_clean %zu (%.2f%%) not_parsable %zu "
332- " refers_to_cset %zu (%.2f%%) still_refers_to_cset %zu (%.2f%%) no_cross_region %zu pending %zu)" ,
333- get_duration (State::Idle, _state).seconds () * 1000.0 ,
334- get_duration (State::Idle, state_bounded_by_sweeprt).seconds () * 1000.0 ,
335- TimeHelper::counter_to_millis (s->refine_duration ()),
336- s->cards_scanned (),
337- s->cards_clean (),
338- percent_of (s->cards_clean (), s->cards_scanned ()),
339- s->cards_not_clean (),
340- percent_of (s->cards_not_clean (), s->cards_scanned ()),
341- s->cards_not_parsable (),
342- s->cards_refer_to_cset (),
343- percent_of (s->cards_refer_to_cset (), s->cards_not_clean ()),
344- s->cards_already_refer_to_cset (),
345- percent_of (s->cards_already_refer_to_cset (), s->cards_not_clean ()),
346- s->cards_no_cross_region (),
347- s->cards_pending ()
348- );
349- }
361+ void G1ConcurrentRefineSweepState::complete_refinement (jlong total_yield_during_sweep_duration,
362+ jlong epoch_yield_duration,
363+ jlong next_epoch_start) {
364+ enter_state (State::CompleteRefineWork, Ticks::now ());
365+
366+ GCTraceTime (Info, gc, refine) tm (" Concurrent Refine Complete Work" );
367+
368+ add_yield_during_sweep_duration (total_yield_during_sweep_duration);
369+
370+ const Ticks completion_time = Ticks::now ();
350371
351- bool has_sweep_rt_work = _state == State::SweepRT;
372+ const Tickspan total_duration = time_since_start (completion_time);
373+ const Tickspan pre_sweep_duration = get_duration (State::SwapGlobalCT, State::SweepRT);
352374
353- advance_state (State::Idle);
354- return has_sweep_rt_work;
375+ print_refinement_stats (total_duration, pre_sweep_duration, &_stats);
376+
377+ G1CollectedHeap* g1h = G1CollectedHeap::heap ();
378+ G1Policy* policy = g1h->policy ();
379+ policy->record_refinement_stats (stats ());
380+
381+ {
382+ MutexLocker x (G1ReviseYoungLength_lock, Mutex::_no_safepoint_check_flag);
383+ policy->record_dirtying_stats (TimeHelper::counter_to_millis (g1h->last_refinement_epoch_start ()),
384+ TimeHelper::counter_to_millis (next_epoch_start),
385+ _stats.cards_pending (),
386+ TimeHelper::counter_to_millis (epoch_yield_duration),
387+ 0 /* pending_cards_from_gc */ ,
388+ _stats.cards_to_cset ());
389+ g1h->set_last_refinement_epoch_start (next_epoch_start, epoch_yield_duration);
390+ }
391+ _stats.reset ();
392+
393+ _state = State::Idle;
355394}
356395
357396void G1ConcurrentRefineSweepState::snapshot_heap_inner () {
@@ -383,10 +422,6 @@ void G1ConcurrentRefineSweepState::snapshot_heap_inner() {
383422 G1CollectedHeap::heap ()->heap_region_iterate (&cl);
384423}
385424
386- bool G1ConcurrentRefineSweepState::is_in_progress () const {
387- return _state != State::Idle;
388- }
389-
390425bool G1ConcurrentRefineSweepState::are_java_threads_synched () const {
391426 return _state > State::SwapJavaThreadsCT || !is_in_progress ();
392427}
@@ -422,19 +457,8 @@ jint G1ConcurrentRefine::initialize() {
422457}
423458
424459G1ConcurrentRefineSweepState& G1ConcurrentRefine::sweep_state_for_merge () {
425- bool has_sweep_claims = sweep_state ().complete_work (false /* concurrent */ );
426- if (has_sweep_claims) {
427- log_debug (gc, refine)(" Continue existing work" );
428- } else {
429- // Refinement has been interrupted without having a snapshot. There may
430- // be a mix of already swapped and not-swapped card tables assigned to threads,
431- // so they might have already dirtied the swapped card tables.
432- // Conservatively scan all (non-free, non-committed) region's card tables,
433- // creating the snapshot right now.
434- log_debug (gc, refine)(" Create work from scratch" );
435-
436- sweep_state ().snapshot_heap (false /* concurrent */ );
437- }
460+ sweep_state ().handle_ongoing_refinement_at_safepoint ();
461+ assert (!sweep_state ().is_in_progress (), " postcondition" );
438462 return sweep_state ();
439463}
440464
0 commit comments