# HG changeset patch # User mseledtsov # Date 1502316209 25200 # Node ID 50dca6b8294e06ace8396043177fde3651624abf # Parent d80ca591ae48ce8f225dd3198c466f4832177072# Parent f504c6f2eea58acff960a480c2c94322294c87b1 Merge diff -r d80ca591ae48 -r 50dca6b8294e hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp --- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Thu Aug 03 10:24:34 2017 +0200 +++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Wed Aug 09 15:03:29 2017 -0700 @@ -3237,7 +3237,7 @@ // investigate this in CR 7178365. double sample_end_time_sec = os::elapsedTime(); double pause_time_ms = (sample_end_time_sec - sample_start_time_sec) * MILLIUNITS; - size_t total_cards_scanned = g1_policy()->phase_times()->sum_thread_work_items(G1GCPhaseTimes::ScanRS, G1GCPhaseTimes::ScannedCards); + size_t total_cards_scanned = g1_policy()->phase_times()->sum_thread_work_items(G1GCPhaseTimes::ScanRS, G1GCPhaseTimes::ScanRSScannedCards); g1_policy()->record_collection_pause_end(pause_time_ms, total_cards_scanned, heap_used_bytes_before_gc); evacuation_info.set_collectionset_used_before(collection_set()->bytes_used_before()); diff -r d80ca591ae48 -r 50dca6b8294e hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp --- a/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp Thu Aug 03 10:24:34 2017 +0200 +++ b/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.cpp Wed Aug 09 15:03:29 2017 -0700 @@ -81,14 +81,18 @@ _gc_par_phases[Other] = new WorkerDataArray(max_gc_threads, "GC Worker Other (ms):"); _scan_rs_scanned_cards = new WorkerDataArray(max_gc_threads, "Scanned Cards:"); - _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_scanned_cards, ScannedCards); + _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_scanned_cards, ScanRSScannedCards); _scan_rs_claimed_cards = new WorkerDataArray(max_gc_threads, "Claimed Cards:"); - _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_claimed_cards, ClaimedCards); + _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_claimed_cards, ScanRSClaimedCards); _scan_rs_skipped_cards = new WorkerDataArray(max_gc_threads, "Skipped Cards:"); - _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_skipped_cards, SkippedCards); + _gc_par_phases[ScanRS]->link_thread_work_items(_scan_rs_skipped_cards, ScanRSSkippedCards); _update_rs_processed_buffers = new WorkerDataArray(max_gc_threads, "Processed Buffers:"); - _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_processed_buffers); + _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_processed_buffers, UpdateRSProcessedBuffers); + _update_rs_scanned_cards = new WorkerDataArray(max_gc_threads, "Scanned Cards:"); + _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_scanned_cards, UpdateRSScannedCards); + _update_rs_skipped_cards = new WorkerDataArray(max_gc_threads, "Skipped Cards:"); + _gc_par_phases[UpdateRS]->link_thread_work_items(_update_rs_skipped_cards, ScanRSSkippedCards); _termination_attempts = new WorkerDataArray(max_gc_threads, "Termination Attempts:"); _gc_par_phases[Termination]->link_thread_work_items(_termination_attempts); diff -r d80ca591ae48 -r 50dca6b8294e hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp --- a/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp Thu Aug 03 10:24:34 2017 +0200 +++ b/hotspot/src/share/vm/gc/g1/g1GCPhaseTimes.hpp Wed Aug 09 15:03:29 2017 -0700 @@ -78,9 +78,15 @@ }; enum GCScanRSWorkItems { - ScannedCards, - ClaimedCards, - SkippedCards + ScanRSScannedCards, + ScanRSClaimedCards, + ScanRSSkippedCards + }; + + enum GCUpdateRSWorkItems { + UpdateRSProcessedBuffers, + UpdateRSScannedCards, + UpdateRSSkippedCards }; private: @@ -92,6 +98,8 @@ WorkerDataArray* _gc_par_phases[GCParPhasesSentinel]; WorkerDataArray* _update_rs_processed_buffers; + WorkerDataArray* _update_rs_scanned_cards; + WorkerDataArray* _update_rs_skipped_cards; WorkerDataArray* _scan_rs_scanned_cards; WorkerDataArray* _scan_rs_claimed_cards; diff -r d80ca591ae48 -r 50dca6b8294e hotspot/src/share/vm/gc/g1/g1RemSet.cpp --- a/hotspot/src/share/vm/gc/g1/g1RemSet.cpp Thu Aug 03 10:24:34 2017 +0200 +++ b/hotspot/src/share/vm/gc/g1/g1RemSet.cpp Wed Aug 09 15:03:29 2017 -0700 @@ -429,9 +429,9 @@ G1GCPhaseTimes* p = _g1p->phase_times(); p->record_time_secs(G1GCPhaseTimes::ScanRS, worker_i, scan_rs_time_sec); - p->record_thread_work_item(G1GCPhaseTimes::ScanRS, worker_i, cl.cards_scanned(), G1GCPhaseTimes::ScannedCards); - p->record_thread_work_item(G1GCPhaseTimes::ScanRS, worker_i, cl.cards_claimed(), G1GCPhaseTimes::ClaimedCards); - p->record_thread_work_item(G1GCPhaseTimes::ScanRS, worker_i, cl.cards_skipped(), G1GCPhaseTimes::SkippedCards); + p->record_thread_work_item(G1GCPhaseTimes::ScanRS, worker_i, cl.cards_scanned(), G1GCPhaseTimes::ScanRSScannedCards); + p->record_thread_work_item(G1GCPhaseTimes::ScanRS, worker_i, cl.cards_claimed(), G1GCPhaseTimes::ScanRSClaimedCards); + p->record_thread_work_item(G1GCPhaseTimes::ScanRS, worker_i, cl.cards_skipped(), G1GCPhaseTimes::ScanRSSkippedCards); p->record_time_secs(G1GCPhaseTimes::CodeRoots, worker_i, cl.strong_code_root_scan_time_sec()); } @@ -440,9 +440,12 @@ class G1RefineCardClosure: public CardTableEntryClosure { G1RemSet* _g1rs; G1ScanObjsDuringUpdateRSClosure* _update_rs_cl; + + size_t _cards_scanned; + size_t _cards_skipped; public: G1RefineCardClosure(G1CollectedHeap* g1h, G1ScanObjsDuringUpdateRSClosure* update_rs_cl) : - _g1rs(g1h->g1_rem_set()), _update_rs_cl(update_rs_cl) + _g1rs(g1h->g1_rem_set()), _update_rs_cl(update_rs_cl), _cards_scanned(0), _cards_skipped(0) {} bool do_card_ptr(jbyte* card_ptr, uint worker_i) { @@ -452,9 +455,18 @@ // In this case worker_i should be the id of a GC worker thread. assert(SafepointSynchronize::is_at_safepoint(), "not during an evacuation pause"); - _g1rs->refine_card_during_gc(card_ptr, _update_rs_cl); + bool card_scanned = _g1rs->refine_card_during_gc(card_ptr, _update_rs_cl); + + if (card_scanned) { + _cards_scanned++; + } else { + _cards_skipped++; + } return true; } + + size_t cards_scanned() const { return _cards_scanned; } + size_t cards_skipped() const { return _cards_skipped; } }; void G1RemSet::update_rem_set(G1ParScanThreadState* pss, uint worker_i) { @@ -469,6 +481,10 @@ } // Apply the closure to all remaining log entries. _g1->iterate_dirty_card_closure(&refine_card_cl, worker_i); + + G1GCPhaseTimes* p = _g1p->phase_times(); + p->record_thread_work_item(G1GCPhaseTimes::UpdateRS, worker_i, refine_card_cl.cards_scanned(), G1GCPhaseTimes::UpdateRSScannedCards); + p->record_thread_work_item(G1GCPhaseTimes::UpdateRS, worker_i, refine_card_cl.cards_skipped(), G1GCPhaseTimes::UpdateRSSkippedCards); } void G1RemSet::cleanupHRRS() { @@ -680,7 +696,7 @@ } } -void G1RemSet::refine_card_during_gc(jbyte* card_ptr, +bool G1RemSet::refine_card_during_gc(jbyte* card_ptr, G1ScanObjsDuringUpdateRSClosure* update_rs_cl) { assert(_g1->is_gc_active(), "Only call during GC"); @@ -689,7 +705,7 @@ // If the card is no longer dirty, nothing to do. This covers cards that were already // scanned as parts of the remembered sets. if (*card_ptr != CardTableModRefBS::dirty_card_val()) { - return; + return false; } // We claim lazily (so races are possible but they're benign), which reduces the @@ -705,7 +721,7 @@ HeapWord* scan_limit = _scan_state->scan_top(card_region_idx); if (scan_limit <= card_start) { // If the card starts above the area in the region containing objects to scan, skip it. - return; + return false; } // Don't use addr_for(card_ptr + 1) which can ask for @@ -718,6 +734,7 @@ update_rs_cl->set_region(card_region); bool card_processed = card_region->oops_on_card_seq_iterate_careful(dirty_region, update_rs_cl); assert(card_processed, "must be"); + return true; } void G1RemSet::print_periodic_summary_info(const char* header, uint period_count) { diff -r d80ca591ae48 -r 50dca6b8294e hotspot/src/share/vm/gc/g1/g1RemSet.hpp --- a/hotspot/src/share/vm/gc/g1/g1RemSet.hpp Thu Aug 03 10:24:34 2017 +0200 +++ b/hotspot/src/share/vm/gc/g1/g1RemSet.hpp Wed Aug 09 15:03:29 2017 -0700 @@ -128,7 +128,8 @@ // Refine the card corresponding to "card_ptr", applying the given closure to // all references found. Must only be called during gc. - void refine_card_during_gc(jbyte* card_ptr, G1ScanObjsDuringUpdateRSClosure* update_rs_cl); + // Returns whether the card has been scanned. + bool refine_card_during_gc(jbyte* card_ptr, G1ScanObjsDuringUpdateRSClosure* update_rs_cl); // Print accumulated summary info from the start of the VM. void print_summary_info(); diff -r d80ca591ae48 -r 50dca6b8294e hotspot/test/gc/g1/TestGCLogMessages.java --- a/hotspot/test/gc/g1/TestGCLogMessages.java Thu Aug 03 10:24:34 2017 +0200 +++ b/hotspot/test/gc/g1/TestGCLogMessages.java Wed Aug 09 15:03:29 2017 -0700 @@ -96,6 +96,8 @@ // Update RS new LogMessageWithLevel("Update RS", Level.DEBUG), new LogMessageWithLevel("Processed Buffers", Level.DEBUG), + new LogMessageWithLevel("Scanned Cards", Level.DEBUG), + new LogMessageWithLevel("Skipped Cards", Level.DEBUG), new LogMessageWithLevel("Scan HCC", Level.TRACE), // Scan RS new LogMessageWithLevel("Scan RS", Level.DEBUG),