# HG changeset patch # User tonyp # Date 1301941397 14400 # Node ID 371bbc844bf1990cd7c7ad30a045cafe8394ccad # Parent c84ee870e0b926ed0d220c4b0a00ea01981f15f5 7027766: G1: introduce flag to dump the liveness information per region at the end of marking Summary: Repurpose the existing flag G1PrintRegionLivenessInfo to print out the liveness distribution across the regions in the heap at the end of marking. Reviewed-by: iveresov, jwilhelm diff -r c84ee870e0b9 -r 371bbc844bf1 src/share/vm/gc_implementation/g1/collectionSetChooser.cpp --- a/src/share/vm/gc_implementation/g1/collectionSetChooser.cpp Mon Apr 04 13:18:35 2011 -0400 +++ b/src/share/vm/gc_implementation/g1/collectionSetChooser.cpp Mon Apr 04 14:23:17 2011 -0400 @@ -262,39 +262,18 @@ for (int i = 0; i < _numMarkedRegions; i++) { assert(_markedRegions.at(i) != NULL, "Should be true by sorting!"); _markedRegions.at(i)->set_sort_index(i); - if (G1PrintRegionLivenessInfo > 0) { - if (i == 0) gclog_or_tty->print_cr("Sorted marked regions:"); - if (i < G1PrintRegionLivenessInfo || - (_numMarkedRegions-i) < G1PrintRegionLivenessInfo) { - HeapRegion* hr = _markedRegions.at(i); - size_t u = hr->used(); - gclog_or_tty->print_cr(" Region %d: %d used, %d max live, %5.2f%%.", - i, u, hr->max_live_bytes(), - 100.0*(float)hr->max_live_bytes()/(float)u); - } + } + if (G1PrintRegionLivenessInfo) { + G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Sorting"); + for (int i = 0; i < _numMarkedRegions; ++i) { + HeapRegion* r = _markedRegions.at(i); + cl.doHeapRegion(r); } } - if (G1PolicyVerbose > 1) - printSortedHeapRegions(); assert(verify(), "should now be sorted"); } void -printHeapRegion(HeapRegion *hr) { - if (hr->isHumongous()) - gclog_or_tty->print("H: "); - if (hr->in_collection_set()) - gclog_or_tty->print("CS: "); - gclog_or_tty->print_cr("Region " PTR_FORMAT " (%s%s) " - "[" PTR_FORMAT ", " PTR_FORMAT"] " - "Used: " SIZE_FORMAT "K, garbage: " SIZE_FORMAT "K.", - hr, hr->is_young() ? "Y " : " ", - hr->is_marked()? "M1" : "M0", - hr->bottom(), hr->end(), - hr->used()/K, hr->garbage_bytes()/K); -} - -void CollectionSetChooser::addMarkedHeapRegion(HeapRegion* hr) { assert(!hr->isHumongous(), "Humongous regions shouldn't be added to the collection set"); @@ -351,27 +330,9 @@ void CollectionSetChooser::updateAfterFullCollection() { - G1CollectedHeap* g1h = G1CollectedHeap::heap(); clearMarkedHeapRegions(); } -void -CollectionSetChooser::printSortedHeapRegions() { - gclog_or_tty->print_cr("Printing %d Heap Regions sorted by amount of known garbage", - _numMarkedRegions); - - DEBUG_ONLY(int marked_count = 0;) - for (int i = 0; i < _markedRegions.length(); i++) { - HeapRegion* r = _markedRegions.at(i); - if (r != NULL) { - printHeapRegion(r); - DEBUG_ONLY(marked_count++;) - } - } - assert(marked_count == _numMarkedRegions, "must be"); - gclog_or_tty->print_cr("Done sorted heap region print"); -} - void CollectionSetChooser::removeRegion(HeapRegion *hr) { int si = hr->sort_index(); assert(si == -1 || hr->is_marked(), "Sort index not valid."); diff -r c84ee870e0b9 -r 371bbc844bf1 src/share/vm/gc_implementation/g1/collectionSetChooser.hpp --- a/src/share/vm/gc_implementation/g1/collectionSetChooser.hpp Mon Apr 04 13:18:35 2011 -0400 +++ b/src/share/vm/gc_implementation/g1/collectionSetChooser.hpp Mon Apr 04 14:23:17 2011 -0400 @@ -100,8 +100,6 @@ CollectionSetChooser(); - void printSortedHeapRegions(); - void sortMarkedHeapRegions(); void fillCache(); bool addRegionToCache(void); diff -r c84ee870e0b9 -r 371bbc844bf1 src/share/vm/gc_implementation/g1/concurrentMark.cpp --- a/src/share/vm/gc_implementation/g1/concurrentMark.cpp Mon Apr 04 13:18:35 2011 -0400 +++ b/src/share/vm/gc_implementation/g1/concurrentMark.cpp Mon Apr 04 14:23:17 2011 -0400 @@ -1204,7 +1204,6 @@ g1p->record_concurrent_mark_remark_end(); } - #define CARD_BM_TEST_MODE 0 class CalcLiveObjectsClosure: public HeapRegionClosure { @@ -1726,6 +1725,11 @@ } _total_counting_time += this_final_counting_time; + if (G1PrintRegionLivenessInfo) { + G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Marking"); + _g1h->heap_region_iterate(&cl); + } + // Install newly created mark bitMap as "prev". swapMarkBitMaps(); @@ -4423,3 +4427,175 @@ _marking_step_diffs_ms.add(0.5); } + +// These are formatting macros that are used below to ensure +// consistent formatting. The *_H_* versions are used to format the +// header for a particular value and they should be kept consistent +// with the corresponding macro. Also note that most of the macros add +// the necessary white space (as a prefix) which makes them a bit +// easier to compose. + +// All the output lines are prefixed with this string to be able to +// identify them easily in a large log file. +#define G1PPRL_LINE_PREFIX "###" + +#define G1PPRL_ADDR_BASE_FORMAT " "PTR_FORMAT"-"PTR_FORMAT +#ifdef _LP64 +#define G1PPRL_ADDR_BASE_H_FORMAT " %37s" +#else // _LP64 +#define G1PPRL_ADDR_BASE_H_FORMAT " %21s" +#endif // _LP64 + +// For per-region info +#define G1PPRL_TYPE_FORMAT " %-4s" +#define G1PPRL_TYPE_H_FORMAT " %4s" +#define G1PPRL_BYTE_FORMAT " "SIZE_FORMAT_W(9) +#define G1PPRL_BYTE_H_FORMAT " %9s" +#define G1PPRL_DOUBLE_FORMAT " %14.1f" +#define G1PPRL_DOUBLE_H_FORMAT " %14s" + +// For summary info +#define G1PPRL_SUM_ADDR_FORMAT(tag) " "tag":"G1PPRL_ADDR_BASE_FORMAT +#define G1PPRL_SUM_BYTE_FORMAT(tag) " "tag": "SIZE_FORMAT +#define G1PPRL_SUM_MB_FORMAT(tag) " "tag": %1.2f MB" +#define G1PPRL_SUM_MB_PERC_FORMAT(tag) G1PPRL_SUM_MB_FORMAT(tag)" / %1.2f %%" + +G1PrintRegionLivenessInfoClosure:: +G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name) + : _out(out), + _total_used_bytes(0), _total_capacity_bytes(0), + _total_prev_live_bytes(0), _total_next_live_bytes(0), + _hum_used_bytes(0), _hum_capacity_bytes(0), + _hum_prev_live_bytes(0), _hum_next_live_bytes(0) { + G1CollectedHeap* g1h = G1CollectedHeap::heap(); + MemRegion g1_committed = g1h->g1_committed(); + MemRegion g1_reserved = g1h->g1_reserved(); + double now = os::elapsedTime(); + + // Print the header of the output. + _out->cr(); + _out->print_cr(G1PPRL_LINE_PREFIX" PHASE %s @ %1.3f", phase_name, now); + _out->print_cr(G1PPRL_LINE_PREFIX" HEAP" + G1PPRL_SUM_ADDR_FORMAT("committed") + G1PPRL_SUM_ADDR_FORMAT("reserved") + G1PPRL_SUM_BYTE_FORMAT("region-size"), + g1_committed.start(), g1_committed.end(), + g1_reserved.start(), g1_reserved.end(), + HeapRegion::GrainBytes); + _out->print_cr(G1PPRL_LINE_PREFIX); + _out->print_cr(G1PPRL_LINE_PREFIX + G1PPRL_TYPE_H_FORMAT + G1PPRL_ADDR_BASE_H_FORMAT + G1PPRL_BYTE_H_FORMAT + G1PPRL_BYTE_H_FORMAT + G1PPRL_BYTE_H_FORMAT + G1PPRL_DOUBLE_H_FORMAT, + "type", "address-range", + "used", "prev-live", "next-live", "gc-eff"); +} + +// It takes as a parameter a reference to one of the _hum_* fields, it +// deduces the corresponding value for a region in a humongous region +// series (either the region size, or what's left if the _hum_* field +// is < the region size), and updates the _hum_* field accordingly. +size_t G1PrintRegionLivenessInfoClosure::get_hum_bytes(size_t* hum_bytes) { + size_t bytes = 0; + // The > 0 check is to deal with the prev and next live bytes which + // could be 0. + if (*hum_bytes > 0) { + bytes = MIN2((size_t) HeapRegion::GrainBytes, *hum_bytes); + *hum_bytes -= bytes; + } + return bytes; +} + +// It deduces the values for a region in a humongous region series +// from the _hum_* fields and updates those accordingly. It assumes +// that that _hum_* fields have already been set up from the "starts +// humongous" region and we visit the regions in address order. +void G1PrintRegionLivenessInfoClosure::get_hum_bytes(size_t* used_bytes, + size_t* capacity_bytes, + size_t* prev_live_bytes, + size_t* next_live_bytes) { + assert(_hum_used_bytes > 0 && _hum_capacity_bytes > 0, "pre-condition"); + *used_bytes = get_hum_bytes(&_hum_used_bytes); + *capacity_bytes = get_hum_bytes(&_hum_capacity_bytes); + *prev_live_bytes = get_hum_bytes(&_hum_prev_live_bytes); + *next_live_bytes = get_hum_bytes(&_hum_next_live_bytes); +} + +bool G1PrintRegionLivenessInfoClosure::doHeapRegion(HeapRegion* r) { + const char* type = ""; + HeapWord* bottom = r->bottom(); + HeapWord* end = r->end(); + size_t capacity_bytes = r->capacity(); + size_t used_bytes = r->used(); + size_t prev_live_bytes = r->live_bytes(); + size_t next_live_bytes = r->next_live_bytes(); + double gc_eff = r->gc_efficiency(); + if (r->used() == 0) { + type = "FREE"; + } else if (r->is_survivor()) { + type = "SURV"; + } else if (r->is_young()) { + type = "EDEN"; + } else if (r->startsHumongous()) { + type = "HUMS"; + + assert(_hum_used_bytes == 0 && _hum_capacity_bytes == 0 && + _hum_prev_live_bytes == 0 && _hum_next_live_bytes == 0, + "they should have been zeroed after the last time we used them"); + // Set up the _hum_* fields. + _hum_capacity_bytes = capacity_bytes; + _hum_used_bytes = used_bytes; + _hum_prev_live_bytes = prev_live_bytes; + _hum_next_live_bytes = next_live_bytes; + get_hum_bytes(&used_bytes, &capacity_bytes, + &prev_live_bytes, &next_live_bytes); + end = bottom + HeapRegion::GrainWords; + } else if (r->continuesHumongous()) { + type = "HUMC"; + get_hum_bytes(&used_bytes, &capacity_bytes, + &prev_live_bytes, &next_live_bytes); + assert(end == bottom + HeapRegion::GrainWords, "invariant"); + } else { + type = "OLD"; + } + + _total_used_bytes += used_bytes; + _total_capacity_bytes += capacity_bytes; + _total_prev_live_bytes += prev_live_bytes; + _total_next_live_bytes += next_live_bytes; + + // Print a line for this particular region. + _out->print_cr(G1PPRL_LINE_PREFIX + G1PPRL_TYPE_FORMAT + G1PPRL_ADDR_BASE_FORMAT + G1PPRL_BYTE_FORMAT + G1PPRL_BYTE_FORMAT + G1PPRL_BYTE_FORMAT + G1PPRL_DOUBLE_FORMAT, + type, bottom, end, + used_bytes, prev_live_bytes, next_live_bytes, gc_eff); + + return false; +} + +G1PrintRegionLivenessInfoClosure::~G1PrintRegionLivenessInfoClosure() { + // Print the footer of the output. + _out->print_cr(G1PPRL_LINE_PREFIX); + _out->print_cr(G1PPRL_LINE_PREFIX + " SUMMARY" + G1PPRL_SUM_MB_FORMAT("capacity") + G1PPRL_SUM_MB_PERC_FORMAT("used") + G1PPRL_SUM_MB_PERC_FORMAT("prev-live") + G1PPRL_SUM_MB_PERC_FORMAT("next-live"), + bytes_to_mb(_total_capacity_bytes), + bytes_to_mb(_total_used_bytes), + perc(_total_used_bytes, _total_capacity_bytes), + bytes_to_mb(_total_prev_live_bytes), + perc(_total_prev_live_bytes, _total_capacity_bytes), + bytes_to_mb(_total_next_live_bytes), + perc(_total_next_live_bytes, _total_capacity_bytes)); + _out->cr(); +} diff -r c84ee870e0b9 -r 371bbc844bf1 src/share/vm/gc_implementation/g1/concurrentMark.hpp --- a/src/share/vm/gc_implementation/g1/concurrentMark.hpp Mon Apr 04 13:18:35 2011 -0400 +++ b/src/share/vm/gc_implementation/g1/concurrentMark.hpp Mon Apr 04 14:23:17 2011 -0400 @@ -1149,4 +1149,54 @@ #endif // _MARKING_STATS_ }; +// Class that's used to to print out per-region liveness +// information. It's currently used at the end of marking and also +// after we sort the old regions at the end of the cleanup operation. +class G1PrintRegionLivenessInfoClosure: public HeapRegionClosure { +private: + outputStream* _out; + + // Accumulators for these values. + size_t _total_used_bytes; + size_t _total_capacity_bytes; + size_t _total_prev_live_bytes; + size_t _total_next_live_bytes; + + // These are set up when we come across a "stars humongous" region + // (as this is where most of this information is stored, not in the + // subsequent "continues humongous" regions). After that, for every + // region in a given humongous region series we deduce the right + // values for it by simply subtracting the appropriate amount from + // these fields. All these values should reach 0 after we've visited + // the last region in the series. + size_t _hum_used_bytes; + size_t _hum_capacity_bytes; + size_t _hum_prev_live_bytes; + size_t _hum_next_live_bytes; + + static double perc(size_t val, size_t total) { + if (total == 0) { + return 0.0; + } else { + return 100.0 * ((double) val / (double) total); + } + } + + static double bytes_to_mb(size_t val) { + return (double) val / (double) M; + } + + // See the .cpp file. + size_t get_hum_bytes(size_t* hum_bytes); + void get_hum_bytes(size_t* used_bytes, size_t* capacity_bytes, + size_t* prev_live_bytes, size_t* next_live_bytes); + +public: + // The header and footer are printed in the constructor and + // destructor respectively. + G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name); + virtual bool doHeapRegion(HeapRegion* r); + ~G1PrintRegionLivenessInfoClosure(); +}; + #endif // SHARE_VM_GC_IMPLEMENTATION_G1_CONCURRENTMARK_HPP diff -r c84ee870e0b9 -r 371bbc844bf1 src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp --- a/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp Mon Apr 04 13:18:35 2011 -0400 +++ b/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp Mon Apr 04 14:23:17 2011 -0400 @@ -1057,7 +1057,13 @@ return _g1_reserved.contains(p); } - // Returns a MemRegion that corresponds to the space that has been + // Returns a MemRegion that corresponds to the space that has been + // reserved for the heap + MemRegion g1_reserved() { + return _g1_reserved; + } + + // Returns a MemRegion that corresponds to the space that has been // committed in the heap MemRegion g1_committed() { return _g1_committed; diff -r c84ee870e0b9 -r 371bbc844bf1 src/share/vm/gc_implementation/g1/g1_globals.hpp --- a/src/share/vm/gc_implementation/g1/g1_globals.hpp Mon Apr 04 13:18:35 2011 -0400 +++ b/src/share/vm/gc_implementation/g1/g1_globals.hpp Mon Apr 04 14:23:17 2011 -0400 @@ -138,9 +138,9 @@ develop(bool, G1RSCountHisto, false, \ "If true, print a histogram of RS occupancies after each pause") \ \ - develop(intx, G1PrintRegionLivenessInfo, 0, \ - "When > 0, print the occupancies of the best and worst" \ - "regions.") \ + product(bool, G1PrintRegionLivenessInfo, false, \ + "Prints the liveness information for all regions in the heap " \ + "at the end of a marking cycle.") \ \ develop(bool, G1PrintParCleanupStats, false, \ "When true, print extra stats about parallel cleanup.") \ diff -r c84ee870e0b9 -r 371bbc844bf1 src/share/vm/gc_implementation/g1/heapRegion.hpp --- a/src/share/vm/gc_implementation/g1/heapRegion.hpp Mon Apr 04 13:18:35 2011 -0400 +++ b/src/share/vm/gc_implementation/g1/heapRegion.hpp Mon Apr 04 14:23:17 2011 -0400 @@ -398,13 +398,16 @@ // The number of bytes marked live in the region in the last marking phase. size_t marked_bytes() { return _prev_marked_bytes; } + size_t live_bytes() { + return (top() - prev_top_at_mark_start()) * HeapWordSize + marked_bytes(); + } + // The number of bytes counted in the next marking. size_t next_marked_bytes() { return _next_marked_bytes; } // The number of bytes live wrt the next marking. size_t next_live_bytes() { - return (top() - next_top_at_mark_start()) - * HeapWordSize - + next_marked_bytes(); + return + (top() - next_top_at_mark_start()) * HeapWordSize + next_marked_bytes(); } // A lower bound on the amount of garbage bytes in the region.