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 /* 25 * @test TestPrintReferences 26 * @bug 8136991 8186402 27 * @summary Validate the reference processing logging 28 * @key gc 29 * @library /test/lib 30 * @modules java.base/jdk.internal.misc 31 * java.management 32 */ 33 34 import java.lang.ref.SoftReference; 35 import java.util.ArrayList; 36 37 import jdk.test.lib.process.OutputAnalyzer; 38 import jdk.test.lib.process.ProcessTools; 39 40 public class TestPrintReferences { 41 public static void main(String[] args) throws Exception { 42 ProcessBuilder pb_enabled = ProcessTools.createJavaProcessBuilder("-Xlog:gc+phases+ref=debug", 43 "-XX:+UseG1GC", 44 "-Xmx10M", 45 // Explicit thread setting is required to avoid using only 1 thread 46 "-XX:ParallelGCThreads=2", 47 GCTest.class.getName()); 48 OutputAnalyzer output = new OutputAnalyzer(pb_enabled.start()); 49 50 String indent_4 = " "; 51 String indent_6 = " "; 52 String indent_8 = " "; 53 String gcLogTimeRegex = ".* GC\\([0-9]+\\) "; 54 String countRegex = "[0-9]+"; 55 String timeRegex = "[0-9]+[.,][0-9]+ms"; 56 String totalRegex = gcLogTimeRegex + indent_4 + "Reference Processing: " + timeRegex + "\n"; 57 String balanceRegex = gcLogTimeRegex + indent_8 + "Balance queues: " + timeRegex + "\n"; 58 String softRefRegex = gcLogTimeRegex + indent_6 + "SoftReference: " + timeRegex + "\n"; 59 String weakRefRegex = gcLogTimeRegex + indent_6 + "WeakReference: " + timeRegex + "\n"; 60 String finalRefRegex = gcLogTimeRegex + indent_6 + "FinalReference: " + timeRegex + "\n"; 61 String phantomRefRegex = gcLogTimeRegex + indent_6 + "PhantomReference: " + timeRegex + "\n"; 62 String refDetailRegex = gcLogTimeRegex + indent_8 + "Phase2: " + timeRegex + "\n" + 63 gcLogTimeRegex + indent_8 + "Phase3: " + timeRegex + "\n" + 64 gcLogTimeRegex + indent_8 + "Discovered: " + countRegex + "\n" + 65 gcLogTimeRegex + indent_8 + "Cleared: " + countRegex + "\n"; 66 String softRefDetailRegex = gcLogTimeRegex + indent_8 + "Phase1: " + timeRegex + "\n" + refDetailRegex; 67 String enqueueRegex = gcLogTimeRegex + indent_4 + "Reference Enqueuing: " + timeRegex + "\n"; 68 String enqueueDetailRegex = gcLogTimeRegex + indent_6 + "Reference Counts: Soft: " + countRegex + 69 " Weak: " + countRegex + " Final: " + countRegex + " Phantom: " + countRegex + "\n"; 70 71 output.shouldMatch(/* Total Reference processing time */ 72 totalRegex + 73 /* SoftReference processing */ 74 softRefRegex + balanceRegex + softRefDetailRegex + 75 /* WeakReference processing */ 76 weakRefRegex + balanceRegex + refDetailRegex + 77 /* FinalReference processing */ 78 finalRefRegex + balanceRegex + refDetailRegex + 79 /* PhantomReference processing */ 80 phantomRefRegex + balanceRegex + refDetailRegex + 81 /* Total Enqueuing time */ 82 enqueueRegex + 83 /* Enqueued Stats */ 84 enqueueDetailRegex 85 ); 86 87 output.shouldHaveExitValue(0); 88 } 89 90 static class GCTest { 91 static final int M = 1024 * 1024; 92 93 public static void main(String [] args) { 94 95 ArrayList arrSoftRefs = new ArrayList(); 96 97 // Populate to triger GC and then Reference related logs will be printed. 98 for (int i = 0; i < 10; i++) { 99 byte[] tmp = new byte[M]; 100 101 arrSoftRefs.add(new SoftReference(tmp)); 102 } 103 } 104 } 105 } | 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 /* 25 * @test TestPrintReferences 26 * @bug 8136991 8186402 8186465 27 * @summary Validate the reference processing logging 28 * @key gc 29 * @library /test/lib 30 * @modules java.base/jdk.internal.misc 31 * java.management 32 */ 33 34 import java.lang.ref.SoftReference; 35 import java.util.ArrayList; 36 37 import jdk.test.lib.process.OutputAnalyzer; 38 import jdk.test.lib.process.ProcessTools; 39 import java.util.*; 40 import java.util.regex.*; 41 42 public class TestPrintReferences { 43 static String output; 44 static final String doubleRegex = "[0-9]+[.,][0-9]+"; 45 static final String referenceProcessing = "Reference Processing: "; 46 static final String softReference = "SoftReference: "; 47 static final String weakReference = "WeakReference: "; 48 static final String finalReference = "FinalReference: "; 49 static final String phantomReference = "PhantomReference: "; 50 static final String phase1 = "Phase1: "; 51 static final String phase2 = "Phase2: "; 52 static final String phase3 = "Phase3: "; 53 static final String gcLogTimeRegex = ".* GC\\([0-9]+\\) "; 54 static final String indent_2 = " "; 55 static final String indent_4 = " "; 56 57 public static void main(String[] args) throws Exception { 58 ProcessBuilder pb_enabled = ProcessTools.createJavaProcessBuilder("-Xlog:gc+phases+ref=debug", 59 "-XX:+UseG1GC", 60 "-Xmx32M", 61 // Explicit thread setting is required to avoid using only 1 thread 62 "-XX:ParallelGCThreads=2", 63 GCTest.class.getName()); 64 OutputAnalyzer output = new OutputAnalyzer(pb_enabled.start()); 65 66 checkLogFormat(output); 67 checkLogValue(output); 68 69 output.shouldHaveExitValue(0); 70 } 71 72 // Find the first Reference Processing log and check its format. 73 public static void checkLogFormat(OutputAnalyzer output) { 74 String indent_6 = " "; 75 String indent_8 = " "; 76 String countRegex = "[0-9]+"; 77 String timeRegex = doubleRegex + "ms"; 78 String totalRegex = gcLogTimeRegex + indent_4 + referenceProcessing + timeRegex + "\n"; 79 String balanceRegex = gcLogTimeRegex + indent_8 + "Balance queues: " + timeRegex + "\n"; 80 String softRefRegex = gcLogTimeRegex + indent_6 + softReference + timeRegex + "\n"; 81 String weakRefRegex = gcLogTimeRegex + indent_6 + weakReference + timeRegex + "\n"; 82 String finalRefRegex = gcLogTimeRegex + indent_6 + finalReference + timeRegex + "\n"; 83 String phantomRefRegex = gcLogTimeRegex + indent_6 + phantomReference + timeRegex + "\n"; 84 String refDetailRegex = gcLogTimeRegex + indent_8 + phase2 + timeRegex + "\n" + 85 gcLogTimeRegex + indent_8 + phase3 + timeRegex + "\n" + 86 gcLogTimeRegex + indent_8 + "Discovered: " + countRegex + "\n" + 87 gcLogTimeRegex + indent_8 + "Cleared: " + countRegex + "\n"; 88 String softRefDetailRegex = gcLogTimeRegex + indent_8 + phase1 + timeRegex + "\n" + refDetailRegex; 89 String enqueueRegex = gcLogTimeRegex + indent_4 + "Reference Enqueuing: " + timeRegex + "\n"; 90 String enqueueDetailRegex = gcLogTimeRegex + indent_6 + "Reference Counts: Soft: " + countRegex + 91 " Weak: " + countRegex + " Final: " + countRegex + " Phantom: " + countRegex + "\n"; 92 93 output.shouldMatch(/* Total Reference processing time */ 94 totalRegex + 95 /* SoftReference processing */ 96 softRefRegex + balanceRegex + softRefDetailRegex + 97 /* WeakReference processing */ 98 weakRefRegex + balanceRegex + refDetailRegex + 99 /* FinalReference processing */ 100 finalRefRegex + balanceRegex + refDetailRegex + 101 /* PhantomReference processing */ 102 phantomRefRegex + balanceRegex + refDetailRegex + 103 /* Total Enqueuing time */ 104 enqueueRegex + 105 /* Enqueued Stats */ 106 enqueueDetailRegex 107 ); 108 } 109 110 // After getting time value, update 'output' for next use. 111 public static double getTimeValue(String name) { 112 Matcher m = Pattern.compile(name + doubleRegex).matcher(output); 113 if (!m.find()) { 114 throw new RuntimeException("Could not find time log for " + name); 115 } 116 117 String match = m.group(); 118 119 // Skip the first timestamp and get elapsed time which starts with space. 120 m = Pattern.compile(" " + doubleRegex).matcher(match); 121 if (!m.find()) { 122 throw new RuntimeException("Could not find time log for " + doubleRegex); 123 } 124 double result = Double.parseDouble(m.group()); 125 126 int index = output.indexOf(match); 127 if (index != -1) { 128 output = output.substring(index, output.length()); 129 } 130 131 return result; 132 } 133 134 // Reference log is printing 1 decimal place of elapsed time. 135 // So sum of each sub-phases could be slightly larger than the enclosing phase in some cases. 136 // As the maximum of sub-phases is 3, allow 0.1 of TOLERANCE. 137 // e.g. Actual value: SoftReference(5.55) = phase1(1.85) + phase2(1.85) + phase3(1.85) 138 // Log value: SoftReference(5.6) = phase1(1.9) + phase2(1.9) + phase3(1.9) 139 // When checked: 5.6 < 5.7 (sum of phase1~3) 140 public static boolean approximatelyEqual(double a, double b) { 141 final double TOLERANCE = 0.1; 142 143 return Math.abs(a - b) <= TOLERANCE; 144 } 145 146 // Return false, if 'total' is larger and not approximately equal to 'refTime'. 147 public static boolean compare(double refTime, double total) { 148 return (refTime < total) && (!approximatelyEqual(refTime, total)); 149 } 150 151 public static double checkRefTime(String refType) { 152 double refTime = getTimeValue(gcLogTimeRegex + indent_2 + refType); 153 double total = 0.0; 154 155 if (softReference.equals(refType)) { 156 total += getTimeValue(gcLogTimeRegex + indent_4 + phase1); 157 } 158 total += getTimeValue(gcLogTimeRegex + indent_4 + phase2); 159 total += getTimeValue(gcLogTimeRegex + indent_4 + phase3); 160 161 if (compare(refTime, total)) { 162 throw new RuntimeException(refType.substring(0, refType.length()-2) +" time(" + refTime + 163 "ms) is less than the sum(" + total + "ms) of each phases"); 164 } 165 166 return refTime; 167 } 168 169 // Find the first concurrent Reference Processing log and compare sub-time vs. total. 170 public static void checkLogValue(OutputAnalyzer out) { 171 output = out.getStdout(); 172 173 double refProcTime = getTimeValue(gcLogTimeRegex + referenceProcessing); 174 175 double total = 0.0; 176 total += checkRefTime(softReference); 177 total += checkRefTime(weakReference); 178 total += checkRefTime(finalReference); 179 total += checkRefTime(phantomReference); 180 181 if (compare(refProcTime, total)) { 182 throw new RuntimeException("Reference Processing time(" + refProcTime + "ms) is less than the sum(" 183 + total + "ms) of each phases"); 184 } 185 } 186 187 static class GCTest { 188 static final int SIZE = 512 * 1024; 189 static Object[] dummy = new Object[SIZE]; 190 191 public static void main(String [] args) { 192 for (int i = 0; i < SIZE; i++) { 193 dummy[i] = new SoftReference<>(new Object()); 194 } 195 } 196 } 197 } |