Mercurial > hg > truffle

changeset 7558:223f645acb9b

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
added compilation rate measurements on top of existing metric/timer facility - enabled with -Dgraal.benchmark.compilation=true
author Doug Simon <doug.simon@oracle.com>
date Fri, 25 Jan 2013 16:05:11 +0100
parents db90c8b5a861
children f701f2ce0f59
files graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/CompilationTask.java graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/MetricRateInPhase.java graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompilerImpl.java graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/meta/HotSpotRuntime.java graal/com.oracle.graal.java/src/com/oracle/graal/java/GraphBuilderPhase.java graal/com.oracle.graal.phases.common/src/com/oracle/graal/phases/common/InliningUtil.java
diffstat 6 files changed, 162 insertions(+), 13 deletions(-) [+]
line wrap: on
line diff
--- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/CompilationTask.java	Fri Jan 25 15:31:54 2013 +0100
+++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/CompilationTask.java	Fri Jan 25 16:05:11 2013 +0100
@@ -23,12 +23,14 @@
 package com.oracle.graal.hotspot;
 
 import static com.oracle.graal.nodes.StructuredGraph.*;
+import static com.oracle.graal.phases.common.InliningUtil.*;
 
 import java.util.concurrent.*;
 
 import com.oracle.graal.api.code.*;
 import com.oracle.graal.api.meta.*;
 import com.oracle.graal.debug.*;
+import com.oracle.graal.debug.internal.*;
 import com.oracle.graal.graph.*;
 import com.oracle.graal.hotspot.meta.*;
 import com.oracle.graal.nodes.*;
@@ -112,9 +114,14 @@
         }
     }
 
+    /**
+     * Time spent in compilation.
+     */
+    public static final DebugTimer CompilationTime = Debug.timer("CompilationTime");
+
     public void runCompilation() {
         CompilationStatistics stats = CompilationStatistics.create(method, entryBCI != StructuredGraph.INVOCATION_ENTRY_BCI);
-        try {
+        try (TimerCloseable a = CompilationTime.start()) {
             final boolean printCompilation = GraalOptions.PrintCompilation && !TTY.isSuppressed();
             if (printCompilation) {
                 TTY.println(String.format("%-6d Graal %-70s %-45s %-50s %s...", id, method.getDeclaringClass().getName(), method.getName(), method.getSignature(),
@@ -138,6 +145,7 @@
                             graph = graph.copy();
                             // System.out.println("compiling intrinsic " + method);
                         }
+                        InlinedBytecodes.add(method.getCodeSize());
                         return graalRuntime.getCompiler().compileMethod(method, graph, graalRuntime.getCache(), plan, optimisticOpts);
                     }
                 });
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/MetricRateInPhase.java	Fri Jan 25 16:05:11 2013 +0100
@@ -0,0 +1,75 @@
+/*
+ * Copyright (c) 2013, 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 com.oracle.graal.hotspot.bridge;
+
+import java.util.concurrent.*;
+
+import com.oracle.graal.debug.*;
+import com.oracle.graal.debug.internal.*;
+
+/**
+ * The rate of accumulation for a metric within an execution phase.
+ */
+final class MetricRateInPhase {
+
+    private final String phase;
+    private final MetricRateInPhase previous;
+    private final long time;
+    private final long value;
+    private final TimeUnit timeUnit;
+
+    public static MetricRateInPhase snapshot(String phase, MetricRateInPhase previous, DebugMetric metric, DebugTimer timer, TimeUnit timeUnit) {
+        return new MetricRateInPhase(phase, previous, metric, timer, timeUnit);
+    }
+
+    private MetricRateInPhase(String phase, MetricRateInPhase previous, DebugMetric metric, DebugTimer timer, TimeUnit timeUnit) {
+        this.phase = phase;
+        this.previous = previous;
+        this.time = VMToCompilerImpl.collectTotal((DebugValue) timer);
+        this.value = VMToCompilerImpl.collectTotal((DebugValue) metric);
+        this.timeUnit = timeUnit;
+    }
+
+    public int rate() {
+        long t = time;
+        long v = value;
+        if (previous != null) {
+            t -= previous.time;
+            v -= previous.value;
+        }
+
+        t = timeUnit.convert(t, TimeUnit.NANOSECONDS);
+        if (t == 0) {
+            t = 1;
+        }
+        return (int) (v / t);
+    }
+
+    public void printAll(String label) {
+        MetricRateInPhase rs = this;
+        while (rs != null) {
+            System.out.println(label + "@" + rs.phase + ": " + rs.rate());
+            rs = rs.previous;
+        }
+    }
+}
--- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompilerImpl.java	Fri Jan 25 15:31:54 2013 +0100
+++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/bridge/VMToCompilerImpl.java	Fri Jan 25 16:05:11 2013 +0100
@@ -24,6 +24,9 @@
 package com.oracle.graal.hotspot.bridge;
 
 import static com.oracle.graal.graph.UnsafeAccess.*;
+import static com.oracle.graal.hotspot.CompilationTask.*;
+import static com.oracle.graal.java.GraphBuilderPhase.*;
+import static com.oracle.graal.phases.common.InliningUtil.*;
 
 import java.io.*;
 import java.lang.reflect.*;
@@ -53,6 +56,8 @@
 
     private final HotSpotGraalRuntime graalRuntime;
 
+    private static final boolean BenchmarkCompilation = Boolean.getBoolean("graal.benchmark.compilation");
+
     public final HotSpotResolvedPrimitiveType typeBoolean;
     public final HotSpotResolvedPrimitiveType typeChar;
     public final HotSpotResolvedPrimitiveType typeFloat;
@@ -121,6 +126,13 @@
             }
         }
 
+        if (BenchmarkCompilation) {
+            GraalOptions.Debug = true;
+            GraalOptions.Meter = "";
+            GraalOptions.Time = "";
+            GraalOptions.SummarizeDebugValues = true;
+        }
+
         if (GraalOptions.Debug) {
             Debug.enable();
             if (GraalOptions.DebugSnippets) {
@@ -147,6 +159,10 @@
 
         }
 
+        if (GraalOptions.DebugSnippets) {
+            phaseTransition("snippets");
+        }
+
         // Create compilation queue.
         BlockingQueue<Runnable> queue = GraalOptions.PriorityCompileQueue ? new PriorityBlockingQueue<Runnable>() : new LinkedBlockingQueue<Runnable>();
         compileQueue = new ThreadPoolExecutor(GraalOptions.Threads, GraalOptions.Threads, 0L, TimeUnit.MILLISECONDS, queue, CompilerThread.FACTORY);
@@ -181,6 +197,19 @@
     }
 
     /**
+     * Take action related to entering a new execution phase.
+     * 
+     * @param phase the execution phase being entered
+     */
+    protected void phaseTransition(String phase) {
+        CompilationStatistics.clear(phase);
+        if (BenchmarkCompilation) {
+            parsedBytecodesPerSecond = MetricRateInPhase.snapshot(phase, parsedBytecodesPerSecond, BytecodesParsed, CompilationTime, TimeUnit.SECONDS);
+            inlinedBytecodesPerSecond = MetricRateInPhase.snapshot(phase, inlinedBytecodesPerSecond, InlinedBytecodes, CompilationTime, TimeUnit.SECONDS);
+        }
+    }
+
+    /**
      * This method is the first method compiled during bootstrapping. Put any code in there that
      * warms up compiler paths that are otherwise not exercised during bootstrapping and lead to
      * later deoptimization when application code is compiled.
@@ -239,7 +268,9 @@
                 }
             }
         } while ((System.currentTimeMillis() - startTime) <= GraalOptions.TimedBootstrap);
-        CompilationStatistics.clear("bootstrap");
+
+        phaseTransition("bootstrap");
+
         bootstrapRunning = false;
 
         TTY.println(" in %d ms", System.currentTimeMillis() - startTime);
@@ -247,9 +278,12 @@
             graalRuntime.getCache().clear();
         }
         System.gc();
-        CompilationStatistics.clear("bootstrap2");
+        phaseTransition("bootstrap2");
     }
 
+    private MetricRateInPhase parsedBytecodesPerSecond;
+    private MetricRateInPhase inlinedBytecodesPerSecond;
+
     private void enqueue(Method m) throws Throwable {
         JavaMethod javaMethod = graalRuntime.getRuntime().lookupJavaMethod(m);
         assert !Modifier.isAbstract(((HotSpotResolvedJavaMethod) javaMethod).getModifiers()) && !Modifier.isNative(((HotSpotResolvedJavaMethod) javaMethod).getModifiers()) : javaMethod;
@@ -298,9 +332,7 @@
                         if (GraalOptions.SummarizePerPhase) {
                             flattenChildren(map, globalMap);
                         } else {
-                            for (DebugValueMap child : map.getChildren()) {
-                                globalMap.addChild(child);
-                            }
+                            globalMap.addChild(map);
                         }
                     }
                     if (!GraalOptions.SummarizePerPhase) {
@@ -311,7 +343,11 @@
                 }
             }
         }
-        CompilationStatistics.clear("final");
+        phaseTransition("final");
+
+        parsedBytecodesPerSecond.printAll("ParsedBytecodesPerSecond");
+        inlinedBytecodesPerSecond.printAll("InlinedBytecodesPerSecond");
+
         SnippetCounter.printGroups(TTY.out().out());
     }
 
@@ -334,6 +370,18 @@
         printMap(result, debugValues, 0);
     }
 
+    static long collectTotal(DebugValue value) {
+        List<DebugValueMap> maps = DebugValueMap.getTopLevelMaps();
+        long total = 0;
+        for (int i = 0; i < maps.size(); i++) {
+            DebugValueMap map = maps.get(i);
+            int index = value.getIndex();
+            total += map.getCurrentValue(index);
+            total += collectTotal(map.getChildren(), index);
+        }
+        return total;
+    }
+
     private static long collectTotal(List<DebugValueMap> maps, int index) {
         long total = 0;
         for (int i = 0; i < maps.size(); i++) {
--- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/meta/HotSpotRuntime.java	Fri Jan 25 15:31:54 2013 +0100
+++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/meta/HotSpotRuntime.java	Fri Jan 25 16:05:11 2013 +0100
@@ -22,6 +22,7 @@
  */
 package com.oracle.graal.hotspot.meta;
 
+import static com.oracle.graal.api.code.CallingConvention.Type.*;
 import static com.oracle.graal.api.code.DeoptimizationAction.*;
 import static com.oracle.graal.api.code.MemoryBarriers.*;
 import static com.oracle.graal.api.code.Register.RegisterFlag.*;
@@ -29,12 +30,11 @@
 import static com.oracle.graal.api.meta.Value.*;
 import static com.oracle.graal.hotspot.HotSpotGraalRuntime.*;
 import static com.oracle.graal.hotspot.snippets.SystemSubstitutions.*;
-import static com.oracle.graal.java.GraphBuilderPhase.*;
+import static com.oracle.graal.java.GraphBuilderPhase.RuntimeCalls.*;
 import static com.oracle.graal.nodes.UnwindNode.*;
 import static com.oracle.graal.nodes.java.RegisterFinalizerNode.*;
 import static com.oracle.graal.snippets.Log.*;
 import static com.oracle.graal.snippets.MathSubstitutionsX86.*;
-import static com.oracle.graal.api.code.CallingConvention.Type.*;
 
 import java.lang.reflect.*;
 import java.util.*;
--- a/graal/com.oracle.graal.java/src/com/oracle/graal/java/GraphBuilderPhase.java	Fri Jan 25 15:31:54 2013 +0100
+++ b/graal/com.oracle.graal.java/src/com/oracle/graal/java/GraphBuilderPhase.java	Fri Jan 25 16:05:11 2013 +0100
@@ -54,8 +54,11 @@
  */
 public final class GraphBuilderPhase extends Phase {
 
-    public static final Descriptor CREATE_NULL_POINTER_EXCEPTION = new Descriptor("createNullPointerException", true, Object.class);
-    public static final Descriptor CREATE_OUT_OF_BOUNDS_EXCEPTION = new Descriptor("createOutOfBoundsException", true, Object.class, int.class);
+    public static final class RuntimeCalls {
+
+        public static final Descriptor CREATE_NULL_POINTER_EXCEPTION = new Descriptor("createNullPointerException", true, Object.class);
+        public static final Descriptor CREATE_OUT_OF_BOUNDS_EXCEPTION = new Descriptor("createOutOfBoundsException", true, Object.class, int.class);
+    }
 
     /**
      * The minimum value to which {@link GraalOptions#TraceBytecodeParserLevel} must be set to trace
@@ -94,6 +97,11 @@
     private long graphId;
 
     /**
+     * Meters the number of actual bytecodes parsed.
+     */
+    public static final DebugMetric BytecodesParsed = Debug.metric("BytecodesParsed");
+
+    /**
      * Node that marks the begin of block during bytecode parsing. When a block is identified the
      * first time as a jump target, the placeholder is created and used as the successor for the
      * jump. When the block is seen the second time, a MergeNode is created to correctly merge the
@@ -833,7 +841,7 @@
             ValueNode exception = ConstantNode.forObject(cachedNullPointerException, runtime, currentGraph);
             trueSucc.setNext(handleException(exception, bci()));
         } else {
-            RuntimeCallNode call = currentGraph.add(new RuntimeCallNode(CREATE_NULL_POINTER_EXCEPTION));
+            RuntimeCallNode call = currentGraph.add(new RuntimeCallNode(RuntimeCalls.CREATE_NULL_POINTER_EXCEPTION));
             call.setStateAfter(frameState.create(bci()));
             trueSucc.setNext(call);
             call.setNext(handleException(call, bci()));
@@ -859,7 +867,7 @@
             ValueNode exception = ConstantNode.forObject(cachedArrayIndexOutOfBoundsException, runtime, currentGraph);
             falseSucc.setNext(handleException(exception, bci()));
         } else {
-            RuntimeCallNode call = currentGraph.add(new RuntimeCallNode(CREATE_OUT_OF_BOUNDS_EXCEPTION, index));
+            RuntimeCallNode call = currentGraph.add(new RuntimeCallNode(RuntimeCalls.CREATE_OUT_OF_BOUNDS_EXCEPTION, index));
             call.setStateAfter(frameState.create(bci()));
             falseSucc.setNext(call);
             call.setNext(handleException(call, bci()));
@@ -1587,6 +1595,8 @@
 
         stream.setBCI(block.startBci);
         int bci = block.startBci;
+        BytecodesParsed.add(block.endBci - bci);
+
         while (bci < endBCI) {
             // read the opcode
             int opcode = stream.currentBC();
--- a/graal/com.oracle.graal.phases.common/src/com/oracle/graal/phases/common/InliningUtil.java	Fri Jan 25 15:31:54 2013 +0100
+++ b/graal/com.oracle.graal.phases.common/src/com/oracle/graal/phases/common/InliningUtil.java	Fri Jan 25 16:05:11 2013 +0100
@@ -48,6 +48,13 @@
     private static final DebugMetric metricInliningTailDuplication = Debug.metric("InliningTailDuplication");
     private static final String inliningDecisionsScopeString = "InliningDecisions";
 
+    /**
+     * Meters the size (in bytecodes) of all methods processed during compilation (i.e., top level and all
+     * inlined methods), irrespective of how many bytecodes in each method are actually parsed
+     * (which may be none for methods whose IR is retrieved from a cache).
+     */
+    public static final DebugMetric InlinedBytecodes = Debug.metric("InlinedBytecodes");
+
     public interface InliningCallback {
 
         StructuredGraph buildGraph(final ResolvedJavaMethod method);
@@ -243,6 +250,7 @@
                 if (calleeGraph == null) {
                     calleeGraph = getGraph(concrete, callback);
                 }
+                InlinedBytecodes.add(concrete.getCodeSize());
                 assumptions.recordMethodContents(concrete);
                 InliningUtil.inline(invoke, calleeGraph, receiverNullCheck);
             }