1 /*
   2  * Copyright (c) 2014, 2019, Oracle and/or its affiliates. All rights reserved.
   3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   4  *
   5  * This code is free software; you can redistribute it and/or modify it
   6  * under the terms of the GNU General Public License version 2 only, as
   7  * published by the Free Software Foundation.
   8  *
   9  * This code is distributed in the hope that it will be useful, but WITHOUT
  10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
  11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
  12  * version 2 for more details (a copy is included in the LICENSE file that
  13  * accompanied this code).
  14  *
  15  * You should have received a copy of the GNU General Public License version
  16  * 2 along with this work; if not, write to the Free Software Foundation,
  17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
  18  *
  19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
  20  * or visit www.oracle.com if you need additional information or have any
  21  * questions.
  22  */
  23 
  24 package gc.g1;
  25 
  26 /*
  27  * @test TestGCLogMessages
  28  * @bug 8035406 8027295 8035398 8019342 8027959 8048179 8027962 8069330 8076463 8150630 8160055 8177059 8166191
  29  * @summary Ensure the output for a minor GC with G1
  30  * includes the expected necessary messages.
  31  * @key gc
  32  * @requires vm.gc.G1
  33  * @library /test/lib
  34  * @modules java.base/jdk.internal.misc
  35  *          java.management
  36  * @build sun.hotspot.WhiteBox
  37  * @run driver ClassFileInstaller sun.hotspot.WhiteBox
  38  *                                sun.hotspot.WhiteBox$WhiteBoxPermission
  39  * @run main/othervm -Xbootclasspath/a:. -XX:+UnlockDiagnosticVMOptions -XX:+WhiteBoxAPI
  40  *                   gc.g1.TestGCLogMessages
  41  */
  42 
  43 import jdk.test.lib.process.OutputAnalyzer;
  44 import jdk.test.lib.process.ProcessTools;
  45 import sun.hotspot.code.Compiler;
  46 
  47 public class TestGCLogMessages {
  48 
  49     private enum Level {
  50         OFF(""),
  51         INFO("info"),
  52         DEBUG("debug"),
  53         TRACE("trace");
  54 
  55         private String logName;
  56 
  57         Level(String logName) {
  58             this.logName = logName;
  59         }
  60 
  61         public boolean lessThan(Level other) {
  62             return this.compareTo(other) < 0;
  63         }
  64 
  65         public String toString() {
  66             return logName;
  67         }
  68     }
  69 
  70     private class LogMessageWithLevel {
  71         String message;
  72         Level level;
  73 
  74         public LogMessageWithLevel(String message, Level level) {
  75             this.message = message;
  76             this.level = level;
  77         }
  78 
  79         public boolean isAvailable() {
  80             return true;
  81         }
  82     };
  83 
  84     private class LogMessageWithLevelC2OrJVMCIOnly extends LogMessageWithLevel {
  85         public LogMessageWithLevelC2OrJVMCIOnly(String message, Level level) {
  86             super(message, level);
  87         }
  88 
  89         public boolean isAvailable() {
  90             return Compiler.isC2OrGraalIncludedInVmBuild();
  91         }
  92     }
  93 
  94     private LogMessageWithLevel allLogMessages[] = new LogMessageWithLevel[] {
  95         new LogMessageWithLevel("Pre Evacuate Collection Set", Level.INFO),
  96         new LogMessageWithLevel("Evacuate Collection Set", Level.INFO),
  97         new LogMessageWithLevel("Post Evacuate Collection Set", Level.INFO),
  98         new LogMessageWithLevel("Other", Level.INFO),
  99 
 100         // Merge Heap Roots
 101         new LogMessageWithLevel("Merge Heap Roots", Level.INFO),
 102         new LogMessageWithLevel("Prepare Merge Heap Roots", Level.DEBUG),
 103         new LogMessageWithLevel("Eager Reclaim", Level.DEBUG),
 104         new LogMessageWithLevel("Remembered Sets", Level.DEBUG),
 105         new LogMessageWithLevel("Merged Sparse", Level.DEBUG),
 106         new LogMessageWithLevel("Merged Fine", Level.DEBUG),
 107         new LogMessageWithLevel("Merged Coarse", Level.DEBUG),
 108         new LogMessageWithLevel("Hot Card Cache", Level.DEBUG),
 109         new LogMessageWithLevel("Log Buffers", Level.DEBUG),
 110         new LogMessageWithLevel("Dirty Cards", Level.DEBUG),
 111         new LogMessageWithLevel("Skipped Cards", Level.DEBUG),
 112         // Scan Heap Roots
 113         new LogMessageWithLevel("Scan Heap Roots", Level.DEBUG),
 114         new LogMessageWithLevel("Scanned Cards", Level.DEBUG),
 115         new LogMessageWithLevel("Scanned Blocks", Level.DEBUG),
 116         new LogMessageWithLevel("Claimed Chunks", Level.DEBUG),
 117         // Code Roots Scan
 118         new LogMessageWithLevel("Code Root Scan", Level.DEBUG),
 119         // Object Copy
 120         new LogMessageWithLevel("Object Copy", Level.DEBUG),
 121         new LogMessageWithLevel("Copied Bytes", Level.DEBUG),
 122         new LogMessageWithLevel("LAB Waste", Level.DEBUG),
 123         new LogMessageWithLevel("LAB Undo Waste", Level.DEBUG),
 124         // Ext Root Scan
 125         new LogMessageWithLevel("Thread Roots", Level.TRACE),
 126         new LogMessageWithLevel("Universe Roots", Level.TRACE),
 127         new LogMessageWithLevel("JNI Handles Roots", Level.TRACE),
 128         new LogMessageWithLevel("ObjectSynchronizer Roots", Level.TRACE),
 129         new LogMessageWithLevel("Management Roots", Level.TRACE),
 130         new LogMessageWithLevel("SystemDictionary Roots", Level.TRACE),
 131         new LogMessageWithLevel("CLDG Roots", Level.TRACE),
 132         new LogMessageWithLevel("JVMTI Roots", Level.TRACE),
 133         new LogMessageWithLevel("CM RefProcessor Roots", Level.TRACE),
 134         // Redirty Cards
 135         new LogMessageWithLevel("Redirty Cards", Level.DEBUG),
 136         new LogMessageWithLevel("Parallel Redirty", Level.TRACE),
 137         new LogMessageWithLevel("Redirtied Cards", Level.TRACE),
 138         // Misc Top-level
 139         new LogMessageWithLevel("Code Roots Purge", Level.DEBUG),
 140         new LogMessageWithLevel("String Deduplication", Level.DEBUG),
 141         new LogMessageWithLevel("Queue Fixup", Level.DEBUG),
 142         new LogMessageWithLevel("Table Fixup", Level.DEBUG),
 143         new LogMessageWithLevel("Expand Heap After Collection", Level.DEBUG),
 144         new LogMessageWithLevel("Region Register", Level.DEBUG),
 145         new LogMessageWithLevel("Prepare Heap Roots", Level.DEBUG),
 146         // Free CSet
 147         new LogMessageWithLevel("Free Collection Set", Level.DEBUG),
 148         new LogMessageWithLevel("Serial Free Collection Set", Level.TRACE),
 149         new LogMessageWithLevel("Parallel Free Collection Set", Level.TRACE),
 150         new LogMessageWithLevel("Young Free Collection Set", Level.TRACE),
 151         new LogMessageWithLevel("Non-Young Free Collection Set", Level.TRACE),
 152         // Rebuild Free List
 153         new LogMessageWithLevel("Rebuild Free List", Level.DEBUG),
 154         new LogMessageWithLevel("Serial Rebuild Free List", Level.TRACE),
 155         new LogMessageWithLevel("Parallel Rebuild Free List", Level.TRACE),
 156 
 157         // Humongous Eager Reclaim
 158         new LogMessageWithLevel("Humongous Reclaim", Level.DEBUG),
 159         // Merge PSS
 160         new LogMessageWithLevel("Merge Per-Thread State", Level.DEBUG),
 161         // TLAB handling
 162         new LogMessageWithLevel("Prepare TLABs", Level.DEBUG),
 163         new LogMessageWithLevel("Resize TLABs", Level.DEBUG),
 164         // Reference Processing
 165         new LogMessageWithLevel("Reference Processing", Level.DEBUG),
 166         // VM internal reference processing
 167         new LogMessageWithLevel("Weak Processing", Level.DEBUG),
 168         new LogMessageWithLevel("JNI weak", Level.DEBUG),
 169         new LogMessageWithLevel("StringTable weak", Level.DEBUG),
 170         new LogMessageWithLevel("ResolvedMethodTable weak", Level.DEBUG),
 171         new LogMessageWithLevel("VM weak", Level.DEBUG),
 172 
 173         new LogMessageWithLevelC2OrJVMCIOnly("DerivedPointerTable Update", Level.DEBUG),
 174         new LogMessageWithLevel("Start New Collection Set", Level.DEBUG),
 175     };
 176 
 177     void checkMessagesAtLevel(OutputAnalyzer output, LogMessageWithLevel messages[], Level level) throws Exception {
 178         for (LogMessageWithLevel l : messages) {
 179             if (level.lessThan(l.level) || !l.isAvailable()) {
 180                 output.shouldNotContain(l.message);
 181             } else {
 182                 output.shouldMatch("\\[" + l.level + ".*" + l.message);
 183             }
 184         }
 185     }
 186 
 187     public static void main(String[] args) throws Exception {
 188         new TestGCLogMessages().testNormalLogs();
 189         new TestGCLogMessages().testWithToSpaceExhaustionLogs();
 190         new TestGCLogMessages().testWithInitialMark();
 191         new TestGCLogMessages().testExpandHeap();
 192     }
 193 
 194     private void testNormalLogs() throws Exception {
 195 
 196         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
 197                                                                   "-Xmx10M",
 198                                                                   GCTest.class.getName());
 199 
 200         OutputAnalyzer output = new OutputAnalyzer(pb.start());
 201         checkMessagesAtLevel(output, allLogMessages, Level.OFF);
 202         output.shouldHaveExitValue(0);
 203 
 204         pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
 205                                                    "-XX:+UseStringDeduplication",
 206                                                    "-Xmx10M",
 207                                                    "-Xlog:gc+phases=debug",
 208                                                    GCTest.class.getName());
 209 
 210         output = new OutputAnalyzer(pb.start());
 211         checkMessagesAtLevel(output, allLogMessages, Level.DEBUG);
 212 
 213         pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
 214                                                    "-XX:+UseStringDeduplication",
 215                                                    "-Xmx10M",
 216                                                    "-Xlog:gc+phases=trace",
 217                                                    GCTest.class.getName());
 218 
 219         output = new OutputAnalyzer(pb.start());
 220         checkMessagesAtLevel(output, allLogMessages, Level.TRACE);
 221         output.shouldHaveExitValue(0);
 222     }
 223 
 224     LogMessageWithLevel exhFailureMessages[] = new LogMessageWithLevel[] {
 225         new LogMessageWithLevel("Evacuation Failure", Level.DEBUG),
 226         new LogMessageWithLevel("Recalculate Used", Level.TRACE),
 227         new LogMessageWithLevel("Remove Self Forwards", Level.TRACE),
 228     };
 229 
 230     private void testWithToSpaceExhaustionLogs() throws Exception {
 231         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
 232                                                                   "-Xmx32M",
 233                                                                   "-Xmn16M",
 234                                                                   "-Xlog:gc+phases=debug",
 235                                                                   GCTestWithToSpaceExhaustion.class.getName());
 236 
 237         OutputAnalyzer output = new OutputAnalyzer(pb.start());
 238         checkMessagesAtLevel(output, exhFailureMessages, Level.DEBUG);
 239         output.shouldHaveExitValue(0);
 240 
 241         pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
 242                                                    "-Xmx32M",
 243                                                    "-Xmn16M",
 244                                                    "-Xlog:gc+phases=trace",
 245                                                    GCTestWithToSpaceExhaustion.class.getName());
 246 
 247         output = new OutputAnalyzer(pb.start());
 248         checkMessagesAtLevel(output, exhFailureMessages, Level.TRACE);
 249         output.shouldHaveExitValue(0);
 250     }
 251 
 252     private void testWithInitialMark() throws Exception {
 253         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
 254                                                                   "-Xmx10M",
 255                                                                   "-Xbootclasspath/a:.",
 256                                                                   "-Xlog:gc*=debug",
 257                                                                   "-XX:+UnlockDiagnosticVMOptions",
 258                                                                   "-XX:+WhiteBoxAPI",
 259                                                                   GCTestWithInitialMark.class.getName());
 260 
 261         OutputAnalyzer output = new OutputAnalyzer(pb.start());
 262         output.shouldContain("Clear Claimed Marks");
 263         output.shouldHaveExitValue(0);
 264     }
 265 
 266     private void testExpandHeap() throws Exception {
 267         ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC",
 268                                                                   "-Xmx10M",
 269                                                                   "-Xbootclasspath/a:.",
 270                                                                   "-Xlog:gc+ergo+heap=debug",
 271                                                                   "-XX:+UnlockDiagnosticVMOptions",
 272                                                                   "-XX:+WhiteBoxAPI",
 273                                                                   GCTest.class.getName());
 274 
 275         OutputAnalyzer output = new OutputAnalyzer(pb.start());
 276         output.shouldContain("Expand the heap. requested expansion amount: ");
 277         output.shouldContain("B expansion amount: ");
 278         output.shouldHaveExitValue(0);
 279     }
 280 
 281 
 282     static class GCTest {
 283         private static byte[] garbage;
 284         public static void main(String [] args) {
 285             System.out.println("Creating garbage");
 286             // create 128MB of garbage. This should result in at least one GC
 287             for (int i = 0; i < 1024; i++) {
 288                 garbage = new byte[128 * 1024];
 289             }
 290             System.out.println("Done");
 291         }
 292     }
 293 
 294     static class GCTestWithToSpaceExhaustion {
 295         private static byte[] garbage;
 296         private static byte[] largeObject;
 297         public static void main(String [] args) {
 298             largeObject = new byte[16*1024*1024];
 299             System.out.println("Creating garbage");
 300             // create 128MB of garbage. This should result in at least one GC,
 301             // some of them with to-space exhaustion.
 302             for (int i = 0; i < 1024; i++) {
 303                 garbage = new byte[128 * 1024];
 304             }
 305             System.out.println("Done");
 306         }
 307     }
 308 
 309     static class GCTestWithInitialMark {
 310         public static void main(String [] args) {
 311             sun.hotspot.WhiteBox WB = sun.hotspot.WhiteBox.getWhiteBox();
 312             WB.g1StartConcMarkCycle();
 313         }
 314     }
 315 
 316 }
 317