--- old/src/share/vm/gc/g1/g1CollectedHeap.cpp 2016-02-01 15:21:01.911638113 +0100 +++ new/src/share/vm/gc/g1/g1CollectedHeap.cpp 2016-02-01 15:21:01.779638107 +0100 @@ -38,6 +38,7 @@ #include "gc/g1/g1CollectorState.hpp" #include "gc/g1/g1EvacStats.inline.hpp" #include "gc/g1/g1GCPhaseTimes.hpp" +#include "gc/g1/g1HeapTransition.hpp" #include "gc/g1/g1HeapVerifier.hpp" #include "gc/g1/g1MarkSweep.hpp" #include "gc/g1/g1OopClosures.inline.hpp" @@ -1250,6 +1251,7 @@ TraceCollectorStats tcs(g1mm()->full_collection_counters()); TraceMemoryManagerStats tms(true /* fullGC */, gc_cause()); + G1HeapTransition heap_transition(this); g1_policy()->record_full_collection_start(); // Note: When we have a more flexible GC logging framework that @@ -1442,14 +1444,14 @@ g1mm()->update_sizes(); gc_epilogue(true); - } - g1_policy()->print_detailed_heap_transition(); + heap_transition.print(); - print_heap_after_gc(); - trace_heap_after_gc(gc_tracer); + print_heap_after_gc(); + trace_heap_after_gc(gc_tracer); - post_full_gc_dump(gc_timer); + post_full_gc_dump(gc_timer); + } gc_timer->register_gc_end(); gc_tracer->report_gc_end(gc_timer->gc_end(), gc_timer->time_partitions()); @@ -3169,17 +3171,6 @@ } #endif // TASKQUEUE_STATS -void G1CollectedHeap::log_gc_footer() { - if (evacuation_failed()) { - log_info(gc)("To-space exhausted"); - } - - g1_policy()->print_phases(); - - g1_policy()->print_detailed_heap_transition(); -} - - void G1CollectedHeap::wait_for_root_region_scanning() { double scan_wait_start = os::elapsedTime(); // We have to wait until the CM threads finish scanning the @@ -3281,6 +3272,9 @@ append_secondary_free_list_if_not_empty_with_lock(); } + G1HeapTransition heap_transition(this); + size_t heap_used_bytes_before_gc = used(); + assert(check_young_list_well_formed(), "young list should be well formed"); // Don't dynamically change the number of GC threads this early. A value of @@ -3474,7 +3468,7 @@ 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 = per_thread_states.total_cards_scanned(); - g1_policy()->record_collection_pause_end(pause_time_ms, total_cards_scanned); + g1_policy()->record_collection_pause_end(pause_time_ms, total_cards_scanned, heap_used_bytes_before_gc); evacuation_info.set_collectionset_used_before(g1_policy()->collection_set_bytes_used_before()); evacuation_info.set_bytes_copied(g1_policy()->bytes_copied_during_gc()); @@ -3527,7 +3521,12 @@ } // Print the remainder of the GC log output. - log_gc_footer(); + if (evacuation_failed()) { + log_info(gc)("To-space exhausted"); + } + + g1_policy()->print_phases(); + heap_transition.print(); // It is not yet to safe to tell the concurrent mark to // start as we have some optional output below. We don't want the --- old/src/share/vm/gc/g1/g1CollectedHeap.hpp 2016-02-01 15:21:02.195638125 +0100 +++ new/src/share/vm/gc/g1/g1CollectedHeap.hpp 2016-02-01 15:21:02.063638119 +0100 @@ -291,8 +291,6 @@ size_t size, size_t translation_factor); - void log_gc_footer(); - void trace_heap(GCWhen::Type when, const GCTracer* tracer); void process_weak_jni_handles(); --- old/src/share/vm/gc/g1/g1CollectorPolicy.cpp 2016-02-01 15:21:02.435638135 +0100 +++ new/src/share/vm/gc/g1/g1CollectorPolicy.cpp 2016-02-01 15:21:02.307638129 +0100 @@ -117,15 +117,6 @@ _rs_lengths_prediction(0), _max_survivor_regions(0), - _eden_used_bytes_before_gc(0), - _survivor_used_bytes_before_gc(0), - _old_used_bytes_before_gc(0), - _humongous_used_bytes_before_gc(0), - _heap_used_bytes_before_gc(0), - _metaspace_used_bytes_before_gc(0), - _eden_capacity_bytes_before_gc(0), - _heap_capacity_bytes_before_gc(0), - _eden_cset_region_length(0), _survivor_cset_region_length(0), _old_cset_region_length(0), @@ -809,7 +800,6 @@ void G1CollectorPolicy::record_full_collection_start() { _full_collection_start_sec = os::elapsedTime(); - record_heap_size_info_at_start(true /* full */); // Release the future to-space so that it is available for compaction into. collector_state()->set_full_collection(true); } @@ -871,8 +861,6 @@ _trace_young_gen_time_data.record_start_collection(s_w_t_ms); _stop_world_start = 0.0; - record_heap_size_info_at_start(false /* full */); - phase_times()->record_cur_collection_start_sec(start_time_sec); _pending_cards = _g1->pending_card_num(); @@ -987,7 +975,7 @@ // Anything below that is considered to be zero #define MIN_TIMER_GRANULARITY 0.0000001 -void G1CollectorPolicy::record_collection_pause_end(double pause_time_ms, size_t cards_scanned) { +void G1CollectorPolicy::record_collection_pause_end(double pause_time_ms, size_t cards_scanned, size_t heap_used_bytes_before_gc) { double end_time_sec = os::elapsedTime(); size_t cur_used_bytes = _g1->used(); @@ -1138,7 +1126,7 @@ } _rs_length_diff_seq->add((double) rs_length_diff); - size_t freed_bytes = _heap_used_bytes_before_gc - cur_used_bytes; + size_t freed_bytes = heap_used_bytes_before_gc - cur_used_bytes; size_t copied_bytes = _collection_set_bytes_used_before - freed_bytes; double cost_per_byte_ms = 0.0; @@ -1260,49 +1248,6 @@ _ihop_control->print(); } -#define EXT_SIZE_FORMAT "%.1f%s" -#define EXT_SIZE_PARAMS(bytes) \ - byte_size_in_proper_unit((double)(bytes)), \ - proper_unit_for_byte_size((bytes)) - -void G1CollectorPolicy::record_heap_size_info_at_start(bool full) { - YoungList* young_list = _g1->young_list(); - _eden_used_bytes_before_gc = young_list->eden_used_bytes(); - _survivor_used_bytes_before_gc = young_list->survivor_used_bytes(); - _heap_capacity_bytes_before_gc = _g1->capacity(); - _old_used_bytes_before_gc = _g1->old_regions_count() * HeapRegion::GrainBytes; - _humongous_used_bytes_before_gc = _g1->humongous_regions_count() * HeapRegion::GrainBytes; - _heap_used_bytes_before_gc = _g1->used(); - _eden_capacity_bytes_before_gc = (_young_list_target_length * HeapRegion::GrainBytes) - _survivor_used_bytes_before_gc; - _metaspace_used_bytes_before_gc = MetaspaceAux::used_bytes(); -} - -void G1CollectorPolicy::print_detailed_heap_transition() const { - YoungList* young_list = _g1->young_list(); - - size_t eden_used_bytes_after_gc = young_list->eden_used_bytes(); - size_t survivor_used_bytes_after_gc = young_list->survivor_used_bytes(); - size_t heap_used_bytes_after_gc = _g1->used(); - size_t old_used_bytes_after_gc = _g1->old_regions_count() * HeapRegion::GrainBytes; - size_t humongous_used_bytes_after_gc = _g1->humongous_regions_count() * HeapRegion::GrainBytes; - - size_t heap_capacity_bytes_after_gc = _g1->capacity(); - size_t eden_capacity_bytes_after_gc = - (_young_list_target_length * HeapRegion::GrainBytes) - survivor_used_bytes_after_gc; - size_t survivor_capacity_bytes_after_gc = _max_survivor_regions * HeapRegion::GrainBytes; - - log_info(gc, heap)("Eden: " SIZE_FORMAT "K->" SIZE_FORMAT "K(" SIZE_FORMAT "K)", - _eden_used_bytes_before_gc / K, eden_used_bytes_after_gc /K, eden_capacity_bytes_after_gc /K); - log_info(gc, heap)("Survivor: " SIZE_FORMAT "K->" SIZE_FORMAT "K(" SIZE_FORMAT "K)", - _survivor_used_bytes_before_gc / K, survivor_used_bytes_after_gc /K, survivor_capacity_bytes_after_gc /K); - log_info(gc, heap)("Old: " SIZE_FORMAT "K->" SIZE_FORMAT "K", - _old_used_bytes_before_gc / K, old_used_bytes_after_gc /K); - log_info(gc, heap)("Humongous: " SIZE_FORMAT "K->" SIZE_FORMAT "K", - _humongous_used_bytes_before_gc / K, humongous_used_bytes_after_gc /K); - - MetaspaceAux::print_metaspace_change(_metaspace_used_bytes_before_gc); -} - void G1CollectorPolicy::print_phases() { phase_times()->print(); } --- old/src/share/vm/gc/g1/g1CollectorPolicy.hpp 2016-02-01 15:21:02.699638146 +0100 +++ new/src/share/vm/gc/g1/g1CollectorPolicy.hpp 2016-02-01 15:21:02.571638140 +0100 @@ -636,7 +636,7 @@ // Record the start and end of an evacuation pause. void record_collection_pause_start(double start_time_sec); - void record_collection_pause_end(double pause_time_ms, size_t cards_scanned); + void record_collection_pause_end(double pause_time_ms, size_t cards_scanned, size_t heap_used_bytes_before_gc); // Record the start and end of a full collection. void record_full_collection_start(); @@ -654,14 +654,6 @@ void record_concurrent_mark_cleanup_end(); void record_concurrent_mark_cleanup_completed(); - // Records the information about the heap size for reporting in - // print_detailed_heap_transition - void record_heap_size_info_at_start(bool full); - - // Print heap sizing transition (with less and more detail). - - void print_detailed_heap_transition() const; - virtual void print_phases(); void record_stop_world_start(); @@ -825,16 +817,6 @@ // The value of _heap_bytes_before_gc is also used to calculate // the cost of copying. - size_t _eden_used_bytes_before_gc; // Eden occupancy before GC - size_t _survivor_used_bytes_before_gc; // Survivor occupancy before GC - size_t _old_used_bytes_before_gc; // Old occupancy before GC - size_t _humongous_used_bytes_before_gc; // Humongous occupancy before GC - size_t _heap_used_bytes_before_gc; // Heap occupancy before GC - size_t _metaspace_used_bytes_before_gc; // Metaspace occupancy before GC - - size_t _eden_capacity_bytes_before_gc; // Eden capacity before GC - size_t _heap_capacity_bytes_before_gc; // Heap capacity before GC - // The amount of survivor regions after a collection. uint _recorded_survivor_regions; // List of survivor regions. @@ -846,6 +828,10 @@ public: uint tenuring_threshold() const { return _tenuring_threshold; } + uint max_survivor_regions() { + return _max_survivor_regions; + } + static const uint REGIONS_UNLIMITED = (uint) -1; uint max_regions(InCSetState dest) const { --- /dev/null 2016-01-18 13:22:01.357170507 +0100 +++ new/src/share/vm/gc/g1/g1HeapTransition.cpp 2016-02-01 15:21:02.815638151 +0100 @@ -0,0 +1,122 @@ +/* + * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#include "precompiled.hpp" +#include "gc/g1/g1CollectedHeap.hpp" +#include "gc/g1/g1CollectorPolicy.hpp" +#include "gc/g1/g1HeapTransition.hpp" +#include "logging/log.hpp" +#include "memory/metaspace.hpp" + +G1HeapTransition::Data::Data(G1CollectedHeap* g1_heap) { + YoungList* young_list = g1_heap->young_list(); + _eden_length = young_list->eden_length(); + _survivor_length = young_list->survivor_length(); + _old_length = g1_heap->old_regions_count(); + _humongous_length = g1_heap->humongous_regions_count(); + _metaspace_used_bytes = MetaspaceAux::used_bytes(); +} + +G1HeapTransition::G1HeapTransition(G1CollectedHeap* g1_heap) : _g1_heap(g1_heap), _before(g1_heap) { } + +struct SeparatedUsageInfo : public StackObj { + size_t _eden_used; + size_t _survivor_used; + size_t _old_used; + size_t _humongous_used; + + size_t _eden_region_count; + size_t _survivor_region_count; + size_t _old_region_count; + size_t _humongous_region_count; + + SeparatedUsageInfo() : + _eden_used(0), _survivor_used(0), _old_used(0), _humongous_used(0), + _eden_region_count(0), _survivor_region_count(0), _old_region_count(0), _humongous_region_count(0) {} +}; + +class SumSeparatedUsedClosure: public HeapRegionClosure { +public: + SeparatedUsageInfo _info; + bool doHeapRegion(HeapRegion* r) { + if (r->is_old()) { + _info._old_used += r->used(); + _info._old_region_count++; + } else if (r->is_survivor()) { + _info._survivor_used += r->used(); + _info._survivor_region_count++; + } else if (r->is_eden()) { + _info._eden_used += r->used(); + _info._eden_region_count++; + } else if (r->is_humongous()) { + _info._humongous_used += r->used(); + _info._humongous_region_count++; + } else { + assert(r->used() == 0, "Expected used to be 0 but it was " SIZE_FORMAT, r->used()); + } + return false; + } +}; + +void G1HeapTransition::print() { + Data after(_g1_heap); + + size_t eden_capacity_bytes_after_gc = _g1_heap->g1_policy()->young_list_target_length() - after._survivor_length; + size_t survivor_capacity_bytes_after_gc = _g1_heap->g1_policy()->max_survivor_regions(); + + SeparatedUsageInfo usage_info; + if (log_is_enabled(Trace, gc, heap)) { + SumSeparatedUsedClosure blk; + _g1_heap->heap_region_iterate(&blk); + usage_info = blk._info; + assert(usage_info._eden_region_count == 0, "Expected no eden regions, but got " SIZE_FORMAT, usage_info._eden_region_count); + assert(usage_info._survivor_region_count == after._survivor_length, "Expected survivors to be " SIZE_FORMAT " but was " SIZE_FORMAT, + after._survivor_length, usage_info._survivor_region_count); + assert(usage_info._old_region_count == after._old_length, "Expected old to be " SIZE_FORMAT " but was " SIZE_FORMAT, + after._old_length, usage_info._old_region_count); + assert(usage_info._humongous_region_count == after._humongous_length, "Expected humongous to be " SIZE_FORMAT " but was " SIZE_FORMAT, + after._humongous_length, usage_info._humongous_region_count); + } + + log_info(gc, heap)("Eden regions: " SIZE_FORMAT "->" SIZE_FORMAT "(" SIZE_FORMAT ")", + _before._eden_length, after._eden_length, eden_capacity_bytes_after_gc); + log_trace(gc, heap)(" Used: 0K, Waste: 0K"); + + log_info(gc, heap)("Survivor regions: " SIZE_FORMAT "->" SIZE_FORMAT "(" SIZE_FORMAT ")", + _before._survivor_length, after._survivor_length, survivor_capacity_bytes_after_gc); + log_trace(gc, heap)(" Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K", + usage_info._survivor_used / K, ((after._survivor_length * HeapRegion::GrainBytes) - usage_info._survivor_used) / K); + + log_info(gc, heap)("Old regions: " SIZE_FORMAT "->" SIZE_FORMAT, + _before._old_length, after._old_length); + log_trace(gc, heap)(" Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K", + usage_info._old_used / K, ((after._old_length * HeapRegion::GrainBytes) - usage_info._old_used) / K); + + log_info(gc, heap)("Humongous regions: " SIZE_FORMAT "->" SIZE_FORMAT, + _before._humongous_length, after._humongous_length); + log_trace(gc, heap)(" Used: " SIZE_FORMAT "K, Waste: " SIZE_FORMAT "K", + usage_info._humongous_used / K, ((after._humongous_length * HeapRegion::GrainBytes) - usage_info._humongous_used) / K); + + MetaspaceAux::print_metaspace_change(_before._metaspace_used_bytes); +} --- /dev/null 2016-01-18 13:22:01.357170507 +0100 +++ new/src/share/vm/gc/g1/g1HeapTransition.hpp 2016-02-01 15:21:02.991638158 +0100 @@ -0,0 +1,52 @@ +/* + * Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + * + */ + +#ifndef SHARE_VM_GC_G1_G1HEAPTRANSITION_HPP +#define SHARE_VM_GC_G1_G1HEAPTRANSITION_HPP + +#include "gc/shared/plab.hpp" + +class G1CollectedHeap; + +class G1HeapTransition { + struct Data { + size_t _eden_length; + size_t _survivor_length; + size_t _old_length; + size_t _humongous_length; + size_t _metaspace_used_bytes; + + Data(G1CollectedHeap* g1_heap); + }; + + G1CollectedHeap* _g1_heap; + Data _before; + +public: + G1HeapTransition(G1CollectedHeap* g1_heap); + + void print(); +}; + +#endif // SHARE_VM_GC_G1_G1HEAPTRANSITION_HPP