Mon, 04 Apr 2011 14:23:17 -0400
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
1.1 --- a/src/share/vm/gc_implementation/g1/collectionSetChooser.cpp Mon Apr 04 13:18:35 2011 -0400 1.2 +++ b/src/share/vm/gc_implementation/g1/collectionSetChooser.cpp Mon Apr 04 14:23:17 2011 -0400 1.3 @@ -262,39 +262,18 @@ 1.4 for (int i = 0; i < _numMarkedRegions; i++) { 1.5 assert(_markedRegions.at(i) != NULL, "Should be true by sorting!"); 1.6 _markedRegions.at(i)->set_sort_index(i); 1.7 - if (G1PrintRegionLivenessInfo > 0) { 1.8 - if (i == 0) gclog_or_tty->print_cr("Sorted marked regions:"); 1.9 - if (i < G1PrintRegionLivenessInfo || 1.10 - (_numMarkedRegions-i) < G1PrintRegionLivenessInfo) { 1.11 - HeapRegion* hr = _markedRegions.at(i); 1.12 - size_t u = hr->used(); 1.13 - gclog_or_tty->print_cr(" Region %d: %d used, %d max live, %5.2f%%.", 1.14 - i, u, hr->max_live_bytes(), 1.15 - 100.0*(float)hr->max_live_bytes()/(float)u); 1.16 - } 1.17 + } 1.18 + if (G1PrintRegionLivenessInfo) { 1.19 + G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Sorting"); 1.20 + for (int i = 0; i < _numMarkedRegions; ++i) { 1.21 + HeapRegion* r = _markedRegions.at(i); 1.22 + cl.doHeapRegion(r); 1.23 } 1.24 } 1.25 - if (G1PolicyVerbose > 1) 1.26 - printSortedHeapRegions(); 1.27 assert(verify(), "should now be sorted"); 1.28 } 1.29 1.30 void 1.31 -printHeapRegion(HeapRegion *hr) { 1.32 - if (hr->isHumongous()) 1.33 - gclog_or_tty->print("H: "); 1.34 - if (hr->in_collection_set()) 1.35 - gclog_or_tty->print("CS: "); 1.36 - gclog_or_tty->print_cr("Region " PTR_FORMAT " (%s%s) " 1.37 - "[" PTR_FORMAT ", " PTR_FORMAT"] " 1.38 - "Used: " SIZE_FORMAT "K, garbage: " SIZE_FORMAT "K.", 1.39 - hr, hr->is_young() ? "Y " : " ", 1.40 - hr->is_marked()? "M1" : "M0", 1.41 - hr->bottom(), hr->end(), 1.42 - hr->used()/K, hr->garbage_bytes()/K); 1.43 -} 1.44 - 1.45 -void 1.46 CollectionSetChooser::addMarkedHeapRegion(HeapRegion* hr) { 1.47 assert(!hr->isHumongous(), 1.48 "Humongous regions shouldn't be added to the collection set"); 1.49 @@ -351,27 +330,9 @@ 1.50 1.51 void 1.52 CollectionSetChooser::updateAfterFullCollection() { 1.53 - G1CollectedHeap* g1h = G1CollectedHeap::heap(); 1.54 clearMarkedHeapRegions(); 1.55 } 1.56 1.57 -void 1.58 -CollectionSetChooser::printSortedHeapRegions() { 1.59 - gclog_or_tty->print_cr("Printing %d Heap Regions sorted by amount of known garbage", 1.60 - _numMarkedRegions); 1.61 - 1.62 - DEBUG_ONLY(int marked_count = 0;) 1.63 - for (int i = 0; i < _markedRegions.length(); i++) { 1.64 - HeapRegion* r = _markedRegions.at(i); 1.65 - if (r != NULL) { 1.66 - printHeapRegion(r); 1.67 - DEBUG_ONLY(marked_count++;) 1.68 - } 1.69 - } 1.70 - assert(marked_count == _numMarkedRegions, "must be"); 1.71 - gclog_or_tty->print_cr("Done sorted heap region print"); 1.72 -} 1.73 - 1.74 void CollectionSetChooser::removeRegion(HeapRegion *hr) { 1.75 int si = hr->sort_index(); 1.76 assert(si == -1 || hr->is_marked(), "Sort index not valid.");
2.1 --- a/src/share/vm/gc_implementation/g1/collectionSetChooser.hpp Mon Apr 04 13:18:35 2011 -0400 2.2 +++ b/src/share/vm/gc_implementation/g1/collectionSetChooser.hpp Mon Apr 04 14:23:17 2011 -0400 2.3 @@ -100,8 +100,6 @@ 2.4 2.5 CollectionSetChooser(); 2.6 2.7 - void printSortedHeapRegions(); 2.8 - 2.9 void sortMarkedHeapRegions(); 2.10 void fillCache(); 2.11 bool addRegionToCache(void);
3.1 --- a/src/share/vm/gc_implementation/g1/concurrentMark.cpp Mon Apr 04 13:18:35 2011 -0400 3.2 +++ b/src/share/vm/gc_implementation/g1/concurrentMark.cpp Mon Apr 04 14:23:17 2011 -0400 3.3 @@ -1204,7 +1204,6 @@ 3.4 g1p->record_concurrent_mark_remark_end(); 3.5 } 3.6 3.7 - 3.8 #define CARD_BM_TEST_MODE 0 3.9 3.10 class CalcLiveObjectsClosure: public HeapRegionClosure { 3.11 @@ -1726,6 +1725,11 @@ 3.12 } 3.13 _total_counting_time += this_final_counting_time; 3.14 3.15 + if (G1PrintRegionLivenessInfo) { 3.16 + G1PrintRegionLivenessInfoClosure cl(gclog_or_tty, "Post-Marking"); 3.17 + _g1h->heap_region_iterate(&cl); 3.18 + } 3.19 + 3.20 // Install newly created mark bitMap as "prev". 3.21 swapMarkBitMaps(); 3.22 3.23 @@ -4423,3 +4427,175 @@ 3.24 3.25 _marking_step_diffs_ms.add(0.5); 3.26 } 3.27 + 3.28 +// These are formatting macros that are used below to ensure 3.29 +// consistent formatting. The *_H_* versions are used to format the 3.30 +// header for a particular value and they should be kept consistent 3.31 +// with the corresponding macro. Also note that most of the macros add 3.32 +// the necessary white space (as a prefix) which makes them a bit 3.33 +// easier to compose. 3.34 + 3.35 +// All the output lines are prefixed with this string to be able to 3.36 +// identify them easily in a large log file. 3.37 +#define G1PPRL_LINE_PREFIX "###" 3.38 + 3.39 +#define G1PPRL_ADDR_BASE_FORMAT " "PTR_FORMAT"-"PTR_FORMAT 3.40 +#ifdef _LP64 3.41 +#define G1PPRL_ADDR_BASE_H_FORMAT " %37s" 3.42 +#else // _LP64 3.43 +#define G1PPRL_ADDR_BASE_H_FORMAT " %21s" 3.44 +#endif // _LP64 3.45 + 3.46 +// For per-region info 3.47 +#define G1PPRL_TYPE_FORMAT " %-4s" 3.48 +#define G1PPRL_TYPE_H_FORMAT " %4s" 3.49 +#define G1PPRL_BYTE_FORMAT " "SIZE_FORMAT_W(9) 3.50 +#define G1PPRL_BYTE_H_FORMAT " %9s" 3.51 +#define G1PPRL_DOUBLE_FORMAT " %14.1f" 3.52 +#define G1PPRL_DOUBLE_H_FORMAT " %14s" 3.53 + 3.54 +// For summary info 3.55 +#define G1PPRL_SUM_ADDR_FORMAT(tag) " "tag":"G1PPRL_ADDR_BASE_FORMAT 3.56 +#define G1PPRL_SUM_BYTE_FORMAT(tag) " "tag": "SIZE_FORMAT 3.57 +#define G1PPRL_SUM_MB_FORMAT(tag) " "tag": %1.2f MB" 3.58 +#define G1PPRL_SUM_MB_PERC_FORMAT(tag) G1PPRL_SUM_MB_FORMAT(tag)" / %1.2f %%" 3.59 + 3.60 +G1PrintRegionLivenessInfoClosure:: 3.61 +G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name) 3.62 + : _out(out), 3.63 + _total_used_bytes(0), _total_capacity_bytes(0), 3.64 + _total_prev_live_bytes(0), _total_next_live_bytes(0), 3.65 + _hum_used_bytes(0), _hum_capacity_bytes(0), 3.66 + _hum_prev_live_bytes(0), _hum_next_live_bytes(0) { 3.67 + G1CollectedHeap* g1h = G1CollectedHeap::heap(); 3.68 + MemRegion g1_committed = g1h->g1_committed(); 3.69 + MemRegion g1_reserved = g1h->g1_reserved(); 3.70 + double now = os::elapsedTime(); 3.71 + 3.72 + // Print the header of the output. 3.73 + _out->cr(); 3.74 + _out->print_cr(G1PPRL_LINE_PREFIX" PHASE %s @ %1.3f", phase_name, now); 3.75 + _out->print_cr(G1PPRL_LINE_PREFIX" HEAP" 3.76 + G1PPRL_SUM_ADDR_FORMAT("committed") 3.77 + G1PPRL_SUM_ADDR_FORMAT("reserved") 3.78 + G1PPRL_SUM_BYTE_FORMAT("region-size"), 3.79 + g1_committed.start(), g1_committed.end(), 3.80 + g1_reserved.start(), g1_reserved.end(), 3.81 + HeapRegion::GrainBytes); 3.82 + _out->print_cr(G1PPRL_LINE_PREFIX); 3.83 + _out->print_cr(G1PPRL_LINE_PREFIX 3.84 + G1PPRL_TYPE_H_FORMAT 3.85 + G1PPRL_ADDR_BASE_H_FORMAT 3.86 + G1PPRL_BYTE_H_FORMAT 3.87 + G1PPRL_BYTE_H_FORMAT 3.88 + G1PPRL_BYTE_H_FORMAT 3.89 + G1PPRL_DOUBLE_H_FORMAT, 3.90 + "type", "address-range", 3.91 + "used", "prev-live", "next-live", "gc-eff"); 3.92 +} 3.93 + 3.94 +// It takes as a parameter a reference to one of the _hum_* fields, it 3.95 +// deduces the corresponding value for a region in a humongous region 3.96 +// series (either the region size, or what's left if the _hum_* field 3.97 +// is < the region size), and updates the _hum_* field accordingly. 3.98 +size_t G1PrintRegionLivenessInfoClosure::get_hum_bytes(size_t* hum_bytes) { 3.99 + size_t bytes = 0; 3.100 + // The > 0 check is to deal with the prev and next live bytes which 3.101 + // could be 0. 3.102 + if (*hum_bytes > 0) { 3.103 + bytes = MIN2((size_t) HeapRegion::GrainBytes, *hum_bytes); 3.104 + *hum_bytes -= bytes; 3.105 + } 3.106 + return bytes; 3.107 +} 3.108 + 3.109 +// It deduces the values for a region in a humongous region series 3.110 +// from the _hum_* fields and updates those accordingly. It assumes 3.111 +// that that _hum_* fields have already been set up from the "starts 3.112 +// humongous" region and we visit the regions in address order. 3.113 +void G1PrintRegionLivenessInfoClosure::get_hum_bytes(size_t* used_bytes, 3.114 + size_t* capacity_bytes, 3.115 + size_t* prev_live_bytes, 3.116 + size_t* next_live_bytes) { 3.117 + assert(_hum_used_bytes > 0 && _hum_capacity_bytes > 0, "pre-condition"); 3.118 + *used_bytes = get_hum_bytes(&_hum_used_bytes); 3.119 + *capacity_bytes = get_hum_bytes(&_hum_capacity_bytes); 3.120 + *prev_live_bytes = get_hum_bytes(&_hum_prev_live_bytes); 3.121 + *next_live_bytes = get_hum_bytes(&_hum_next_live_bytes); 3.122 +} 3.123 + 3.124 +bool G1PrintRegionLivenessInfoClosure::doHeapRegion(HeapRegion* r) { 3.125 + const char* type = ""; 3.126 + HeapWord* bottom = r->bottom(); 3.127 + HeapWord* end = r->end(); 3.128 + size_t capacity_bytes = r->capacity(); 3.129 + size_t used_bytes = r->used(); 3.130 + size_t prev_live_bytes = r->live_bytes(); 3.131 + size_t next_live_bytes = r->next_live_bytes(); 3.132 + double gc_eff = r->gc_efficiency(); 3.133 + if (r->used() == 0) { 3.134 + type = "FREE"; 3.135 + } else if (r->is_survivor()) { 3.136 + type = "SURV"; 3.137 + } else if (r->is_young()) { 3.138 + type = "EDEN"; 3.139 + } else if (r->startsHumongous()) { 3.140 + type = "HUMS"; 3.141 + 3.142 + assert(_hum_used_bytes == 0 && _hum_capacity_bytes == 0 && 3.143 + _hum_prev_live_bytes == 0 && _hum_next_live_bytes == 0, 3.144 + "they should have been zeroed after the last time we used them"); 3.145 + // Set up the _hum_* fields. 3.146 + _hum_capacity_bytes = capacity_bytes; 3.147 + _hum_used_bytes = used_bytes; 3.148 + _hum_prev_live_bytes = prev_live_bytes; 3.149 + _hum_next_live_bytes = next_live_bytes; 3.150 + get_hum_bytes(&used_bytes, &capacity_bytes, 3.151 + &prev_live_bytes, &next_live_bytes); 3.152 + end = bottom + HeapRegion::GrainWords; 3.153 + } else if (r->continuesHumongous()) { 3.154 + type = "HUMC"; 3.155 + get_hum_bytes(&used_bytes, &capacity_bytes, 3.156 + &prev_live_bytes, &next_live_bytes); 3.157 + assert(end == bottom + HeapRegion::GrainWords, "invariant"); 3.158 + } else { 3.159 + type = "OLD"; 3.160 + } 3.161 + 3.162 + _total_used_bytes += used_bytes; 3.163 + _total_capacity_bytes += capacity_bytes; 3.164 + _total_prev_live_bytes += prev_live_bytes; 3.165 + _total_next_live_bytes += next_live_bytes; 3.166 + 3.167 + // Print a line for this particular region. 3.168 + _out->print_cr(G1PPRL_LINE_PREFIX 3.169 + G1PPRL_TYPE_FORMAT 3.170 + G1PPRL_ADDR_BASE_FORMAT 3.171 + G1PPRL_BYTE_FORMAT 3.172 + G1PPRL_BYTE_FORMAT 3.173 + G1PPRL_BYTE_FORMAT 3.174 + G1PPRL_DOUBLE_FORMAT, 3.175 + type, bottom, end, 3.176 + used_bytes, prev_live_bytes, next_live_bytes, gc_eff); 3.177 + 3.178 + return false; 3.179 +} 3.180 + 3.181 +G1PrintRegionLivenessInfoClosure::~G1PrintRegionLivenessInfoClosure() { 3.182 + // Print the footer of the output. 3.183 + _out->print_cr(G1PPRL_LINE_PREFIX); 3.184 + _out->print_cr(G1PPRL_LINE_PREFIX 3.185 + " SUMMARY" 3.186 + G1PPRL_SUM_MB_FORMAT("capacity") 3.187 + G1PPRL_SUM_MB_PERC_FORMAT("used") 3.188 + G1PPRL_SUM_MB_PERC_FORMAT("prev-live") 3.189 + G1PPRL_SUM_MB_PERC_FORMAT("next-live"), 3.190 + bytes_to_mb(_total_capacity_bytes), 3.191 + bytes_to_mb(_total_used_bytes), 3.192 + perc(_total_used_bytes, _total_capacity_bytes), 3.193 + bytes_to_mb(_total_prev_live_bytes), 3.194 + perc(_total_prev_live_bytes, _total_capacity_bytes), 3.195 + bytes_to_mb(_total_next_live_bytes), 3.196 + perc(_total_next_live_bytes, _total_capacity_bytes)); 3.197 + _out->cr(); 3.198 +}
4.1 --- a/src/share/vm/gc_implementation/g1/concurrentMark.hpp Mon Apr 04 13:18:35 2011 -0400 4.2 +++ b/src/share/vm/gc_implementation/g1/concurrentMark.hpp Mon Apr 04 14:23:17 2011 -0400 4.3 @@ -1149,4 +1149,54 @@ 4.4 #endif // _MARKING_STATS_ 4.5 }; 4.6 4.7 +// Class that's used to to print out per-region liveness 4.8 +// information. It's currently used at the end of marking and also 4.9 +// after we sort the old regions at the end of the cleanup operation. 4.10 +class G1PrintRegionLivenessInfoClosure: public HeapRegionClosure { 4.11 +private: 4.12 + outputStream* _out; 4.13 + 4.14 + // Accumulators for these values. 4.15 + size_t _total_used_bytes; 4.16 + size_t _total_capacity_bytes; 4.17 + size_t _total_prev_live_bytes; 4.18 + size_t _total_next_live_bytes; 4.19 + 4.20 + // These are set up when we come across a "stars humongous" region 4.21 + // (as this is where most of this information is stored, not in the 4.22 + // subsequent "continues humongous" regions). After that, for every 4.23 + // region in a given humongous region series we deduce the right 4.24 + // values for it by simply subtracting the appropriate amount from 4.25 + // these fields. All these values should reach 0 after we've visited 4.26 + // the last region in the series. 4.27 + size_t _hum_used_bytes; 4.28 + size_t _hum_capacity_bytes; 4.29 + size_t _hum_prev_live_bytes; 4.30 + size_t _hum_next_live_bytes; 4.31 + 4.32 + static double perc(size_t val, size_t total) { 4.33 + if (total == 0) { 4.34 + return 0.0; 4.35 + } else { 4.36 + return 100.0 * ((double) val / (double) total); 4.37 + } 4.38 + } 4.39 + 4.40 + static double bytes_to_mb(size_t val) { 4.41 + return (double) val / (double) M; 4.42 + } 4.43 + 4.44 + // See the .cpp file. 4.45 + size_t get_hum_bytes(size_t* hum_bytes); 4.46 + void get_hum_bytes(size_t* used_bytes, size_t* capacity_bytes, 4.47 + size_t* prev_live_bytes, size_t* next_live_bytes); 4.48 + 4.49 +public: 4.50 + // The header and footer are printed in the constructor and 4.51 + // destructor respectively. 4.52 + G1PrintRegionLivenessInfoClosure(outputStream* out, const char* phase_name); 4.53 + virtual bool doHeapRegion(HeapRegion* r); 4.54 + ~G1PrintRegionLivenessInfoClosure(); 4.55 +}; 4.56 + 4.57 #endif // SHARE_VM_GC_IMPLEMENTATION_G1_CONCURRENTMARK_HPP
5.1 --- a/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp Mon Apr 04 13:18:35 2011 -0400 5.2 +++ b/src/share/vm/gc_implementation/g1/g1CollectedHeap.hpp Mon Apr 04 14:23:17 2011 -0400 5.3 @@ -1057,7 +1057,13 @@ 5.4 return _g1_reserved.contains(p); 5.5 } 5.6 5.7 - // Returns a MemRegion that corresponds to the space that has been 5.8 + // Returns a MemRegion that corresponds to the space that has been 5.9 + // reserved for the heap 5.10 + MemRegion g1_reserved() { 5.11 + return _g1_reserved; 5.12 + } 5.13 + 5.14 + // Returns a MemRegion that corresponds to the space that has been 5.15 // committed in the heap 5.16 MemRegion g1_committed() { 5.17 return _g1_committed;
6.1 --- a/src/share/vm/gc_implementation/g1/g1_globals.hpp Mon Apr 04 13:18:35 2011 -0400 6.2 +++ b/src/share/vm/gc_implementation/g1/g1_globals.hpp Mon Apr 04 14:23:17 2011 -0400 6.3 @@ -138,9 +138,9 @@ 6.4 develop(bool, G1RSCountHisto, false, \ 6.5 "If true, print a histogram of RS occupancies after each pause") \ 6.6 \ 6.7 - develop(intx, G1PrintRegionLivenessInfo, 0, \ 6.8 - "When > 0, print the occupancies of the <n> best and worst" \ 6.9 - "regions.") \ 6.10 + product(bool, G1PrintRegionLivenessInfo, false, \ 6.11 + "Prints the liveness information for all regions in the heap " \ 6.12 + "at the end of a marking cycle.") \ 6.13 \ 6.14 develop(bool, G1PrintParCleanupStats, false, \ 6.15 "When true, print extra stats about parallel cleanup.") \
7.1 --- a/src/share/vm/gc_implementation/g1/heapRegion.hpp Mon Apr 04 13:18:35 2011 -0400 7.2 +++ b/src/share/vm/gc_implementation/g1/heapRegion.hpp Mon Apr 04 14:23:17 2011 -0400 7.3 @@ -398,13 +398,16 @@ 7.4 7.5 // The number of bytes marked live in the region in the last marking phase. 7.6 size_t marked_bytes() { return _prev_marked_bytes; } 7.7 + size_t live_bytes() { 7.8 + return (top() - prev_top_at_mark_start()) * HeapWordSize + marked_bytes(); 7.9 + } 7.10 + 7.11 // The number of bytes counted in the next marking. 7.12 size_t next_marked_bytes() { return _next_marked_bytes; } 7.13 // The number of bytes live wrt the next marking. 7.14 size_t next_live_bytes() { 7.15 - return (top() - next_top_at_mark_start()) 7.16 - * HeapWordSize 7.17 - + next_marked_bytes(); 7.18 + return 7.19 + (top() - next_top_at_mark_start()) * HeapWordSize + next_marked_bytes(); 7.20 } 7.21 7.22 // A lower bound on the amount of garbage bytes in the region.