changeset 1440:ae08c0b9db44

7902097: dtraceasm profiler for Mac OS X Contributed-by: Vsevolod Tolstopyatov <qwwdfsad@gmail.com>
author shade
date Mon, 22 Jan 2018 18:04:43 +0100
parents 6d51e8e924d0
children a5079769b73b
files jmh-core/src/main/java/org/openjdk/jmh/profile/AbstractPerfAsmProfiler.java jmh-core/src/main/java/org/openjdk/jmh/profile/DTraceAsmProfiler.java jmh-core/src/main/java/org/openjdk/jmh/profile/ProfilerFactory.java jmh-core/src/main/java/org/openjdk/jmh/util/Utils.java jmh-samples/src/main/java/org/openjdk/jmh/samples/JMHSample_35_Profilers.java
diffstat 5 files changed, 257 insertions(+), 12 deletions(-) [+]
line wrap: on
line diff
--- a/jmh-core/src/main/java/org/openjdk/jmh/profile/AbstractPerfAsmProfiler.java	Mon Jan 22 17:50:08 2018 +0100
+++ b/jmh-core/src/main/java/org/openjdk/jmh/profile/AbstractPerfAsmProfiler.java	Mon Jan 22 18:04:43 2018 +0100
@@ -270,7 +270,7 @@
 
     @Override
     public Collection<? extends Result> afterTrial(BenchmarkResult br, long pid, File stdOut, File stdErr) {
-        PerfResult result = processAssembly(br, stdOut, stdErr);
+        PerfResult result = processAssembly(br);
 
         // we know these are not needed anymore, proactively delete
         hsLog.delete();
@@ -311,7 +311,7 @@
      */
     protected abstract String perfBinaryExtension();
 
-    private PerfResult processAssembly(BenchmarkResult br, File stdOut, File stdErr) {
+    private PerfResult processAssembly(BenchmarkResult br) {
         /**
          * 1. Parse binary events.
          */
@@ -647,11 +647,11 @@
         }
     }
 
-    void printDottedLine(PrintWriter pw) {
+    private void printDottedLine(PrintWriter pw) {
         printDottedLine(pw, null);
     }
 
-    void printDottedLine(PrintWriter pw, String header) {
+    private void printDottedLine(PrintWriter pw, String header) {
         final int HEADER_WIDTH = 100;
 
         pw.print("....");
@@ -668,7 +668,7 @@
         pw.println();
     }
 
-    List<Region> makeRegions(Assembly asms, PerfEvents events) {
+    private List<Region> makeRegions(Assembly asms, PerfEvents events) {
         List<Region> regions = new ArrayList<>();
 
         SortedSet<Long> allAddrs = events.getAllAddresses();
@@ -728,7 +728,7 @@
         return intervals;
     }
 
-    Collection<Collection<String>> splitAssembly(File stdOut) {
+    private Collection<Collection<String>> splitAssembly(File stdOut) {
         try (FileReader in = new FileReader(stdOut);
              BufferedReader br = new BufferedReader(in)) {
             Multimap<Long, String> writerToLines = new HashMultimap<>();
@@ -764,7 +764,7 @@
         }
     }
 
-    Assembly readAssembly(File stdOut) {
+    private Assembly readAssembly(File stdOut) {
         List<ASMLine> lines = new ArrayList<>();
         SortedMap<Long, Integer> addressMap = new TreeMap<>();
 
@@ -919,11 +919,11 @@
     static class PerfResultAggregator implements Aggregator<PerfResult> {
         @Override
         public PerfResult aggregate(Collection<PerfResult> results) {
-            String output = "";
+            StringBuilder output = new StringBuilder();
             for (PerfResult r : results) {
-                output += r.output;
+                output.append(r.output);
             }
-            return new PerfResult(output);
+            return new PerfResult(output.toString());
         }
     }
 
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/jmh-core/src/main/java/org/openjdk/jmh/profile/DTraceAsmProfiler.java	Mon Jan 22 18:04:43 2018 +0100
@@ -0,0 +1,218 @@
+/*
+ * Copyright (c) 2014, 2015, 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.  Oracle designates this
+ * particular file as subject to the "Classpath" exception as provided
+ * by Oracle in the LICENSE file that accompanied this code.
+ *
+ * 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.openjdk.jmh.profile;
+
+import joptsimple.OptionException;
+import joptsimple.OptionParser;
+import joptsimple.OptionSpec;
+import org.openjdk.jmh.infra.BenchmarkParams;
+import org.openjdk.jmh.results.BenchmarkResult;
+import org.openjdk.jmh.results.Result;
+import org.openjdk.jmh.util.*;
+
+import java.io.BufferedReader;
+import java.io.File;
+import java.io.FileReader;
+import java.io.IOException;
+import java.util.Collection;
+import java.util.Collections;
+import java.util.Map;
+import java.util.TreeMap;
+import java.util.concurrent.TimeUnit;
+
+/**
+ * Mac OS X perfasm profiler based on DTrace "profile-n" provider which samples program counter by timer interrupt.
+ * Due to DTrace limitations on Mac OS X target JVM cannot be run directly under DTrace control, so DTrace is run separately,
+ * all processes are sampled and irrelevant samples are filtered out in {@link #readEvents(double, double)} stage.
+ * Super user privileges are required in order to run DTrace.
+ * <p>
+ * If you see a lot of "[unknown]" regions in profile then you are probably hitting kernel code, kernel sampling is not yet supported.
+ *
+ * @author Tolstopyatov Vsevolod
+ * @since 18/10/2017
+ */
+public class DTraceAsmProfiler extends AbstractPerfAsmProfiler {
+
+    private final long sampleFrequency;
+    private volatile String pid;
+    private volatile Process dtraceProcess;
+    private OptionSpec<Long> optFrequency;
+
+    public DTraceAsmProfiler(String initLine) throws ProfilerException {
+        super(initLine, "sampled_pc");
+
+        // Check DTrace availability
+        Collection<String> messages = Utils.tryWith("sudo", "dtrace", "-V");
+        if (!messages.isEmpty()) {
+            throw new ProfilerException(messages.toString());
+        }
+
+        try {
+            sampleFrequency = set.valueOf(optFrequency);
+        } catch (OptionException e) {
+            throw new ProfilerException(e.getMessage());
+        }
+    }
+
+    @Override
+    public void beforeTrial(BenchmarkParams params) {
+        super.beforeTrial(params);
+    }
+
+    @Override
+    public Collection<? extends Result> afterTrial(BenchmarkResult br, long pid, File stdOut, File stdErr) {
+        if (pid == 0) {
+            throw new IllegalStateException("DTrace needs the forked VM PID, but it is not initialized");
+        }
+
+        Collection<String> messages = Utils.destroy(dtraceProcess);
+        if (!messages.isEmpty()) {
+            throw new IllegalStateException(messages.toString());
+        }
+
+        this.pid = String.valueOf(pid);
+        return super.afterTrial(br, pid, stdOut, stdErr);
+    }
+
+    @Override
+    public Collection<String> addJVMInvokeOptions(BenchmarkParams params) {
+        dtraceProcess = Utils.runAsync("sudo", "dtrace", "-n", "profile-" + sampleFrequency +
+                        " /arg1/ { printf(\"%d 0x%lx %d\", pid, arg1, timestamp); ufunc(arg1)}", "-o",
+                perfBinData.getAbsolutePath());
+        return Collections.emptyList();
+    }
+
+    @Override
+    public String getDescription() {
+        return "DTrace profile provider + PrintAssembly Profiler";
+    }
+
+    @Override
+    protected void addMyOptions(OptionParser parser) {
+        optFrequency = parser.accepts("frequency",
+                "Sampling frequency. This is synonymous to profile-#")
+                .withRequiredArg().ofType(Long.class).describedAs("freq").defaultsTo(1001L);
+    }
+
+    @Override
+    protected void parseEvents() {
+        // Do nothing because DTrace writes text output anyway
+    }
+
+    @Override
+    protected PerfEvents readEvents(double skipMs, double lenMs) {
+        long start = (long) skipMs;
+        long end = (long) (skipMs + lenMs);
+
+        try (FileReader fr = new FileReader(perfBinData.file());
+             BufferedReader reader = new BufferedReader(fr)) {
+
+            Deduplicator<MethodDesc> dedup = new Deduplicator<>();
+            Multimap<MethodDesc, Long> methods = new HashMultimap<>();
+            Multiset<Long> events = new TreeMultiset<>();
+
+            long dtraceTimestampBase = 0L;
+            String line;
+            while ((line = reader.readLine()) != null) {
+
+                // Filter out DTrace misc
+                if (!line.contains(":profile")) {
+                    continue;
+                }
+
+                line = line.trim();
+                line = line.substring(line.indexOf(":profile"));
+                String[] splits = line.split(" ", 5);
+                String sampledPid = splits[1];
+
+                if (!sampledPid.equals(pid)) {
+                    continue;
+                }
+
+                // Sometimes DTrace ufunc fails and gives no information about symbols
+                if (splits.length < 4) {
+                    continue;
+                }
+
+                long timestamp = Long.valueOf(splits[3]);
+                if (dtraceTimestampBase == 0) {
+                    // Use first event timestamp as base for time comparison
+                    dtraceTimestampBase = timestamp;
+                    continue;
+                }
+
+                long elapsed = timestamp - dtraceTimestampBase;
+                long elapsedMs = TimeUnit.NANOSECONDS.toMillis(elapsed);
+
+                if (elapsedMs < start || elapsedMs > end) {
+                    continue;
+                }
+
+                long address = Long.decode(splits[2]);
+                events.add(address);
+
+                String methodLine = splits[4];
+                // JIT-compiled code has address instead of symbol information
+                if (methodLine.startsWith("0x")) {
+                    continue;
+                }
+
+                String symbol = "[unknown]";
+                String[] methodSplit = methodLine.split("`");
+                String library = methodSplit[0];
+                if ("".equals(library)) {
+                    library = "[unknown]";
+                }
+
+                if (methodSplit.length == 2) {
+                    symbol = methodSplit[1];
+                }
+
+                methods.put(dedup.dedup(MethodDesc.nativeMethod(symbol, library)), address);
+            }
+
+            IntervalMap<MethodDesc> methodMap = new IntervalMap<>();
+            for (MethodDesc md : methods.keys()) {
+                Collection<Long> longs = methods.get(md);
+                methodMap.add(md, Utils.min(longs), Utils.max(longs));
+            }
+
+            Map<String, Multiset<Long>> allEvents = new TreeMap<>();
+            assert this.events.size() == 1;
+            allEvents.put(this.events.get(0), events);
+            return new PerfEvents(this.events, allEvents, methodMap);
+
+        } catch (IOException e) {
+            return new PerfEvents(events);
+        }
+
+    }
+
+    @Override
+    protected String perfBinaryExtension() {
+        // DTrace produces human-readable txt
+        return ".txt";
+    }
+}
--- a/jmh-core/src/main/java/org/openjdk/jmh/profile/ProfilerFactory.java	Mon Jan 22 17:50:08 2018 +0100
+++ b/jmh-core/src/main/java/org/openjdk/jmh/profile/ProfilerFactory.java	Mon Jan 22 18:04:43 2018 +0100
@@ -27,7 +27,6 @@
 import org.openjdk.jmh.runner.options.ProfilerConfig;
 
 import java.io.PrintStream;
-import java.lang.reflect.Constructor;
 import java.lang.reflect.InvocationTargetException;
 import java.util.*;
 
@@ -178,6 +177,7 @@
         BUILT_IN.put("perfnorm", LinuxPerfNormProfiler.class);
         BUILT_IN.put("perfasm",  LinuxPerfAsmProfiler.class);
         BUILT_IN.put("xperfasm", WinPerfAsmProfiler.class);
+        BUILT_IN.put("dtraceasm", DTraceAsmProfiler.class);
         BUILT_IN.put("pauses",   PausesProfiler.class);
         BUILT_IN.put("safepoints", SafepointsProfiler.class);
     }
--- a/jmh-core/src/main/java/org/openjdk/jmh/util/Utils.java	Mon Jan 22 17:50:08 2018 +0100
+++ b/jmh-core/src/main/java/org/openjdk/jmh/util/Utils.java	Mon Jan 22 18:04:43 2018 +0100
@@ -446,6 +446,31 @@
         return messages;
     }
 
+    public static Process runAsync(String... cmd) {
+        try {
+            return new ProcessBuilder(cmd).start();
+        } catch (IOException ex) {
+            throw new IllegalStateException(ex);
+        }
+    }
+
+    public static Collection<String> destroy(Process process) {
+        Collection<String> messages = new ArrayList<>();
+        try {
+            ByteArrayOutputStream baos = new ByteArrayOutputStream();
+            process.destroy();
+            int exitCode = process.waitFor();
+            if (exitCode == 0) {
+                return Collections.emptyList();
+            }
+
+            messages.add(baos.toString());
+            return messages;
+        } catch (InterruptedException e) {
+            throw new IllegalStateException(e);
+        }
+    }
+
     public static Collection<String> runWith(List<String> cmd) {
         Collection<String> messages = new ArrayList<>();
         try {
--- a/jmh-samples/src/main/java/org/openjdk/jmh/samples/JMHSample_35_Profilers.java	Mon Jan 22 17:50:08 2018 +0100
+++ b/jmh-samples/src/main/java/org/openjdk/jmh/samples/JMHSample_35_Profilers.java	Mon Jan 22 18:04:43 2018 +0100
@@ -33,6 +33,7 @@
 import org.openjdk.jmh.annotations.*;
 import org.openjdk.jmh.infra.Blackhole;
 import org.openjdk.jmh.profile.ClassloaderProfiler;
+import org.openjdk.jmh.profile.DTraceAsmProfiler;
 import org.openjdk.jmh.profile.LinuxPerfProfiler;
 import org.openjdk.jmh.profile.StackProfiler;
 import org.openjdk.jmh.runner.Runner;
@@ -352,7 +353,7 @@
          *    $ java -jar target/benchmarks.jar JMHSample_35.*Atomic -prof perfnorm -f 3 (Linux)
          *    $ java -jar target/benchmarks.jar JMHSample_35.*Atomic -prof perfasm  -f 1 (Linux)
          *    $ java -jar target/benchmarks.jar JMHSample_35.*Atomic -prof xperfasm -f 1 (Windows)
-         *
+         *    $ java -jar target/benchmarks.jar JMHSample_35.*Atomic -prof dtraceasm -f 1 (Mac OS X)
          * b) Via the Java API:
          *    (see the JMH homepage for possible caveats when running from IDE:
          *      http://openjdk.java.net/projects/code-tools/jmh/)
@@ -365,6 +366,7 @@
 //                    .addProfiler(LinuxPerfNormProfiler.class)
 //                    .addProfiler(LinuxPerfAsmProfiler.class)
 //                    .addProfiler(WinPerfAsmProfiler.class)
+//                    .addProfiler(DTraceAsmProfiler.class)
                     .build();
 
             new Runner(opt).run();