/*
 * 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 DynamicCounterNodes. 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 -XX:JVMCICounterSize=value. -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:
  • Set -XX:JVMCICounterSize=value. The actual required value depends on the granularity of the profiling, 10000 should be enough for most cases.
  • Also: -XX:+/-JVMCICountersExcludeCompiler specifies whether the numbers generated by compiler threads should be excluded (default: true).
  • Start the DaCapo pmd benchmark with "-Dgraal.BenchmarkDynamicCounters=err, starting ====, PASSED in " and -Dgraal.ProfileAllocations=true.
  • The numbers will only include allocation from compiled code!
  • The counters can be further configured by modifying the HotspotSnippetsOptions.ProfileAllocationsContext flag..
/** * This class contains infrastructure to maintain counters based on {@link DynamicCounterNode}s. The * infrastructure is enabled by specifying either the GenericDynamicCounters or * BenchmarkDynamicCounters option. * <p> * * 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. * * <h1>Example</h1> In order to create statistics about allocations within the DaCapo pmd benchmark * the following steps are necessary: * <ul> * <li>Set {@code -XX:JVMCICounterSize=value}. The actual required value depends on the granularity * of the profiling, 10000 should be enough for most cases.</li> * <li>Also: {@code -XX:+/-JVMCICountersExcludeCompiler} specifies whether the numbers generated by * compiler threads should be excluded (default: true).</li> * <li>Start the DaCapo pmd benchmark with * {@code "-Dgraal.BenchmarkDynamicCounters=err, starting ====, PASSED in "} and * {@code -Dgraal.ProfileAllocations=true}.</li> * <li>The numbers will only include allocation from compiled code!</li> * <li>The counters can be further configured by modifying the * {@link HotspotSnippetsOptions#ProfileAllocationsContext} flag..</li> * </ul> */
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<Boolean> 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<Integer> 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<String> BenchmarkDynamicCounters = new OptionValue<>(null); @Option(help = "Use grouping separators for number printing", type = OptionType.Debug) public static final OptionValue<Boolean> DynamicCountersPrintGroupSeparator = new OptionValue<>(true); @Option(help = "Print in human readable format", type = OptionType.Debug) public static final OptionValue<Boolean> DynamicCountersHumanReadable = new OptionValue<>(true); @Option(help = "Benchmark counters log file (default is stdout)", type = OptionType.Debug) public static final OptionValue<String> BenchmarkCountersFile = new OptionValue<>(null); @Option(help = "Dump dynamic counters", type = OptionType.Debug) public static final StableOptionValue<Boolean> BenchmarkCountersDumpDynamic = new StableOptionValue<>(true); @Option(help = "Dump static counters", type = OptionType.Debug) public static final StableOptionValue<Boolean> 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<String, Counter> 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<String> 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<Entry<String, Counter>> 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<Entry<String, Counter>> counterEntrySet) { // sort the counters by putting them into a sorted map TreeMap<Long, String> sorted = new TreeMap<>(); long sum = 0; for (Map.Entry<String, Counter> 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<Map.Entry<Long, String>> iter = sorted.entrySet().iterator(); while (iter.hasNext()) { Map.Entry<Long, String> 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<Long, String> 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<Long, String> 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<Long, String> 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<Entry<String, Counter>> counterEntrySet) { String category = staticCounter ? "static counters" : "dynamic counters"; for (Map.Entry<String, Counter> 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; } }