Thu, 19 Mar 2015 15:25:54 +0100
8027962: Per-phase timing measurements for strong roots processing
Reviewed-by: tschatzl, ecaspole
tschatzl@6402 | 1 | /* |
brutisso@7660 | 2 | * Copyright (c) 2014, 2015 Oracle and/or its affiliates. All rights reserved. |
tschatzl@6402 | 3 | * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. |
tschatzl@6402 | 4 | * |
tschatzl@6402 | 5 | * This code is free software; you can redistribute it and/or modify it |
tschatzl@6402 | 6 | * under the terms of the GNU General Public License version 2 only, as |
tschatzl@6402 | 7 | * published by the Free Software Foundation. |
tschatzl@6402 | 8 | * |
tschatzl@6402 | 9 | * This code is distributed in the hope that it will be useful, but WITHOUT |
tschatzl@6402 | 10 | * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or |
tschatzl@6402 | 11 | * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License |
tschatzl@6402 | 12 | * version 2 for more details (a copy is included in the LICENSE file that |
tschatzl@6402 | 13 | * accompanied this code). |
tschatzl@6402 | 14 | * |
tschatzl@6402 | 15 | * You should have received a copy of the GNU General Public License version |
tschatzl@6402 | 16 | * 2 along with this work; if not, write to the Free Software Foundation, |
tschatzl@6402 | 17 | * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. |
tschatzl@6402 | 18 | * |
tschatzl@6402 | 19 | * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA |
tschatzl@6402 | 20 | * or visit www.oracle.com if you need additional information or have any |
tschatzl@6402 | 21 | * questions. |
tschatzl@6402 | 22 | */ |
tschatzl@6402 | 23 | |
tschatzl@6402 | 24 | /* |
jmasa@6950 | 25 | * @test TestGCLogMessages |
brutisso@7660 | 26 | * @bug 8035406 8027295 8035398 8019342 8027959 8027962 |
tschatzl@6402 | 27 | * @summary Ensure that the PrintGCDetails output for a minor GC with G1 |
tschatzl@6402 | 28 | * includes the expected necessary messages. |
tschatzl@6402 | 29 | * @key gc |
tschatzl@6402 | 30 | * @library /testlibrary |
tschatzl@6402 | 31 | */ |
tschatzl@6402 | 32 | |
tschatzl@6402 | 33 | import com.oracle.java.testlibrary.ProcessTools; |
tschatzl@6402 | 34 | import com.oracle.java.testlibrary.OutputAnalyzer; |
tschatzl@6402 | 35 | |
tschatzl@6402 | 36 | public class TestGCLogMessages { |
tschatzl@6406 | 37 | |
brutisso@7660 | 38 | private enum Level { |
brutisso@7660 | 39 | OFF, FINER, FINEST; |
brutisso@7660 | 40 | public boolean lessOrEqualTo(Level other) { |
brutisso@7660 | 41 | return this.compareTo(other) < 0; |
brutisso@7660 | 42 | } |
brutisso@7660 | 43 | } |
tschatzl@6402 | 44 | |
brutisso@7660 | 45 | private class LogMessageWithLevel { |
brutisso@7660 | 46 | String message; |
brutisso@7660 | 47 | Level level; |
tschatzl@6402 | 48 | |
brutisso@7660 | 49 | public LogMessageWithLevel(String message, Level level) { |
brutisso@7660 | 50 | this.message = message; |
brutisso@7660 | 51 | this.level = level; |
brutisso@7660 | 52 | } |
brutisso@7660 | 53 | }; |
tschatzl@6402 | 54 | |
brutisso@7660 | 55 | private LogMessageWithLevel allLogMessages[] = new LogMessageWithLevel[] { |
brutisso@7660 | 56 | // Ext Root Scan |
brutisso@7660 | 57 | new LogMessageWithLevel("Thread Roots (ms)", Level.FINEST), |
brutisso@7660 | 58 | new LogMessageWithLevel("StringTable Roots (ms)", Level.FINEST), |
brutisso@7660 | 59 | new LogMessageWithLevel("Universe Roots (ms)", Level.FINEST), |
brutisso@7660 | 60 | new LogMessageWithLevel("JNI Handles Roots (ms)", Level.FINEST), |
brutisso@7660 | 61 | new LogMessageWithLevel("ObjectSynchronizer Roots (ms)", Level.FINEST), |
brutisso@7660 | 62 | new LogMessageWithLevel("FlatProfiler Roots", Level.FINEST), |
brutisso@7660 | 63 | new LogMessageWithLevel("Management Roots", Level.FINEST), |
brutisso@7660 | 64 | new LogMessageWithLevel("SystemDictionary Roots", Level.FINEST), |
brutisso@7660 | 65 | new LogMessageWithLevel("CLDG Roots", Level.FINEST), |
brutisso@7660 | 66 | new LogMessageWithLevel("JVMTI Roots", Level.FINEST), |
brutisso@7660 | 67 | new LogMessageWithLevel("CodeCache Roots", Level.FINEST), |
brutisso@7660 | 68 | new LogMessageWithLevel("SATB Filtering", Level.FINEST), |
brutisso@7660 | 69 | new LogMessageWithLevel("CM RefProcessor Roots", Level.FINEST), |
brutisso@7660 | 70 | new LogMessageWithLevel("Wait For Strong CLD", Level.FINEST), |
brutisso@7660 | 71 | new LogMessageWithLevel("Weak CLD Roots", Level.FINEST), |
brutisso@7660 | 72 | // Redirty Cards |
brutisso@7660 | 73 | new LogMessageWithLevel("Redirty Cards", Level.FINER), |
brutisso@7660 | 74 | new LogMessageWithLevel("Parallel Redirty", Level.FINEST), |
brutisso@7660 | 75 | new LogMessageWithLevel("Redirtied Cards", Level.FINEST), |
brutisso@7660 | 76 | // Misc Top-level |
brutisso@7660 | 77 | new LogMessageWithLevel("Code Root Purge", Level.FINER), |
brutisso@7660 | 78 | new LogMessageWithLevel("String Dedup Fixup", Level.FINER), |
brutisso@7660 | 79 | // Free CSet |
brutisso@7660 | 80 | new LogMessageWithLevel("Young Free CSet", Level.FINEST), |
brutisso@7660 | 81 | new LogMessageWithLevel("Non-Young Free CSet", Level.FINEST), |
brutisso@7660 | 82 | // Humongous Eager Reclaim |
brutisso@7660 | 83 | new LogMessageWithLevel("Humongous Reclaim", Level.FINER), |
brutisso@7660 | 84 | }; |
tschatzl@6404 | 85 | |
brutisso@7660 | 86 | void checkMessagesAtLevel(OutputAnalyzer output, LogMessageWithLevel messages[], Level level) throws Exception { |
brutisso@7660 | 87 | for (LogMessageWithLevel l : messages) { |
brutisso@7660 | 88 | if (level.lessOrEqualTo(l.level)) { |
brutisso@7660 | 89 | output.shouldNotContain(l.message); |
brutisso@7660 | 90 | } else { |
brutisso@7660 | 91 | output.shouldContain(l.message); |
brutisso@7660 | 92 | } |
brutisso@7660 | 93 | } |
brutisso@7660 | 94 | } |
tschatzl@6404 | 95 | |
brutisso@7660 | 96 | public static void main(String[] args) throws Exception { |
brutisso@7660 | 97 | new TestGCLogMessages().testNormalLogs(); |
brutisso@7660 | 98 | new TestGCLogMessages().testWithToSpaceExhaustionLogs(); |
brutisso@7660 | 99 | } |
tschatzl@6404 | 100 | |
brutisso@7660 | 101 | private void testNormalLogs() throws Exception { |
tschatzl@6404 | 102 | |
brutisso@7660 | 103 | ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC", |
brutisso@7660 | 104 | "-Xmx10M", |
brutisso@7660 | 105 | GCTest.class.getName()); |
tschatzl@6404 | 106 | |
brutisso@7660 | 107 | OutputAnalyzer output = new OutputAnalyzer(pb.start()); |
brutisso@7660 | 108 | checkMessagesAtLevel(output, allLogMessages, Level.OFF); |
brutisso@7660 | 109 | output.shouldHaveExitValue(0); |
tschatzl@6404 | 110 | |
brutisso@7660 | 111 | pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC", |
brutisso@7660 | 112 | "-XX:+UseStringDeduplication", |
brutisso@7660 | 113 | "-Xmx10M", |
brutisso@7660 | 114 | "-XX:+PrintGCDetails", |
brutisso@7660 | 115 | GCTest.class.getName()); |
tschatzl@6406 | 116 | |
brutisso@7660 | 117 | output = new OutputAnalyzer(pb.start()); |
brutisso@7660 | 118 | checkMessagesAtLevel(output, allLogMessages, Level.FINER); |
tschatzl@6406 | 119 | |
brutisso@7660 | 120 | pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC", |
brutisso@7660 | 121 | "-XX:+UseStringDeduplication", |
brutisso@7660 | 122 | "-Xmx10M", |
brutisso@7660 | 123 | "-XX:+PrintGCDetails", |
brutisso@7660 | 124 | "-XX:+UnlockExperimentalVMOptions", |
brutisso@7660 | 125 | "-XX:G1LogLevel=finest", |
brutisso@7660 | 126 | GCTest.class.getName()); |
tschatzl@6404 | 127 | |
brutisso@7660 | 128 | output = new OutputAnalyzer(pb.start()); |
brutisso@7660 | 129 | checkMessagesAtLevel(output, allLogMessages, Level.FINEST); |
brutisso@7660 | 130 | output.shouldHaveExitValue(0); |
brutisso@7660 | 131 | } |
tschatzl@6406 | 132 | |
brutisso@7660 | 133 | LogMessageWithLevel exhFailureMessages[] = new LogMessageWithLevel[] { |
brutisso@7660 | 134 | new LogMessageWithLevel("Evacuation Failure", Level.FINER), |
brutisso@7660 | 135 | new LogMessageWithLevel("Recalculate Used", Level.FINEST), |
brutisso@7660 | 136 | new LogMessageWithLevel("Remove Self Forwards", Level.FINEST), |
brutisso@7660 | 137 | new LogMessageWithLevel("Restore RemSet", Level.FINEST), |
brutisso@7660 | 138 | }; |
tschatzl@6402 | 139 | |
brutisso@7660 | 140 | private void testWithToSpaceExhaustionLogs() throws Exception { |
brutisso@7660 | 141 | ProcessBuilder pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC", |
brutisso@7660 | 142 | "-Xmx32M", |
brutisso@7660 | 143 | "-Xmn16M", |
brutisso@7660 | 144 | "-XX:+PrintGCDetails", |
brutisso@7660 | 145 | GCTestWithToSpaceExhaustion.class.getName()); |
brutisso@7660 | 146 | |
brutisso@7660 | 147 | OutputAnalyzer output = new OutputAnalyzer(pb.start()); |
brutisso@7660 | 148 | checkMessagesAtLevel(output, exhFailureMessages, Level.FINER); |
brutisso@7660 | 149 | output.shouldHaveExitValue(0); |
brutisso@7660 | 150 | |
brutisso@7660 | 151 | pb = ProcessTools.createJavaProcessBuilder("-XX:+UseG1GC", |
brutisso@7660 | 152 | "-Xmx32M", |
brutisso@7660 | 153 | "-Xmn16M", |
brutisso@7660 | 154 | "-XX:+PrintGCDetails", |
brutisso@7660 | 155 | "-XX:+UnlockExperimentalVMOptions", |
brutisso@7660 | 156 | "-XX:G1LogLevel=finest", |
brutisso@7660 | 157 | GCTestWithToSpaceExhaustion.class.getName()); |
brutisso@7660 | 158 | |
brutisso@7660 | 159 | output = new OutputAnalyzer(pb.start()); |
brutisso@7660 | 160 | checkMessagesAtLevel(output, exhFailureMessages, Level.FINEST); |
brutisso@7660 | 161 | output.shouldHaveExitValue(0); |
tschatzl@6402 | 162 | } |
tschatzl@6406 | 163 | |
brutisso@7660 | 164 | static class GCTest { |
brutisso@7660 | 165 | private static byte[] garbage; |
brutisso@7660 | 166 | public static void main(String [] args) { |
brutisso@7660 | 167 | System.out.println("Creating garbage"); |
brutisso@7660 | 168 | // create 128MB of garbage. This should result in at least one GC |
brutisso@7660 | 169 | for (int i = 0; i < 1024; i++) { |
brutisso@7660 | 170 | garbage = new byte[128 * 1024]; |
brutisso@7660 | 171 | } |
brutisso@7660 | 172 | System.out.println("Done"); |
brutisso@7660 | 173 | } |
tschatzl@6406 | 174 | } |
brutisso@7660 | 175 | |
brutisso@7660 | 176 | static class GCTestWithToSpaceExhaustion { |
brutisso@7660 | 177 | private static byte[] garbage; |
brutisso@7660 | 178 | private static byte[] largeObject; |
brutisso@7660 | 179 | public static void main(String [] args) { |
brutisso@7660 | 180 | largeObject = new byte[16*1024*1024]; |
brutisso@7660 | 181 | System.out.println("Creating garbage"); |
brutisso@7660 | 182 | // create 128MB of garbage. This should result in at least one GC, |
brutisso@7660 | 183 | // some of them with to-space exhaustion. |
brutisso@7660 | 184 | for (int i = 0; i < 1024; i++) { |
brutisso@7660 | 185 | garbage = new byte[128 * 1024]; |
brutisso@7660 | 186 | } |
brutisso@7660 | 187 | System.out.println("Done"); |
brutisso@7660 | 188 | } |
brutisso@7660 | 189 | } |
tschatzl@6402 | 190 | } |
brutisso@7660 | 191 |