1 /* 2 * Copyright (c) 2013, 2014, 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 package org.graalvm.compiler.hotspot.debug; 24 25 import java.io.FileNotFoundException; 26 import java.io.IOException; 27 import java.io.OutputStream; 28 import java.io.PrintStream; 29 import java.nio.file.Path; 30 import java.util.Iterator; 31 import java.util.Locale; 32 import java.util.Map; 33 import java.util.Map.Entry; 34 import java.util.Set; 35 import java.util.TreeMap; 36 import java.util.TreeSet; 37 import java.util.concurrent.ConcurrentHashMap; 38 import java.util.concurrent.atomic.AtomicLong; 39 40 import org.graalvm.compiler.core.common.SuppressFBWarnings; 41 import org.graalvm.compiler.debug.CSVUtil; 42 import org.graalvm.compiler.debug.GraalDebugConfig; 43 import org.graalvm.compiler.debug.GraalError; 44 import org.graalvm.compiler.debug.TTY; 45 import org.graalvm.compiler.hotspot.GraalHotSpotVMConfig; 46 import org.graalvm.compiler.hotspot.replacements.HotspotSnippetsOptions; 47 import org.graalvm.compiler.nodes.debug.DynamicCounterNode; 48 import org.graalvm.compiler.options.Option; 49 import org.graalvm.compiler.options.OptionKey; 50 import org.graalvm.compiler.options.OptionType; 51 import org.graalvm.compiler.options.OptionValues; 52 import org.graalvm.compiler.options.UniquePathUtilities; 53 54 import jdk.vm.ci.hotspot.HotSpotJVMCIRuntime; 55 56 //JaCoCo Exclude 57 58 /** 59 * This class contains infrastructure to maintain counters based on {@link DynamicCounterNode}s. The 60 * infrastructure is enabled by specifying either the GenericDynamicCounters or 61 * BenchmarkDynamicCounters option. 62 * <p> 63 * 64 * The counters are kept in a special area allocated for each native JavaThread object, and the 65 * number of counters is configured using {@code -XX:JVMCICounterSize=value}. 66 * {@code -XX:+/-JVMCICountersExcludeCompiler} configures whether to exclude compiler threads 67 * (defaults to true). 68 * 69 * The subsystems that use the logging need to have their own options to turn on the counters, and 70 * insert DynamicCounterNodes when they're enabled. 71 * 72 * Counters will be displayed as a rate (per second) if their group name starts with "~", otherwise 73 * they will be displayed as a total number. 74 * 75 * <h1>Example</h1> In order to create statistics about allocations within the DaCapo pmd benchmark 76 * the following steps are necessary: 77 * <ul> 78 * <li>Set {@code -XX:JVMCICounterSize=value}. The actual required value depends on the granularity 79 * of the profiling, 10000 should be enough for most cases.</li> 80 * <li>Also: {@code -XX:+/-JVMCICountersExcludeCompiler} specifies whether the numbers generated by 81 * compiler threads should be excluded (default: true).</li> 82 * <li>Start the DaCapo pmd benchmark with 83 * {@code "-Dgraal.BenchmarkDynamicCounters=err, starting ====, PASSED in "} and 84 * {@code -Dgraal.ProfileAllocations=true}.</li> 85 * <li>The numbers will only include allocation from compiled code!</li> 86 * <li>The counters can be further configured by modifying the 87 * {@link HotspotSnippetsOptions#ProfileAllocationsContext} flag..</li> 88 * </ul> 89 */ 90 public class BenchmarkCounters { 91 92 static class Options { 93 94 //@formatter:off 95 @Option(help = "Turn on the benchmark counters, and displays the results on VM shutdown", type = OptionType.Debug) 96 public static final OptionKey<Boolean> GenericDynamicCounters = new OptionKey<>(false); 97 @Option(help = "Turn on the benchmark counters, and displays the results every n milliseconds", type = OptionType.Debug) 98 public static final OptionKey<Integer> TimedDynamicCounters = new OptionKey<>(-1); 99 100 @Option(help = "Turn on the benchmark counters, and listen for specific patterns on System.out/System.err:%n" + 101 "Format: (err|out),start pattern,end pattern (~ matches multiple digits)%n" + 102 "Examples:%n" + 103 " dacapo = 'err, starting =====, PASSED in'%n" + 104 " specjvm2008 = 'out,Iteration ~ (~s) begins:,Iteration ~ (~s) ends:'", type = OptionType.Debug) 105 public static final OptionKey<String> BenchmarkDynamicCounters = new OptionKey<>(null); 106 @Option(help = "Use grouping separators for number printing", type = OptionType.Debug) 107 public static final OptionKey<Boolean> DynamicCountersPrintGroupSeparator = new OptionKey<>(true); 108 @Option(help = "Print in human readable format", type = OptionType.Debug) 109 public static final OptionKey<Boolean> DynamicCountersHumanReadable = new OptionKey<>(true); 110 @Option(help = "Benchmark counters log file (default is stdout)", type = OptionType.Debug) 111 public static final OptionKey<String> BenchmarkCountersFile = new OptionKey<>(null); 112 @Option(help = "Dump dynamic counters", type = OptionType.Debug) 113 public static final OptionKey<Boolean> BenchmarkCountersDumpDynamic = new OptionKey<>(true); 114 @Option(help = "Dump static counters", type = OptionType.Debug) 115 public static final OptionKey<Boolean> BenchmarkCountersDumpStatic = new OptionKey<>(false); 116 //@formatter:on 117 } 118 119 public static boolean enabled = false; 120 121 private static class Counter { 122 public final int index; 123 public final String group; 124 public final AtomicLong staticCounters; 125 126 Counter(int index, String group, AtomicLong staticCounters) { 127 this.index = index; 128 this.group = group; 129 this.staticCounters = staticCounters; 130 } 131 } 132 133 public static final ConcurrentHashMap<String, Counter> counterMap = new ConcurrentHashMap<>(); 134 public static long[] delta; 135 136 public static int getIndexConstantIncrement(String name, String group, GraalHotSpotVMConfig config, long increment) { 137 Counter counter = getCounter(name, group, config); 138 counter.staticCounters.addAndGet(increment); 139 return counter.index; 140 } 141 142 public static int getIndex(String name, String group, GraalHotSpotVMConfig config) { 143 Counter counter = getCounter(name, group, config); 144 return counter.index; 145 } 146 147 @SuppressFBWarnings(value = "AT_OPERATION_SEQUENCE_ON_CONCURRENT_ABSTRACTION", justification = "concurrent abstraction calls are in synchronized block") 148 private static Counter getCounter(String name, String group, GraalHotSpotVMConfig config) throws GraalError { 149 if (!enabled) { 150 throw new GraalError("cannot access count index when counters are not enabled: " + group + ", " + name); 151 } 152 String nameGroup = name + "#" + group; 153 Counter counter = counterMap.get(nameGroup); 154 if (counter == null) { 155 synchronized (BenchmarkCounters.class) { 156 counter = counterMap.get(nameGroup); 157 if (counter == null) { 158 counter = new Counter(counterMap.size(), group, new AtomicLong()); 159 counterMap.put(nameGroup, counter); 160 } 161 } 162 } 163 assert counter.group.equals(group) : "mismatching groups: " + counter.group + " vs. " + group; 164 int countersSize = config.jvmciCountersSize; 165 if (counter.index >= countersSize) { 166 throw new GraalError("too many counters, reduce number of counters or increase -XX:JVMCICounterSize=... (current value: " + countersSize + ")"); 167 } 168 return counter; 169 } 170 171 private static synchronized void dump(OptionValues options, PrintStream out, double seconds, long[] counters, int maxRows) { 172 if (!counterMap.isEmpty()) { 173 if (Options.DynamicCountersHumanReadable.getValue(options)) { 174 out.println("====== dynamic counters (" + counterMap.size() + " in total) ======"); 175 } 176 TreeSet<String> set = new TreeSet<>(); 177 counterMap.forEach((nameGroup, counter) -> set.add(counter.group)); 178 for (String group : set) { 179 if (group != null) { 180 if (Options.BenchmarkCountersDumpStatic.getValue(options)) { 181 dumpCounters(options, out, seconds, counters, true, group, maxRows); 182 } 183 if (Options.BenchmarkCountersDumpDynamic.getValue(options)) { 184 dumpCounters(options, out, seconds, counters, false, group, maxRows); 185 } 186 } 187 } 188 if (Options.DynamicCountersHumanReadable.getValue(options)) { 189 out.println("============================"); 190 } 191 192 clear(counters); 193 } 194 } 195 196 private static synchronized void clear(long[] counters) { 197 delta = counters; 198 } 199 200 private static synchronized void dumpCounters(OptionValues options, PrintStream out, double seconds, long[] counters, boolean staticCounter, String group, int maxRows) { 201 202 // collect the numbers 203 long[] array; 204 if (staticCounter) { 205 array = new long[counterMap.size()]; 206 for (Counter counter : counterMap.values()) { 207 array[counter.index] = counter.staticCounters.get(); 208 } 209 } else { 210 array = counters.clone(); 211 for (int i = 0; i < array.length; i++) { 212 array[i] -= delta[i]; 213 } 214 } 215 Set<Entry<String, Counter>> counterEntrySet = counterMap.entrySet(); 216 if (Options.DynamicCountersHumanReadable.getValue(options)) { 217 dumpHumanReadable(options, out, seconds, staticCounter, group, maxRows, array, counterEntrySet); 218 } else { 219 dumpComputerReadable(out, staticCounter, group, array, counterEntrySet); 220 } 221 } 222 223 private static String getName(String nameGroup, String group) { 224 return nameGroup.substring(0, nameGroup.length() - group.length() - 1); 225 } 226 227 private static void dumpHumanReadable(OptionValues options, PrintStream out, double seconds, boolean staticCounter, String group, int maxRows, long[] array, 228 Set<Entry<String, Counter>> counterEntrySet) { 229 // sort the counters by putting them into a sorted map 230 TreeMap<Long, String> sorted = new TreeMap<>(); 231 long sum = 0; 232 for (Map.Entry<String, Counter> entry : counterEntrySet) { 233 Counter counter = entry.getValue(); 234 int index = counter.index; 235 if (counter.group.equals(group)) { 236 sum += array[index]; 237 sorted.put(array[index] * array.length + index, getName(entry.getKey(), group)); 238 } 239 } 240 241 if (sum > 0) { 242 long cutoff = sorted.size() < 10 ? 1 : Math.max(1, sum / 100); 243 int cnt = sorted.size(); 244 245 // remove everything below cutoff and keep at most maxRows 246 Iterator<Map.Entry<Long, String>> iter = sorted.entrySet().iterator(); 247 while (iter.hasNext()) { 248 Map.Entry<Long, String> entry = iter.next(); 249 long counter = entry.getKey() / array.length; 250 if (counter < cutoff || cnt > maxRows) { 251 iter.remove(); 252 } 253 cnt--; 254 } 255 256 String numFmt = Options.DynamicCountersPrintGroupSeparator.getValue(options) ? "%,19d" : "%19d"; 257 if (staticCounter) { 258 out.println("=========== " + group + " (static counters):"); 259 for (Map.Entry<Long, String> entry : sorted.entrySet()) { 260 long counter = entry.getKey() / array.length; 261 out.format(Locale.US, numFmt + " %3d%% %s\n", counter, percentage(counter, sum), entry.getValue()); 262 } 263 out.format(Locale.US, numFmt + " total\n", sum); 264 } else { 265 if (group.startsWith("~")) { 266 out.println("=========== " + group + " (dynamic counters), time = " + seconds + " s:"); 267 for (Map.Entry<Long, String> entry : sorted.entrySet()) { 268 long counter = entry.getKey() / array.length; 269 out.format(Locale.US, numFmt + "/s %3d%% %s\n", (long) (counter / seconds), percentage(counter, sum), entry.getValue()); 270 } 271 out.format(Locale.US, numFmt + "/s total\n", (long) (sum / seconds)); 272 } else { 273 out.println("=========== " + group + " (dynamic counters):"); 274 for (Map.Entry<Long, String> entry : sorted.entrySet()) { 275 long counter = entry.getKey() / array.length; 276 out.format(Locale.US, numFmt + " %3d%% %s\n", counter, percentage(counter, sum), entry.getValue()); 277 } 278 out.format(Locale.US, numFmt + " total\n", sum); 279 } 280 } 281 } 282 } 283 284 private static final String CSV_FMT = CSVUtil.buildFormatString("%s", "%s", "%s", "%d"); 285 286 private static void dumpComputerReadable(PrintStream out, boolean staticCounter, String group, long[] array, Set<Entry<String, Counter>> counterEntrySet) { 287 String category = staticCounter ? "static counters" : "dynamic counters"; 288 for (Map.Entry<String, Counter> entry : counterEntrySet) { 289 Counter counter = entry.getValue(); 290 if (counter.group.equals(group)) { 291 String name = getName(entry.getKey(), group); 292 int index = counter.index; 293 long value = array[index]; 294 CSVUtil.Escape.println(out, CSV_FMT, category, group, name, value); 295 } 296 } 297 } 298 299 private static long percentage(long counter, long sum) { 300 return (counter * 200 + 1) / sum / 2; 301 } 302 303 private abstract static class CallbackOutputStream extends OutputStream { 304 305 protected final PrintStream delegate; 306 private final byte[][] patterns; 307 private final int[] positions; 308 309 CallbackOutputStream(PrintStream delegate, String... patterns) { 310 this.delegate = delegate; 311 this.positions = new int[patterns.length]; 312 this.patterns = new byte[patterns.length][]; 313 for (int i = 0; i < patterns.length; i++) { 314 this.patterns[i] = patterns[i].getBytes(); 315 } 316 } 317 318 protected abstract void patternFound(int index); 319 320 @Override 321 public void write(int b) throws IOException { 322 try { 323 delegate.write(b); 324 for (int i = 0; i < patterns.length; i++) { 325 int j = positions[i]; 326 byte[] cs = patterns[i]; 327 byte patternChar = cs[j]; 328 if (patternChar == '~' && Character.isDigit(b)) { 329 // nothing to do... 330 } else { 331 if (patternChar == '~') { 332 patternChar = cs[++positions[i]]; 333 } 334 if (b == patternChar) { 335 positions[i]++; 336 } else { 337 positions[i] = 0; 338 } 339 } 340 if (positions[i] == patterns[i].length) { 341 positions[i] = 0; 342 patternFound(i); 343 } 344 } 345 } catch (RuntimeException e) { 346 e.printStackTrace(delegate); 347 throw e; 348 } 349 } 350 } 351 352 public static void initialize(final HotSpotJVMCIRuntime jvmciRuntime, OptionValues options) { 353 final class BenchmarkCountersOutputStream extends CallbackOutputStream { 354 355 private long startTime; 356 private boolean running; 357 private boolean waitingForEnd; 358 359 private BenchmarkCountersOutputStream(PrintStream delegate, String start, String end) { 360 super(delegate, new String[]{"\n", end, start}); 361 } 362 363 @Override 364 protected void patternFound(int index) { 365 switch (index) { 366 case 2: 367 startTime = System.nanoTime(); 368 BenchmarkCounters.clear(jvmciRuntime.collectCounters()); 369 running = true; 370 break; 371 case 1: 372 if (running) { 373 waitingForEnd = true; 374 } 375 break; 376 case 0: 377 if (waitingForEnd) { 378 waitingForEnd = false; 379 running = false; 380 BenchmarkCounters.dump(options, getPrintStream(options), (System.nanoTime() - startTime) / 1000000000d, jvmciRuntime.collectCounters(), 100); 381 } 382 break; 383 } 384 } 385 } 386 387 if (Options.BenchmarkDynamicCounters.getValue(options) != null) { 388 String[] arguments = Options.BenchmarkDynamicCounters.getValue(options).split(","); 389 if (arguments.length == 0 || (arguments.length % 3) != 0) { 390 throw new GraalError("invalid arguments to BenchmarkDynamicCounters: (err|out),start,end,(err|out),start,end,... (~ matches multiple digits)"); 391 } 392 for (int i = 0; i < arguments.length; i += 3) { 393 if (arguments[i].equals("err")) { 394 System.setErr(new PrintStream(new BenchmarkCountersOutputStream(System.err, arguments[i + 1], arguments[i + 2]))); 395 } else if (arguments[i].equals("out")) { 396 System.setOut(new PrintStream(new BenchmarkCountersOutputStream(System.out, arguments[i + 1], arguments[i + 2]))); 397 } else { 398 throw new GraalError("invalid arguments to BenchmarkDynamicCounters: err|out"); 399 } 400 } 401 enabled = true; 402 } 403 if (Options.GenericDynamicCounters.getValue(options)) { 404 enabled = true; 405 } 406 if (Options.TimedDynamicCounters.getValue(options) > 0) { 407 Thread thread = new Thread() { 408 long lastTime = System.nanoTime(); 409 PrintStream out = getPrintStream(options); 410 411 @Override 412 public void run() { 413 while (true) { 414 try { 415 Thread.sleep(Options.TimedDynamicCounters.getValue(options)); 416 } catch (InterruptedException e) { 417 } 418 long time = System.nanoTime(); 419 dump(options, out, (time - lastTime) / 1000000000d, jvmciRuntime.collectCounters(), 10); 420 lastTime = time; 421 } 422 } 423 }; 424 thread.setDaemon(true); 425 thread.setPriority(Thread.MAX_PRIORITY); 426 thread.start(); 427 enabled = true; 428 } 429 if (enabled) { 430 clear(jvmciRuntime.collectCounters()); 431 } 432 } 433 434 public static void shutdown(HotSpotJVMCIRuntime jvmciRuntime, OptionValues options, long compilerStartTime) { 435 if (Options.GenericDynamicCounters.getValue(options)) { 436 dump(options, getPrintStream(options), (System.nanoTime() - compilerStartTime) / 1000000000d, jvmciRuntime.collectCounters(), 100); 437 } 438 } 439 440 private static PrintStream getPrintStream(OptionValues options) { 441 if (Options.BenchmarkCountersFile.getValue(options) != null) { 442 try { 443 Path path = UniquePathUtilities.getPathGlobal(options, Options.BenchmarkCountersFile, GraalDebugConfig.Options.DumpPath, "csv"); 444 TTY.println("Writing benchmark counters to '%s'", path); 445 return new PrintStream(path.toFile()); 446 } catch (FileNotFoundException e) { 447 TTY.out().println(e.getMessage()); 448 TTY.out().println("Fallback to default"); 449 } 450 } 451 return TTY.out; 452 } 453 }