8212657: Implementation of JDK-8204089 Promptly Return Unused Committed Memory from G1
authortschatzl
Mon, 10 Dec 2018 10:25:27 +0100
changeset 52918 f94c7929a44b
parent 52917 0c637249d934
child 52919 ef9a34d58474
8212657: Implementation of JDK-8204089 Promptly Return Unused Committed Memory from G1 Summary: Issue optional, default enabled, concurrent cycles when the VM is idle to reclaim unused internal and Java heap memory. Reviewed-by: sjohanss, sangheki Contributed-by: Rodrigo Bruno <rbruno@gsd.inesc-id.pt>, Ruslan Synytsky <rs@jelastic.com>, Thomas Schatzl <thomas.schatzl@oracle.com>
src/hotspot/share/gc/g1/g1CollectedHeap.cpp
src/hotspot/share/gc/g1/g1Policy.cpp
src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.cpp
src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.hpp
src/hotspot/share/gc/g1/g1_globals.hpp
src/hotspot/share/gc/shared/gcCause.cpp
src/hotspot/share/gc/shared/gcCause.hpp
src/hotspot/share/gc/shared/gcVMOperations.cpp
src/hotspot/share/logging/logTag.hpp
test/hotspot/jtreg/TEST.groups
test/hotspot/jtreg/gc/g1/TestPeriodicCollection.java
--- a/src/hotspot/share/gc/g1/g1CollectedHeap.cpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/g1/g1CollectedHeap.cpp	Mon Dec 10 10:25:27 2018 +0100
@@ -1150,6 +1150,8 @@
 }
 
 void G1CollectedHeap::resize_heap_if_necessary() {
+  assert_at_safepoint_on_vm_thread();
+
   // Capacity, free and used after the GC counted as full regions to
   // include the waste in the following calculations.
   const size_t capacity_after_gc = capacity();
@@ -1991,6 +1993,7 @@
   switch (cause) {
     case GCCause::_gc_locker:               return GCLockerInvokesConcurrent;
     case GCCause::_g1_humongous_allocation: return true;
+    case GCCause::_g1_periodic_collection:  return G1PeriodicGCInvokesConcurrent;
     default:                                return is_user_requested_concurrent_full_gc(cause);
   }
 }
--- a/src/hotspot/share/gc/g1/g1Policy.cpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/g1/g1Policy.cpp	Mon Dec 10 10:25:27 2018 +0100
@@ -714,20 +714,34 @@
   }
 
   _free_regions_at_end_of_collection = _g1h->num_free_regions();
-  // IHOP control wants to know the expected young gen length if it were not
-  // restrained by the heap reserve. Using the actual length would make the
-  // prediction too small and the limit the young gen every time we get to the
-  // predicted target occupancy.
-  size_t last_unrestrained_young_length = update_young_list_max_and_target_length();
+
   update_rs_lengths_prediction();
 
-  update_ihop_prediction(app_time_ms / 1000.0,
-                         _bytes_allocated_in_old_since_last_gc,
-                         last_unrestrained_young_length * HeapRegion::GrainBytes,
-                         this_pause_was_young_only);
-  _bytes_allocated_in_old_since_last_gc = 0;
+  // Do not update dynamic IHOP due to G1 periodic collection as it is highly likely
+  // that in this case we are not running in a "normal" operating mode.
+  if (_g1h->gc_cause() != GCCause::_g1_periodic_collection) {
+    // IHOP control wants to know the expected young gen length if it were not
+    // restrained by the heap reserve. Using the actual length would make the
+    // prediction too small and the limit the young gen every time we get to the
+    // predicted target occupancy.
+    size_t last_unrestrained_young_length = update_young_list_max_and_target_length();
 
-  _ihop_control->send_trace_event(_g1h->gc_tracer_stw());
+    update_ihop_prediction(app_time_ms / 1000.0,
+                           _bytes_allocated_in_old_since_last_gc,
+                           last_unrestrained_young_length * HeapRegion::GrainBytes,
+                           this_pause_was_young_only);
+    _bytes_allocated_in_old_since_last_gc = 0;
+
+    _ihop_control->send_trace_event(_g1h->gc_tracer_stw());
+  } else {
+    // Any garbage collection triggered as periodic collection resets the time-to-mixed
+    // measurement. Periodic collection typically means that the application is "inactive", i.e.
+    // the marking threads may have received an uncharacterisic amount of cpu time
+    // for completing the marking, i.e. are faster than expected.
+    // This skews the predicted marking length towards smaller values which might cause
+    // the mark start being too late.
+    _initial_mark_to_mixed.reset();
+  }
 
   // Note that _mmu_tracker->max_gc_time() returns the time in seconds.
   double update_rs_time_goal_ms = _mmu_tracker->max_gc_time() * MILLIUNITS * G1RSetUpdatingPauseTimePercent / 100.0;
@@ -1078,7 +1092,9 @@
       _initial_mark_to_mixed.add_pause(end - start);
       break;
     case InitialMarkGC:
-      _initial_mark_to_mixed.record_initial_mark_end(end);
+      if (_g1h->gc_cause() != GCCause::_g1_periodic_collection) {
+        _initial_mark_to_mixed.record_initial_mark_end(end);
+      }
       break;
     case MixedGC:
       _initial_mark_to_mixed.record_mixed_gc_start(start);
--- a/src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.cpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.cpp	Mon Dec 10 10:25:27 2018 +0100
@@ -25,6 +25,8 @@
 #include "precompiled.hpp"
 #include "gc/g1/g1CollectedHeap.inline.hpp"
 #include "gc/g1/g1CollectionSet.hpp"
+#include "gc/g1/g1ConcurrentMark.inline.hpp"
+#include "gc/g1/g1ConcurrentMarkThread.inline.hpp"
 #include "gc/g1/g1Policy.hpp"
 #include "gc/g1/g1YoungRemSetSamplingThread.hpp"
 #include "gc/g1/heapRegion.inline.hpp"
@@ -37,7 +39,8 @@
     _monitor(Mutex::nonleaf,
              "G1YoungRemSetSamplingThread monitor",
              true,
-             Monitor::_safepoint_check_never) {
+             Monitor::_safepoint_check_never),
+    _last_periodic_gc_attempt_s(os::elapsedTime()) {
   set_name("G1 Young RemSet Sampling");
   create_and_start();
 }
@@ -45,11 +48,49 @@
 void G1YoungRemSetSamplingThread::sleep_before_next_cycle() {
   MutexLockerEx x(&_monitor, Mutex::_no_safepoint_check_flag);
   if (!should_terminate()) {
-    uintx waitms = G1ConcRefinementServiceIntervalMillis; // 300, really should be?
+    uintx waitms = G1ConcRefinementServiceIntervalMillis;
     _monitor.wait(Mutex::_no_safepoint_check_flag, waitms);
   }
 }
 
+bool G1YoungRemSetSamplingThread::should_start_periodic_gc() {
+  // If we are currently in a concurrent mark we are going to uncommit memory soon.
+  if (G1CollectedHeap::heap()->concurrent_mark()->cm_thread()->during_cycle()) {
+    log_debug(gc, periodic)("Concurrent cycle in progress. Skipping.");
+    return false;
+  }
+
+  // Check if enough time has passed since the last GC.
+  uintx time_since_last_gc;
+  if ((G1PeriodicGCInterval == 0) ||
+      ((time_since_last_gc = (uintx)Universe::heap()->millis_since_last_gc()) < G1PeriodicGCInterval)) {
+    log_debug(gc, periodic)("Last GC occurred " UINTX_FORMAT "ms before which is below threshold " UINTX_FORMAT "ms. Skipping.",
+                            time_since_last_gc, G1PeriodicGCInterval);
+    return false;
+  }
+
+  // Check if load is lower than max.
+  double recent_load;
+  if ((G1PeriodicGCSystemLoadThreshold > 0) &&
+      (os::loadavg(&recent_load, 1) == -1 || recent_load > G1PeriodicGCSystemLoadThreshold)) {
+    log_debug(gc, periodic)("Load %1.2f is higher than threshold " UINTX_FORMAT ". Skipping.",
+                            recent_load, G1PeriodicGCSystemLoadThreshold);
+    return false;
+  }
+
+  return true;
+}
+
+void G1YoungRemSetSamplingThread::check_for_periodic_gc(){
+  if ((os::elapsedTime() - _last_periodic_gc_attempt_s) > (G1PeriodicGCInterval / 1000.0)) {
+    log_debug(gc, periodic)("Checking for periodic GC.");
+    if (should_start_periodic_gc()) {
+      Universe::heap()->collect(GCCause::_g1_periodic_collection);
+    }
+    _last_periodic_gc_attempt_s = os::elapsedTime();
+  }
+}
+
 void G1YoungRemSetSamplingThread::run_service() {
   double vtime_start = os::elapsedVTime();
 
@@ -62,6 +103,8 @@
       _vtime_accum = 0.0;
     }
 
+    check_for_periodic_gc();
+
     sleep_before_next_cycle();
   }
 }
--- a/src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.hpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.hpp	Mon Dec 10 10:25:27 2018 +0100
@@ -43,14 +43,20 @@
 private:
   Monitor _monitor;
 
+  double _last_periodic_gc_attempt_s;
+
+  double _vtime_accum;  // Accumulated virtual time.
+
   void sample_young_list_rs_lengths();
 
   void run_service();
+  void check_for_periodic_gc();
+
   void stop_service();
 
   void sleep_before_next_cycle();
 
-  double _vtime_accum;  // Accumulated virtual time.
+  bool should_start_periodic_gc();
 
 public:
   G1YoungRemSetSamplingThread();
--- a/src/hotspot/share/gc/g1/g1_globals.hpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/g1/g1_globals.hpp	Mon Dec 10 10:25:27 2018 +0100
@@ -299,6 +299,23 @@
           "Verify the code root lists attached to each heap region.")       \
                                                                             \
   develop(bool, G1VerifyBitmaps, false,                                     \
-          "Verifies the consistency of the marking bitmaps")
+          "Verifies the consistency of the marking bitmaps")                \
+                                                                            \
+  manageable(uintx, G1PeriodicGCInterval, 0,                                \
+          "Number of milliseconds after a previous GC to wait before "      \
+          "triggering a periodic gc. A value of zero disables periodically "\
+          "enforced gc cycles.")                                            \
+          range(0, max_jlong)                                               \
+                                                                            \
+  product(bool, G1PeriodicGCInvokesConcurrent, true,                        \
+          "Determines the kind of periodic GC. Set to true to have G1 "     \
+          "perform a concurrent GC as periodic GC, otherwise use a STW "    \
+          "Full GC.")                                                       \
+                                                                            \
+  manageable(uintx, G1PeriodicGCSystemLoadThreshold, 0,                     \
+          "Maximum recent system wide system load as returned by the 1m "   \
+          "value of getloadavg() at which G1 triggers a periodic GC. A "    \
+          "load above this value cancels a given periodic GC. A value of "  \
+          "zero disables this check.")                                      \
 
 #endif // SHARE_VM_GC_G1_G1_GLOBALS_HPP
--- a/src/hotspot/share/gc/shared/gcCause.cpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/shared/gcCause.cpp	Mon Dec 10 10:25:27 2018 +0100
@@ -105,6 +105,9 @@
     case _g1_humongous_allocation:
       return "G1 Humongous Allocation";
 
+    case _g1_periodic_collection:
+      return "G1 Periodic Collection";
+
     case _dcmd_gc_run:
       return "Diagnostic Command";
 
--- a/src/hotspot/share/gc/shared/gcCause.hpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/shared/gcCause.hpp	Mon Dec 10 10:25:27 2018 +0100
@@ -76,6 +76,7 @@
 
     _g1_inc_collection_pause,
     _g1_humongous_allocation,
+    _g1_periodic_collection,
 
     _dcmd_gc_run,
 
--- a/src/hotspot/share/gc/shared/gcVMOperations.cpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/gc/shared/gcVMOperations.cpp	Mon Dec 10 10:25:27 2018 +0100
@@ -81,7 +81,6 @@
 }
 
 bool VM_GC_Operation::doit_prologue() {
-  assert(Thread::current()->is_Java_thread(), "just checking");
   assert(((_gc_cause != GCCause::_no_gc) &&
           (_gc_cause != GCCause::_no_cause_specified)), "Illegal GCCause");
 
@@ -110,7 +109,6 @@
 
 
 void VM_GC_Operation::doit_epilogue() {
-  assert(Thread::current()->is_Java_thread(), "just checking");
   // Clean up old interpreter OopMap entries that were replaced
   // during the GC thread root traversal.
   OopMapCache::cleanup_old_entries();
--- a/src/hotspot/share/logging/logTag.hpp	Mon Dec 10 09:37:18 2018 +0100
+++ b/src/hotspot/share/logging/logTag.hpp	Mon Dec 10 10:25:27 2018 +0100
@@ -119,6 +119,7 @@
   LOG_TAG(patch) \
   LOG_TAG(path) \
   LOG_TAG(perf) \
+  LOG_TAG(periodic) \
   LOG_TAG(phases) \
   LOG_TAG(plab) \
   LOG_TAG(preview)   /* Trace loading of preview feature types */ \
--- a/test/hotspot/jtreg/TEST.groups	Mon Dec 10 09:37:18 2018 +0100
+++ b/test/hotspot/jtreg/TEST.groups	Mon Dec 10 10:25:27 2018 +0100
@@ -178,6 +178,7 @@
   gc/epsilon/ \
   gc/g1/ \
   -gc/g1/ihop/TestIHOPErgo.java
+  -gc/g1/TestTimelyCompaction.java
 
 tier1_gc_2 = \
   gc/ \
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/hotspot/jtreg/gc/g1/TestPeriodicCollection.java	Mon Dec 10 10:25:27 2018 +0100
@@ -0,0 +1,110 @@
+/*
+ * Copyright (c) 2018, 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 TestPeriodicCollection
+ * @requires vm.gc.G1
+ * @requires vm.compMode != "Xcomp"
+ * @summary Verify that heap shrinks when the application is idle.
+ * @library /test/lib /
+ * @modules java.base/jdk.internal.misc
+ * @modules java.management/sun.management
+ * @run main/othervm -XX:MaxNewSize=32M -XX:InitialHeapSize=48M -Xmx128M -XX:MinHeapFreeRatio=5 -XX:MaxHeapFreeRatio=25 -XX:+UseG1GC -XX:G1PeriodicGCInterval=3000 -XX:+G1PeriodicGCInvokesConcurrent -Xlog:gc,gc+periodic=debug,gc+ergo+heap=debug TestPeriodicCollection
+ * @run main/othervm -XX:MaxNewSize=32M -XX:InitialHeapSize=48M -Xmx128M -XX:MinHeapFreeRatio=5 -XX:MaxHeapFreeRatio=25 -XX:+UseG1GC -XX:G1PeriodicGCInterval=3000 -XX:-G1PeriodicGCInvokesConcurrent -Xlog:gc,gc+periodic=debug,gc+ergo+heap=debug TestPeriodicCollection
+ */
+
+import com.sun.management.HotSpotDiagnosticMXBean;
+
+import gc.testlibrary.Helpers;
+
+import java.lang.management.GarbageCollectorMXBean;
+import java.lang.management.ManagementFactory;
+import java.lang.management.MemoryUsage;
+import java.text.NumberFormat;
+import static jdk.test.lib.Asserts.*;
+
+public class TestPeriodicCollection {
+
+    public static final String MIN_FREE_RATIO_FLAG_NAME = "MinHeapFreeRatio";
+    public static final String MAX_FREE_RATIO_FLAG_NAME = "MaxHeapFreeRatio";
+
+    private static final int IDLE_TIME = 7 * 1000;
+
+    private static boolean gcOccurred() {
+        for (GarbageCollectorMXBean b : ManagementFactory.getGarbageCollectorMXBeans()) {
+            if (b.getCollectionCount() != 0) {
+                return true;
+            }
+        }
+        return false;
+    }
+
+    public static void main(String[] args) {
+        MemoryUsage muInitial = ManagementFactory.getMemoryMXBean().getHeapMemoryUsage();
+        MemoryUsagePrinter.printMemoryUsage("initial", muInitial);
+
+        if (gcOccurred()) {
+          System.out.println("At least one garbage collection occurred. Exiting as this may have already shrunk the heap.");
+          return;
+        }
+
+        try {
+            Thread.sleep(IDLE_TIME);
+        } catch (InterruptedException ie) {
+            System.err.println("Skipped. Failed to wait for idle collection");
+        }
+
+        MemoryUsage muAfter = ManagementFactory.getMemoryMXBean().getHeapMemoryUsage();
+        MemoryUsagePrinter.printMemoryUsage("after", muAfter);
+
+        assertLessThan(muAfter.getCommitted(), muInitial.getCommitted(), String.format(
+                "committed free heap size is not less than committed full heap size, heap hasn't been shrunk?%n"
+                + "%s = %s%n%s = %s",
+                MIN_FREE_RATIO_FLAG_NAME,
+                ManagementFactory.getPlatformMXBean(HotSpotDiagnosticMXBean.class)
+                    .getVMOption(MIN_FREE_RATIO_FLAG_NAME).getValue(),
+                MAX_FREE_RATIO_FLAG_NAME,
+                ManagementFactory.getPlatformMXBean(HotSpotDiagnosticMXBean.class)
+                    .getVMOption(MAX_FREE_RATIO_FLAG_NAME).getValue()
+        ));
+    }
+}
+
+/**
+ * Prints memory usage to standard output
+ */
+class MemoryUsagePrinter {
+
+    public static final NumberFormat NF = Helpers.numberFormatter();
+
+    public static void printMemoryUsage(String label, MemoryUsage memusage) {
+        float freeratio = 1f - (float) memusage.getUsed() / memusage.getCommitted();
+        System.out.format("[%-24s] init: %-7s, used: %-7s, comm: %-7s, freeRatio ~= %.1f%%%n",
+                label,
+                NF.format(memusage.getInit()),
+                NF.format(memusage.getUsed()),
+                NF.format(memusage.getCommitted()),
+                freeratio * 100
+        );
+    }
+}