--- /dev/null 2016-05-31 09:42:47.975716356 -0700 +++ new/src/jdk.vm.compiler/share/classes/org.graalvm.compiler.hotspot/src/org/graalvm/compiler/hotspot/debug/BenchmarkCounters.java 2016-12-09 00:49:22.501012659 -0800 @@ -0,0 +1,452 @@ +/* + * Copyright (c) 2013, 2014, 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. + */ +package org.graalvm.compiler.hotspot.debug; + +import java.io.FileNotFoundException; +import java.io.IOException; +import java.io.OutputStream; +import java.io.PrintStream; +import java.nio.file.Path; +import java.util.Iterator; +import java.util.Locale; +import java.util.Map; +import java.util.Map.Entry; +import java.util.Set; +import java.util.TreeMap; +import java.util.TreeSet; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.atomic.AtomicLong; + +import org.graalvm.compiler.core.common.SuppressFBWarnings; +import org.graalvm.compiler.debug.CSVUtil; +import org.graalvm.compiler.debug.GraalDebugConfig; +import org.graalvm.compiler.debug.GraalError; +import org.graalvm.compiler.debug.TTY; +import org.graalvm.compiler.hotspot.GraalHotSpotVMConfig; +import org.graalvm.compiler.hotspot.replacements.HotspotSnippetsOptions; +import org.graalvm.compiler.nodes.debug.DynamicCounterNode; +import org.graalvm.compiler.options.Option; +import org.graalvm.compiler.options.OptionType; +import org.graalvm.compiler.options.OptionValue; +import org.graalvm.compiler.options.StableOptionValue; +import org.graalvm.compiler.options.UniquePathUtilities; + +import jdk.vm.ci.hotspot.HotSpotJVMCIRuntime; + +//JaCoCo Exclude + +/** + * This class contains infrastructure to maintain counters based on {@link DynamicCounterNode}s. The + * infrastructure is enabled by specifying either the GenericDynamicCounters or + * BenchmarkDynamicCounters option. + *

+ * + * The counters are kept in a special area allocated for each native JavaThread object, and the + * number of counters is configured using {@code -XX:JVMCICounterSize=value}. + * {@code -XX:+/-JVMCICountersExcludeCompiler} configures whether to exclude compiler threads + * (defaults to true). + * + * The subsystems that use the logging need to have their own options to turn on the counters, and + * insert DynamicCounterNodes when they're enabled. + * + * Counters will be displayed as a rate (per second) if their group name starts with "~", otherwise + * they will be displayed as a total number. + * + *

Example

In order to create statistics about allocations within the DaCapo pmd benchmark + * the following steps are necessary: + * + */ +public class BenchmarkCounters { + + static class Options { + + //@formatter:off + @Option(help = "Turn on the benchmark counters, and displays the results on VM shutdown", type = OptionType.Debug) + public static final OptionValue GenericDynamicCounters = new OptionValue<>(false); + @Option(help = "Turn on the benchmark counters, and displays the results every n milliseconds", type = OptionType.Debug) + public static final OptionValue TimedDynamicCounters = new OptionValue<>(-1); + + @Option(help = "Turn on the benchmark counters, and listen for specific patterns on System.out/System.err:%n" + + "Format: (err|out),start pattern,end pattern (~ matches multiple digits)%n" + + "Examples:%n" + + " dacapo = 'err, starting =====, PASSED in'%n" + + " specjvm2008 = 'out,Iteration ~ (~s) begins:,Iteration ~ (~s) ends:'", type = OptionType.Debug) + public static final OptionValue BenchmarkDynamicCounters = new OptionValue<>(null); + @Option(help = "Use grouping separators for number printing", type = OptionType.Debug) + public static final OptionValue DynamicCountersPrintGroupSeparator = new OptionValue<>(true); + @Option(help = "Print in human readable format", type = OptionType.Debug) + public static final OptionValue DynamicCountersHumanReadable = new OptionValue<>(true); + @Option(help = "Benchmark counters log file (default is stdout)", type = OptionType.Debug) + public static final OptionValue BenchmarkCountersFile = new OptionValue<>(null); + @Option(help = "Dump dynamic counters", type = OptionType.Debug) + public static final StableOptionValue BenchmarkCountersDumpDynamic = new StableOptionValue<>(true); + @Option(help = "Dump static counters", type = OptionType.Debug) + public static final StableOptionValue BenchmarkCountersDumpStatic = new StableOptionValue<>(false); + //@formatter:on + } + + public static boolean enabled = false; + + private static class Counter { + public final int index; + public final String group; + public final AtomicLong staticCounters; + + Counter(int index, String group, AtomicLong staticCounters) { + this.index = index; + this.group = group; + this.staticCounters = staticCounters; + } + } + + public static final ConcurrentHashMap counterMap = new ConcurrentHashMap<>(); + public static long[] delta; + + public static int getIndexConstantIncrement(String name, String group, GraalHotSpotVMConfig config, long increment) { + Counter counter = getCounter(name, group, config); + counter.staticCounters.addAndGet(increment); + return counter.index; + } + + public static int getIndex(String name, String group, GraalHotSpotVMConfig config) { + Counter counter = getCounter(name, group, config); + return counter.index; + } + + @SuppressFBWarnings(value = "AT_OPERATION_SEQUENCE_ON_CONCURRENT_ABSTRACTION", justification = "concurrent abstraction calls are in synchronized block") + private static Counter getCounter(String name, String group, GraalHotSpotVMConfig config) throws GraalError { + if (!enabled) { + throw new GraalError("cannot access count index when counters are not enabled: " + group + ", " + name); + } + String nameGroup = name + "#" + group; + Counter counter = counterMap.get(nameGroup); + if (counter == null) { + synchronized (BenchmarkCounters.class) { + counter = counterMap.get(nameGroup); + if (counter == null) { + counter = new Counter(counterMap.size(), group, new AtomicLong()); + counterMap.put(nameGroup, counter); + } + } + } + assert counter.group.equals(group) : "mismatching groups: " + counter.group + " vs. " + group; + int countersSize = config.jvmciCountersSize; + if (counter.index >= countersSize) { + throw new GraalError("too many counters, reduce number of counters or increase -XX:JVMCICounterSize=... (current value: " + countersSize + ")"); + } + return counter; + } + + private static synchronized void dump(PrintStream out, double seconds, long[] counters, int maxRows) { + if (!counterMap.isEmpty()) { + if (Options.DynamicCountersHumanReadable.getValue()) { + out.println("====== dynamic counters (" + counterMap.size() + " in total) ======"); + } + TreeSet set = new TreeSet<>(); + counterMap.forEach((nameGroup, counter) -> set.add(counter.group)); + for (String group : set) { + if (group != null) { + if (Options.BenchmarkCountersDumpStatic.getValue()) { + dumpCounters(out, seconds, counters, true, group, maxRows); + } + if (Options.BenchmarkCountersDumpDynamic.getValue()) { + dumpCounters(out, seconds, counters, false, group, maxRows); + } + } + } + if (Options.DynamicCountersHumanReadable.getValue()) { + out.println("============================"); + } + + clear(counters); + } + } + + private static synchronized void clear(long[] counters) { + delta = counters; + } + + private static synchronized void dumpCounters(PrintStream out, double seconds, long[] counters, boolean staticCounter, String group, int maxRows) { + + // collect the numbers + long[] array; + if (staticCounter) { + array = new long[counterMap.size()]; + for (Counter counter : counterMap.values()) { + array[counter.index] = counter.staticCounters.get(); + } + } else { + array = counters.clone(); + for (int i = 0; i < array.length; i++) { + array[i] -= delta[i]; + } + } + Set> counterEntrySet = counterMap.entrySet(); + if (Options.DynamicCountersHumanReadable.getValue()) { + dumpHumanReadable(out, seconds, staticCounter, group, maxRows, array, counterEntrySet); + } else { + dumpComputerReadable(out, staticCounter, group, array, counterEntrySet); + } + } + + private static String getName(String nameGroup, String group) { + return nameGroup.substring(0, nameGroup.length() - group.length() - 1); + } + + private static void dumpHumanReadable(PrintStream out, double seconds, boolean staticCounter, String group, int maxRows, long[] array, Set> counterEntrySet) { + // sort the counters by putting them into a sorted map + TreeMap sorted = new TreeMap<>(); + long sum = 0; + for (Map.Entry entry : counterEntrySet) { + Counter counter = entry.getValue(); + int index = counter.index; + if (counter.group.equals(group)) { + sum += array[index]; + sorted.put(array[index] * array.length + index, getName(entry.getKey(), group)); + } + } + + if (sum > 0) { + long cutoff = sorted.size() < 10 ? 1 : Math.max(1, sum / 100); + int cnt = sorted.size(); + + // remove everything below cutoff and keep at most maxRows + Iterator> iter = sorted.entrySet().iterator(); + while (iter.hasNext()) { + Map.Entry entry = iter.next(); + long counter = entry.getKey() / array.length; + if (counter < cutoff || cnt > maxRows) { + iter.remove(); + } + cnt--; + } + + String numFmt = Options.DynamicCountersPrintGroupSeparator.getValue() ? "%,19d" : "%19d"; + if (staticCounter) { + out.println("=========== " + group + " (static counters):"); + for (Map.Entry entry : sorted.entrySet()) { + long counter = entry.getKey() / array.length; + out.format(Locale.US, numFmt + " %3d%% %s\n", counter, percentage(counter, sum), entry.getValue()); + } + out.format(Locale.US, numFmt + " total\n", sum); + } else { + if (group.startsWith("~")) { + out.println("=========== " + group + " (dynamic counters), time = " + seconds + " s:"); + for (Map.Entry entry : sorted.entrySet()) { + long counter = entry.getKey() / array.length; + out.format(Locale.US, numFmt + "/s %3d%% %s\n", (long) (counter / seconds), percentage(counter, sum), entry.getValue()); + } + out.format(Locale.US, numFmt + "/s total\n", (long) (sum / seconds)); + } else { + out.println("=========== " + group + " (dynamic counters):"); + for (Map.Entry entry : sorted.entrySet()) { + long counter = entry.getKey() / array.length; + out.format(Locale.US, numFmt + " %3d%% %s\n", counter, percentage(counter, sum), entry.getValue()); + } + out.format(Locale.US, numFmt + " total\n", sum); + } + } + } + } + + private static final String CSV_FMT = CSVUtil.buildFormatString("%s", "%s", "%s", "%d"); + + private static void dumpComputerReadable(PrintStream out, boolean staticCounter, String group, long[] array, Set> counterEntrySet) { + String category = staticCounter ? "static counters" : "dynamic counters"; + for (Map.Entry entry : counterEntrySet) { + Counter counter = entry.getValue(); + if (counter.group.equals(group)) { + String name = getName(entry.getKey(), group); + int index = counter.index; + long value = array[index]; + CSVUtil.Escape.println(out, CSV_FMT, category, group, name, value); + } + } + } + + private static long percentage(long counter, long sum) { + return (counter * 200 + 1) / sum / 2; + } + + private abstract static class CallbackOutputStream extends OutputStream { + + protected final PrintStream delegate; + private final byte[][] patterns; + private final int[] positions; + + CallbackOutputStream(PrintStream delegate, String... patterns) { + this.delegate = delegate; + this.positions = new int[patterns.length]; + this.patterns = new byte[patterns.length][]; + for (int i = 0; i < patterns.length; i++) { + this.patterns[i] = patterns[i].getBytes(); + } + } + + protected abstract void patternFound(int index); + + @Override + public void write(int b) throws IOException { + try { + delegate.write(b); + for (int i = 0; i < patterns.length; i++) { + int j = positions[i]; + byte[] cs = patterns[i]; + byte patternChar = cs[j]; + if (patternChar == '~' && Character.isDigit(b)) { + // nothing to do... + } else { + if (patternChar == '~') { + patternChar = cs[++positions[i]]; + } + if (b == patternChar) { + positions[i]++; + } else { + positions[i] = 0; + } + } + if (positions[i] == patterns[i].length) { + positions[i] = 0; + patternFound(i); + } + } + } catch (RuntimeException e) { + e.printStackTrace(delegate); + throw e; + } + } + } + + public static void initialize(final HotSpotJVMCIRuntime jvmciRuntime) { + final class BenchmarkCountersOutputStream extends CallbackOutputStream { + + private long startTime; + private boolean running; + private boolean waitingForEnd; + + private BenchmarkCountersOutputStream(PrintStream delegate, String start, String end) { + super(delegate, new String[]{"\n", end, start}); + } + + @Override + protected void patternFound(int index) { + switch (index) { + case 2: + startTime = System.nanoTime(); + BenchmarkCounters.clear(jvmciRuntime.collectCounters()); + running = true; + break; + case 1: + if (running) { + waitingForEnd = true; + } + break; + case 0: + if (waitingForEnd) { + waitingForEnd = false; + running = false; + BenchmarkCounters.dump(getPrintStream(), (System.nanoTime() - startTime) / 1000000000d, jvmciRuntime.collectCounters(), 100); + } + break; + } + } + } + + if (Options.BenchmarkDynamicCounters.getValue() != null) { + String[] arguments = Options.BenchmarkDynamicCounters.getValue().split(","); + if (arguments.length == 0 || (arguments.length % 3) != 0) { + throw new GraalError("invalid arguments to BenchmarkDynamicCounters: (err|out),start,end,(err|out),start,end,... (~ matches multiple digits)"); + } + for (int i = 0; i < arguments.length; i += 3) { + if (arguments[i].equals("err")) { + System.setErr(new PrintStream(new BenchmarkCountersOutputStream(System.err, arguments[i + 1], arguments[i + 2]))); + } else if (arguments[i].equals("out")) { + System.setOut(new PrintStream(new BenchmarkCountersOutputStream(System.out, arguments[i + 1], arguments[i + 2]))); + } else { + throw new GraalError("invalid arguments to BenchmarkDynamicCounters: err|out"); + } + } + enabled = true; + } + if (Options.GenericDynamicCounters.getValue()) { + enabled = true; + } + if (Options.TimedDynamicCounters.getValue() > 0) { + Thread thread = new Thread() { + long lastTime = System.nanoTime(); + PrintStream out = getPrintStream(); + + @Override + public void run() { + while (true) { + try { + Thread.sleep(Options.TimedDynamicCounters.getValue()); + } catch (InterruptedException e) { + } + long time = System.nanoTime(); + dump(out, (time - lastTime) / 1000000000d, jvmciRuntime.collectCounters(), 10); + lastTime = time; + } + } + }; + thread.setDaemon(true); + thread.setPriority(Thread.MAX_PRIORITY); + thread.start(); + enabled = true; + } + if (enabled) { + clear(jvmciRuntime.collectCounters()); + } + } + + public static void shutdown(HotSpotJVMCIRuntime jvmciRuntime, long compilerStartTime) { + if (Options.GenericDynamicCounters.getValue()) { + dump(getPrintStream(), (System.nanoTime() - compilerStartTime) / 1000000000d, jvmciRuntime.collectCounters(), 100); + } + } + + private static PrintStream getPrintStream() { + if (Options.BenchmarkCountersFile.getValue() != null) { + try { + Path path = UniquePathUtilities.getPathGlobal(Options.BenchmarkCountersFile, GraalDebugConfig.Options.DumpPath, "csv"); + TTY.println("Writing benchmark counters to '%s'", path); + return new PrintStream(path.toFile()); + } catch (FileNotFoundException e) { + TTY.out().println(e.getMessage()); + TTY.out().println("Fallback to default"); + } + } + return TTY.out; + } +}