8177764: Humongous Reclaimed log output may be confusing
Summary: Make all log messages dealing with humongous reclaim report number of handled objects, not regions.
Reviewed-by: pliden, sjohanss
--- a/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Fri May 12 11:38:20 2017 +0200
+++ b/hotspot/src/share/vm/gc/g1/g1CollectedHeap.cpp Fri May 12 11:41:05 2017 +0200
@@ -4928,12 +4928,13 @@
private:
FreeRegionList* _free_region_list;
HeapRegionSet* _proxy_set;
- uint _humongous_regions_removed;
+ uint _humongous_objects_reclaimed;
+ uint _humongous_regions_reclaimed;
size_t _freed_bytes;
public:
G1FreeHumongousRegionClosure(FreeRegionList* free_region_list) :
- _free_region_list(free_region_list), _humongous_regions_removed(0), _freed_bytes(0) {
+ _free_region_list(free_region_list), _humongous_objects_reclaimed(0), _humongous_regions_reclaimed(0), _freed_bytes(0) {
}
virtual bool doHeapRegion(HeapRegion* r) {
@@ -5009,11 +5010,12 @@
if (next_bitmap->isMarked(r->bottom())) {
next_bitmap->clear(r->bottom());
}
+ _humongous_objects_reclaimed++;
do {
HeapRegion* next = g1h->next_region_in_humongous(r);
_freed_bytes += r->used();
r->set_containing_set(NULL);
- _humongous_regions_removed++;
+ _humongous_regions_reclaimed++;
g1h->free_humongous_region(r, _free_region_list, false /* skip_remset */ );
r = next;
} while (r != NULL);
@@ -5021,8 +5023,12 @@
return false;
}
- uint humongous_free_count() {
- return _humongous_regions_removed;
+ uint humongous_objects_reclaimed() {
+ return _humongous_objects_reclaimed;
+ }
+
+ uint humongous_regions_reclaimed() {
+ return _humongous_regions_reclaimed;
}
size_t bytes_freed() const {
@@ -5046,7 +5052,7 @@
G1FreeHumongousRegionClosure cl(&local_cleanup_list);
heap_region_iterate(&cl);
- remove_from_old_sets(0, cl.humongous_free_count());
+ remove_from_old_sets(0, cl.humongous_regions_reclaimed());
G1HRPrinter* hrp = hr_printer();
if (hrp->is_active()) {
@@ -5061,7 +5067,7 @@
decrement_summary_bytes(cl.bytes_freed());
g1_policy()->phase_times()->record_fast_reclaim_humongous_time_ms((os::elapsedTime() - start_time) * 1000.0,
- cl.humongous_free_count());
+ cl.humongous_objects_reclaimed());
}
class G1AbandonCollectionSetClosure : public HeapRegionClosure {
--- /dev/null Thu Jan 01 00:00:00 1970 +0000
+++ b/hotspot/test/gc/g1/TestEagerReclaimHumongousRegionsLog.java Fri May 12 11:41:05 2017 +0200
@@ -0,0 +1,131 @@
+/*
+ * Copyright (c) 2017, 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.
+ */
+
+/*
+ * @test TestEagerReclaimHumongousRegionsLog
+ * @summary Check that G1 reports humongous eager reclaim statistics correctly.
+ * @requires vm.gc.G1
+ * @key gc
+ * @library /test/lib
+ * @modules java.base/jdk.internal.misc
+ * java.management
+ * @build sun.hotspot.WhiteBox
+ * @run main ClassFileInstaller sun.hotspot.WhiteBox
+ * @run driver TestEagerReclaimHumongousRegionsLog
+ */
+
+import sun.hotspot.WhiteBox;
+
+import java.util.Arrays;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
+
+import jdk.test.lib.Asserts;
+
+import jdk.test.lib.Platform;
+import jdk.test.lib.process.OutputAnalyzer;
+import jdk.test.lib.process.ProcessTools;
+
+public class TestEagerReclaimHumongousRegionsLog {
+
+ private static final String LogSeparator = ": ";
+
+ public static void runTest() throws Exception {
+ final String[] arguments = {
+ "-Xbootclasspath/a:.",
+ "-XX:+UnlockExperimentalVMOptions",
+ "-XX:+UnlockDiagnosticVMOptions",
+ "-XX:+WhiteBoxAPI",
+ "-XX:+UseG1GC",
+ "-XX:G1HeapRegionSize=1M",
+ "-Xms128M",
+ "-Xmx128M",
+ "-Xlog:gc+phases=trace,gc+heap=info",
+ GCTest.class.getName()
+ };
+
+ ProcessBuilder pb = ProcessTools.createJavaProcessBuilder(arguments);
+ OutputAnalyzer output = new OutputAnalyzer(pb.start());
+
+ output.shouldHaveExitValue(0);
+
+ System.out.println(output.getStdout());
+
+ // This gives an array of lines containing eager reclaim of humongous regions
+ // log messages contents after the ":" in the following order for every GC:
+ // Humongous Register: a.ams
+ // Humongous Total: b
+ // Humongous Candidate: c
+ // Humongous Reclaim: d.dms
+ // Humongous Reclaimed: e
+ // Humongous Regions: f->g
+
+ String[] lines = Arrays.stream(output.getStdout().split("\\R"))
+ .filter(s -> s.contains("Humongous")).map(s -> s.substring(s.indexOf(LogSeparator) + LogSeparator.length()))
+ .toArray(String[]::new);
+
+ Asserts.assertTrue(lines.length % 6 == 0, "There seems to be an unexpected amount of log messages (total: " + lines.length + ") per GC");
+
+ for (int i = 0; i < lines.length; i += 6) {
+ int total = Integer.parseInt(lines[i + 1]);
+ int candidate = Integer.parseInt(lines[i + 2]);
+ int reclaimed = Integer.parseInt(lines[i + 4]);
+
+ int before = Integer.parseInt(lines[i + 5].substring(0, 1));
+ int after = Integer.parseInt(lines[i + 5].substring(3, 4));
+ System.out.println("total " + total + " candidate " + candidate + " reclaimed " + reclaimed + " before " + before + " after " + after);
+
+ Asserts.assertEQ(total, candidate, "Not all humonguous objects are candidates");
+ Asserts.assertLTE(reclaimed, candidate, "The number of reclaimed objects must be less or equal than the number of candidates");
+
+ if (reclaimed > 0) {
+ Asserts.assertLT(after, before, "Number of regions after must be smaller than before.");
+ Asserts.assertEQ(reclaimed, candidate, "Must have reclaimed all candidates.");
+ Asserts.assertGT((before - after), reclaimed, "Number of regions reclaimed (" + (before - after) +
+ ") must be larger than number of objects reclaimed (" + reclaimed + ")");
+ }
+ }
+ }
+
+ public static void main(String[] args) throws Exception {
+ runTest();
+ }
+
+ static class GCTest {
+ private static final WhiteBox WB = WhiteBox.getWhiteBox();
+
+ public static Object holder;
+
+ public static void main(String [] args) {
+ // Create a humongous objects spanning multiple regions so that the difference
+ // between number of humongous objects reclaimed and number of regions reclaimed
+ // is apparent.
+ holder = new byte[4 * 1024 * 1024];
+ WB.youngGC();
+ System.out.println(holder);
+ holder = null;
+ WB.youngGC();
+ }
+ }
+}
+