8216490: Spammy periodic GC log message contains random time stamp with periodic gc disabled
authortschatzl
Wed, 16 Jan 2019 11:43:51 +0100
changeset 53354 528207d2e73e
parent 53353 a6620d37728b
child 53355 dbbe6654948d
8216490: Spammy periodic GC log message contains random time stamp with periodic gc disabled Summary: Print periodic gc status at startup and only print regular messages if enabled. Reviewed-by: sangheki, kbarrett
src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.cpp
test/hotspot/jtreg/gc/g1/TestPeriodicLogMessages.java
--- a/src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.cpp	Wed Jan 16 09:48:35 2019 +0100
+++ b/src/hotspot/share/gc/g1/g1YoungRemSetSamplingThread.cpp	Wed Jan 16 11:43:51 2019 +0100
@@ -61,9 +61,8 @@
   }
 
   // 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)) {
+  uintx time_since_last_gc = (uintx)Universe::heap()->millis_since_last_gc();
+  if ((time_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;
@@ -82,6 +81,10 @@
 }
 
 void G1YoungRemSetSamplingThread::check_for_periodic_gc(){
+  // If disabled, just return.
+  if (G1PeriodicGCInterval == 0) {
+    return;
+  }
   if ((os::elapsedTime() - _last_periodic_gc_attempt_s) > (G1PeriodicGCInterval / 1000.0)) {
     log_debug(gc, periodic)("Checking for periodic GC.");
     if (should_start_periodic_gc()) {
@@ -94,6 +97,13 @@
 void G1YoungRemSetSamplingThread::run_service() {
   double vtime_start = os::elapsedVTime();
 
+  // Print a message about periodic GC configuration.
+  if (G1PeriodicGCInterval != 0) {
+    log_info(gc)("Periodic GC enabled with interval " UINTX_FORMAT "ms", G1PeriodicGCInterval);
+  } else {
+    log_info(gc)("Periodic GC disabled");
+  }
+
   while (!should_terminate()) {
     sample_young_list_rs_lengths();
 
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/test/hotspot/jtreg/gc/g1/TestPeriodicLogMessages.java	Wed Jan 16 11:43:51 2019 +0100
@@ -0,0 +1,73 @@
+/*
+ * Copyright (c) 2019, 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 TestPeriodicLogMessages
+ * @bug 8216490
+ * @requires vm.gc.G1
+ * @summary Verify that log messages are printed as expected
+ * @library /test/lib /
+ * @modules java.base/jdk.internal.misc
+ * @modules java.management/sun.management
+ */
+
+import jdk.test.lib.process.OutputAnalyzer;
+import jdk.test.lib.process.ProcessTools;
+import jdk.test.lib.Platform;
+
+public class TestPeriodicLogMessages {
+
+    public static void main(String[] args) throws Exception {
+        ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
+                                                                  "-XX:G1PeriodicGCInterval=0",
+                                                                  "-Xlog:gc,gc+periodic=debug",
+                                                                  "-Xmx10M",
+                                                                  GCTest.class.getName());
+
+        OutputAnalyzer output = new OutputAnalyzer(pb.start());
+        output.shouldContain("Periodic GC disabled");
+        output.shouldNotContain("Checking for periodic GC");
+        output.shouldHaveExitValue(0);
+
+        pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
+                                                   "-XX:G1PeriodicGCInterval=100",
+                                                   "-Xlog:gc,gc+periodic=debug",
+                                                   "-Xmx10M",
+                                                   GCTest.class.getName());
+
+        output = new OutputAnalyzer(pb.start());
+        output.shouldContain("Periodic GC enabled with interval 100ms");
+        output.shouldContain("Checking for periodic GC");
+        output.shouldHaveExitValue(0);
+    }
+
+    static class GCTest {
+        public static void main(String [] args) throws Exception {
+            System.out.println("Waiting for messages...");
+            Thread.sleep(1000);
+            System.out.println("Done");
+        }
+    }
+}
+
+