Mercurial > hg > truffle
changeset 18200:62de94d5cf73
Truffle: refactor implementation of TraceTruffleCompilation, TraceTruffleCompilationDetails into separate classes.
line wrap: on
line diff
--- a/graal/com.oracle.graal.truffle.hotspot/src/com/oracle/graal/truffle/hotspot/HotSpotTruffleRuntime.java Mon Oct 27 13:42:21 2014 +0100 +++ b/graal/com.oracle.graal.truffle.hotspot/src/com/oracle/graal/truffle/hotspot/HotSpotTruffleRuntime.java Mon Oct 27 15:18:14 2014 +0100 @@ -79,6 +79,8 @@ installOptimizedCallTargetCallDirect(); lookupCallMethods(getGraalProviders().getMetaAccess()); + installDefaultListeners(); + // Create compilation queue. CompilerThreadFactory factory = new CompilerThreadFactory("TruffleCompilerThread", new CompilerThreadFactory.DebugConfigAccess() { public GraalDebugConfig getDebugConfig() { @@ -92,6 +94,7 @@ } }); compileQueue = new ThreadPoolExecutor(1, 1, 0L, TimeUnit.MILLISECONDS, new LinkedBlockingQueue<Runnable>(), factory); + } private static void installOptimizedCallTargetCallDirect() {
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/GraalTruffleRuntime.java Mon Oct 27 13:42:21 2014 +0100 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/GraalTruffleRuntime.java Mon Oct 27 15:18:14 2014 +0100 @@ -56,6 +56,12 @@ Runtime.getRuntime().addShutdownHook(new Thread(this::shutdown)); } + protected void installDefaultListeners() { + TraceCompilationFailureListener.install(this); + TraceCompilationListener.install(this); + TraceCompilationPolymorphismListener.install(this); + } + protected void lookupCallMethods(MetaAccessProvider metaAccess) { callNodeMethod = new ResolvedJavaMethod[]{metaAccess.lookupJavaMethod(GraalFrameInstance.CallNodeFrame.METHOD)}; callTargetMethod = new ResolvedJavaMethod[]{metaAccess.lookupJavaMethod(GraalFrameInstance.CallTargetFrame.METHOD)};
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/OptimizedCallTarget.java Mon Oct 27 13:42:21 2014 +0100 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/OptimizedCallTarget.java Mon Oct 27 15:18:14 2014 +0100 @@ -291,12 +291,8 @@ this.inlining = inliningDecision; } - private boolean cancelInstalledTask(Node oldNode, Node newNode, CharSequence reason) { - boolean cancelled = this.runtime.cancelInstalledTask(this, newNode, reason); - if (cancelled) { - notifyCompilationDequeued(oldNode, newNode, reason); - } - return cancelled; + private boolean cancelInstalledTask(Node source, CharSequence reason) { + return this.runtime.cancelInstalledTask(this, source, reason); } private void interpreterCall() { @@ -314,28 +310,16 @@ public void compile() { if (!runtime.isCompiling(this)) { - notifyCompilationQueued(); runtime.compile(this, TruffleBackgroundCompilation.getValue() && !TruffleCompilationExceptionsAreThrown.getValue()); } } - public void notifyCompilationQueued() { - logOptimizingQueued(this); - } - - public void notifyCompilationDequeued(Node oldNode, Node newNode, CharSequence reason) { - logOptimizingUnqueued(this, oldNode, newNode, reason); - } - public void notifyCompilationFailed(Throwable t) { if (!(t instanceof BailoutException) || ((BailoutException) t).isPermanent()) { compilationPolicy.recordCompilationFailure(t); - logOptimizingFailed(this, t.toString()); if (TruffleCompilationExceptionsAreThrown.getValue()) { throw new OptimizationFailedException(t, this); } - } else { - logOptimizingUnqueued(this, null, null, "Non permanent bailout: " + t.toString()); } if (t instanceof BailoutException) { @@ -357,7 +341,7 @@ for (TruffleInliningDecision decision : parentDecision) { if (decision.isInline()) { OptimizedCallTarget target = decision.getTarget(); - target.cancelInstalledTask(decision.getProfile().getCallNode(), decision.getProfile().getCallNode(), "Inlining caller compiled."); + target.cancelInstalledTask(decision.getProfile().getCallNode(), "Inlining caller compiled."); dequeueInlinedCallSites(decision); } } @@ -435,13 +419,12 @@ if (isValid()) { CompilerAsserts.neverPartOfCompilation(); invalidate(newNode, reason); - logOptimizedInvalidated(this, oldNode, newNode, reason); } /* Notify compiled method that have inlined this call target that the tree changed. */ nodeRewritingAssumption.invalidate(); compilationProfile.reportNodeReplaced(); - if (cancelInstalledTask(oldNode, newNode, reason)) { + if (cancelInstalledTask(newNode, reason)) { compilationProfile.reportInvalidated(); } }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/OptimizedCallTargetLog.java Mon Oct 27 13:42:21 2014 +0100 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/OptimizedCallTargetLog.java Mon Oct 27 15:18:14 2014 +0100 @@ -32,7 +32,7 @@ import com.oracle.graal.debug.*; import com.oracle.graal.truffle.TruffleInlining.CallTreeNodeVisitor; import com.oracle.truffle.api.*; -import com.oracle.truffle.api.nodes.*; +import com.oracle.truffle.api.nodes.Node; public final class OptimizedCallTargetLog { @@ -130,69 +130,6 @@ } } - public static void logOptimizingQueued(OptimizedCallTarget target) { - if (TraceTruffleCompilationDetails.getValue()) { - log(0, "opt queued", target.toString(), target.getDebugProperties()); - } - } - - public static void logOptimizingUnqueued(OptimizedCallTarget target, Node oldNode, Node newNode, CharSequence reason) { - if (TraceTruffleCompilationDetails.getValue()) { - Map<String, Object> properties = new LinkedHashMap<>(); - addReplaceProperties(properties, oldNode, newNode); - properties.put("Reason", reason); - log(0, "opt unqueued", target.toString(), properties); - } - } - - private static void addReplaceProperties(Map<String, Object> properties, Node oldNode, Node newNode) { - if (oldNode != null && newNode != null) { - properties.put("OldClass", oldNode.getClass().getSimpleName()); - properties.put("NewClass", newNode.getClass().getSimpleName()); - properties.put("Node", newNode); - } - } - - static void logOptimizingStart(OptimizedCallTarget target) { - if (TraceTruffleCompilationDetails.getValue()) { - log(0, "opt start", target.toString(), target.getDebugProperties()); - } - } - - public static void logOptimizedInvalidated(OptimizedCallTarget target, Node oldNode, Node newNode, CharSequence reason) { - if (TraceTruffleCompilation.getValue()) { - Map<String, Object> properties = new LinkedHashMap<>(); - addReplaceProperties(properties, oldNode, newNode); - properties.put("Reason", reason); - log(0, "opt invalidated", target.toString(), properties); - } - } - - public static void logOptimizingFailed(OptimizedCallTarget callSite, CharSequence reason) { - Map<String, Object> properties = new LinkedHashMap<>(); - properties.put("Reason", reason); - log(0, "opt fail", callSite.toString(), properties); - } - - public static void logOptimizingDone(OptimizedCallTarget target, Map<String, Object> properties) { - if (TraceTruffleCompilationDetails.getValue() || TraceTruffleCompilation.getValue()) { - log(0, "opt done", target.toString(), properties); - } - if (TraceTruffleCompilationPolymorphism.getValue()) { - // @formatter:off - target.nodeStream(true).filter(node -> node != null && (node.getCost() == NodeCost.MEGAMORPHIC || node.getCost() == NodeCost.POLYMORPHIC)). - forEach(node -> { - NodeCost cost = node.getCost(); - Map<String, Object> props = new LinkedHashMap<>(); - props.put("simpleName", node.getClass().getSimpleName()); - props.put("subtree", "\n" + NodeUtil.printCompactTreeToString(node)); - String msg = cost == NodeCost.MEGAMORPHIC ? "megamorphic" : "polymorphic"; - log(0, msg, node.toString(), props); - }); - // @formatter:on - } - } - private static int splitCount = 0; static void logSplit(OptimizedDirectCallNode callNode, OptimizedCallTarget target, OptimizedCallTarget newTarget) {
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/TruffleCompilerImpl.java Mon Oct 27 13:42:21 2014 +0100 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/TruffleCompilerImpl.java Mon Oct 27 15:18:14 2014 +0100 @@ -50,7 +50,6 @@ import com.oracle.graal.truffle.nodes.*; import com.oracle.truffle.api.*; import com.oracle.truffle.api.nodes.*; -import com.oracle.truffle.api.source.*; /** * Implementation of the Truffle compiler using Graal. @@ -113,12 +112,7 @@ compilationNotify.notifyCompilationStarted(compilable); - if (TraceTruffleCompilation.getValue()) { - OptimizedCallTargetLog.logOptimizingStart(compilable); - } - try { - long timeCompilationStarted = System.nanoTime(); Assumptions assumptions = new Assumptions(true); try (TimerCloseable a = PartialEvaluationTime.start(); Closeable c = PartialEvaluationMemUse.start()) { @@ -131,14 +125,7 @@ compilationNotify.notifyCompilationTruffleTierFinished(compilable, graph); - long timePartialEvaluationFinished = System.nanoTime(); - int nodeCountPartialEval = graph.getNodeCount(); CompilationResult compilationResult = compileMethodHelper(graph, assumptions, compilable.toString(), compilable.getSpeculationLog(), compilable); - long timeCompilationFinished = System.nanoTime(); - int nodeCountLowered = graph.getNodeCount(); - if (TraceTruffleCompilation.getValue()) { - printTruffleCompilation(compilable, timeCompilationStarted, timePartialEvaluationFinished, nodeCountPartialEval, compilationResult, timeCompilationFinished, nodeCountLowered); - } if (TraceTruffleCompilationAST.getValue()) { OptimizedCallUtils.printCompactTree(OptimizedCallTarget.OUT, compilable); } @@ -156,40 +143,6 @@ } } - private static void printTruffleCompilation(final OptimizedCallTarget compilable, long timeCompilationStarted, long timePartialEvaluationFinished, int nodeCountPartialEval, - CompilationResult compilationResult, long timeCompilationFinished, int nodeCountLowered) { - - TruffleInlining inlining = compilable.getInlining(); - - int calls; - int inlinedCalls; - if (inlining == null) { - calls = (int) compilable.nodeStream(false).filter(node -> (node instanceof OptimizedDirectCallNode)).count(); - inlinedCalls = 0; - } else { - calls = inlining.countCalls(); - inlinedCalls = inlining.countInlinedCalls(); - } - - int dispatchedCalls = calls - inlinedCalls; - Map<String, Object> properties = new LinkedHashMap<>(); - OptimizedCallTargetLog.addASTSizeProperty(compilable, properties); - properties.put("Time", String.format("%5.0f(%4.0f+%-4.0f)ms", // - (timeCompilationFinished - timeCompilationStarted) / 1e6, // - (timePartialEvaluationFinished - timeCompilationStarted) / 1e6, // - (timeCompilationFinished - timePartialEvaluationFinished) / 1e6)); - properties.put("DirectCallNodes", String.format("I %4d/D %4d", inlinedCalls, dispatchedCalls)); - properties.put("GraalNodes", String.format("%5d/%5d", nodeCountPartialEval, nodeCountLowered)); - properties.put("CodeSize", compilationResult.getTargetCodeSize()); - properties.put("Source", formatSourceSection(compilable.getRootNode().getSourceSection())); - - OptimizedCallTargetLog.logOptimizingDone(compilable, properties); - } - - private static String formatSourceSection(SourceSection sourceSection) { - return sourceSection != null ? sourceSection.getShortDescription() : "n/a"; - } - public CompilationResult compileMethodHelper(StructuredGraph graph, Assumptions assumptions, String name, SpeculationLog speculationLog, InstalledCode predefinedInstalledCode) { try (Scope s = Debug.scope("TruffleFinal")) { Debug.dump(1, graph, "After TruffleTier");
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/AbstractDebugCompilationListener.java Mon Oct 27 15:18:14 2014 +0100 @@ -0,0 +1,83 @@ +package com.oracle.graal.truffle.debug; + +import java.io.*; +import java.util.*; + +import com.oracle.graal.api.code.*; +import com.oracle.graal.debug.*; +import com.oracle.graal.nodes.*; +import com.oracle.graal.truffle.*; +import com.oracle.truffle.api.*; + +public class AbstractDebugCompilationListener implements GraalTruffleCompilationListener { + + protected static final PrintStream OUT = TTY.out().out(); + + public void notifyCompilationQueued(OptimizedCallTarget target) { + } + + public void notifyCompilationDequeued(OptimizedCallTarget target, Object source, CharSequence reason) { + } + + public void notifyCompilationFailed(OptimizedCallTarget target, StructuredGraph graph, Throwable t) { + } + + public void notifyCompilationStarted(OptimizedCallTarget target) { + } + + public void notifyCompilationTruffleTierFinished(OptimizedCallTarget target, StructuredGraph graph) { + } + + public void notifyCompilationSuccess(OptimizedCallTarget target, StructuredGraph graph, CompilationResult result) { + } + + public void notifyCompilationInvalidated(OptimizedCallTarget target, Object source, CharSequence reason) { + } + + public void notifyShutdown(TruffleRuntime runtime) { + } + + protected static void log(int indent, String msg, String details, Map<String, Object> properties) { + StringBuilder sb = new StringBuilder(); + sb.append(String.format("[truffle] %-16s ", msg)); + for (int i = 0; i < indent; i++) { + sb.append(' '); + } + sb.append(String.format("%-" + (60 - indent) + "s", details)); + if (properties != null) { + for (String property : properties.keySet()) { + Object value = properties.get(property); + if (value == null) { + continue; + } + sb.append('|'); + sb.append(property); + + StringBuilder propertyBuilder = new StringBuilder(); + if (value instanceof Integer) { + propertyBuilder.append(String.format("%6d", value)); + } else if (value instanceof Double) { + propertyBuilder.append(String.format("%8.2f", value)); + } else { + propertyBuilder.append(value); + } + + int length = Math.max(1, 20 - property.length()); + sb.append(String.format(" %" + length + "s ", propertyBuilder.toString())); + } + } + OUT.println(sb.toString()); + } + + protected static void addASTSizeProperty(OptimizedCallTarget target, Map<String, Object> properties) { + int nodeCount = OptimizedCallUtils.countNonTrivialNodes(target, false); + int deepNodeCount = nodeCount; + TruffleInlining inlining = target.getInlining(); + if (inlining != null) { + deepNodeCount += inlining.getInlinedNodeCount(); + } + properties.put("ASTSize", String.format("%5d/%5d", nodeCount, deepNodeCount)); + + } + +}
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationFailureListener.java Mon Oct 27 15:18:14 2014 +0100 @@ -0,0 +1,31 @@ +package com.oracle.graal.truffle.debug; + +import java.util.*; + +import com.oracle.graal.api.code.*; +import com.oracle.graal.nodes.*; +import com.oracle.graal.truffle.*; + +public class TraceCompilationFailureListener extends AbstractDebugCompilationListener { + + private TraceCompilationFailureListener() { + } + + public static void install(GraalTruffleRuntime runtime) { + runtime.addCompilationListener(new TraceCompilationFailureListener()); + } + + @Override + public void notifyCompilationFailed(OptimizedCallTarget target, StructuredGraph graph, Throwable t) { + if (isPermanentBailout(t)) { + Map<String, Object> properties = new LinkedHashMap<>(); + properties.put("Reason", t.toString()); + log(0, "opt fail", target.toString(), properties); + } + } + + public static final boolean isPermanentBailout(Throwable t) { + return !(t instanceof BailoutException) || ((BailoutException) t).isPermanent(); + } + +}
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationListener.java Mon Oct 27 15:18:14 2014 +0100 @@ -0,0 +1,128 @@ +package com.oracle.graal.truffle.debug; + +import static com.oracle.graal.truffle.TruffleCompilerOptions.*; + +import java.util.*; + +import com.oracle.graal.api.code.*; +import com.oracle.graal.nodes.*; +import com.oracle.graal.truffle.*; +import com.oracle.truffle.api.source.*; + +public class TraceCompilationListener extends AbstractDebugCompilationListener { + + private final ThreadLocal<LocalCompilation> currentCompilation = new ThreadLocal<>(); + + private TraceCompilationListener() { + } + + public static void install(GraalTruffleRuntime runtime) { + if (TraceTruffleCompilation.getValue() || TraceTruffleCompilationDetails.getValue()) { + runtime.addCompilationListener(new TraceCompilationListener()); + } + } + + @Override + public void notifyCompilationQueued(OptimizedCallTarget target) { + if (TraceTruffleCompilationDetails.getValue()) { + log(0, "opt queued", target.toString(), target.getDebugProperties()); + } + } + + @Override + public void notifyCompilationDequeued(OptimizedCallTarget target, Object source, CharSequence reason) { + if (TraceTruffleCompilationDetails.getValue()) { + Map<String, Object> properties = new LinkedHashMap<>(); + addSourceInfo(properties, source); + properties.put("Reason", reason); + log(0, "opt unqueued", target.toString(), properties); + } + } + + @Override + public void notifyCompilationFailed(OptimizedCallTarget target, StructuredGraph graph, Throwable t) { + super.notifyCompilationFailed(target, graph, t); + if (!TraceCompilationFailureListener.isPermanentBailout(t)) { + notifyCompilationDequeued(target, null, "Non permanent bailout: " + t.toString()); + } + currentCompilation.set(null); + } + + @Override + public void notifyCompilationStarted(OptimizedCallTarget target) { + if (TraceTruffleCompilationDetails.getValue()) { + log(0, "opt start", target.toString(), target.getDebugProperties()); + } + LocalCompilation compilation = new LocalCompilation(); + compilation.timeCompilationStarted = System.nanoTime(); + currentCompilation.set(compilation); + } + + @Override + public void notifyCompilationTruffleTierFinished(OptimizedCallTarget target, StructuredGraph graph) { + super.notifyCompilationTruffleTierFinished(target, graph); + LocalCompilation compilation = currentCompilation.get(); + compilation.timePartialEvaluationFinished = System.nanoTime(); + compilation.nodeCountPartialEval = graph.getNodeCount(); + } + + @Override + public void notifyCompilationSuccess(OptimizedCallTarget target, StructuredGraph graph, CompilationResult result) { + long timeCompilationFinished = System.nanoTime(); + int nodeCountLowered = graph.getNodeCount(); + LocalCompilation compilation = currentCompilation.get(); + TruffleInlining inlining = target.getInlining(); + + int calls; + int inlinedCalls; + if (inlining == null) { + calls = (int) target.nodeStream(false).filter(node -> (node instanceof OptimizedDirectCallNode)).count(); + inlinedCalls = 0; + } else { + calls = inlining.countCalls(); + inlinedCalls = inlining.countInlinedCalls(); + } + + int dispatchedCalls = calls - inlinedCalls; + Map<String, Object> properties = new LinkedHashMap<>(); + OptimizedCallTargetLog.addASTSizeProperty(target, properties); + properties.put("Time", String.format("%5.0f(%4.0f+%-4.0f)ms", // + (timeCompilationFinished - compilation.timeCompilationStarted) / 1e6, // + (compilation.timePartialEvaluationFinished - compilation.timeCompilationStarted) / 1e6, // + (timeCompilationFinished - compilation.timePartialEvaluationFinished) / 1e6)); + properties.put("DirectCallNodes", String.format("I %4d/D %4d", inlinedCalls, dispatchedCalls)); + properties.put("GraalNodes", String.format("%5d/%5d", compilation.nodeCountPartialEval, nodeCountLowered)); + properties.put("CodeSize", result.getTargetCodeSize()); + properties.put("Source", formatSourceSection(target.getRootNode().getSourceSection())); + + log(0, "opt done", target.toString(), properties); + super.notifyCompilationSuccess(target, graph, result); + currentCompilation.set(null); + } + + private static String formatSourceSection(SourceSection sourceSection) { + return sourceSection != null ? sourceSection.getShortDescription() : "n/a"; + } + + @Override + public void notifyCompilationInvalidated(OptimizedCallTarget target, Object source, CharSequence reason) { + Map<String, Object> properties = new LinkedHashMap<>(); + addSourceInfo(properties, source); + properties.put("Reason", reason); + log(0, "opt invalidated", target.toString(), properties); + } + + private static void addSourceInfo(Map<String, Object> properties, Object source) { + if (source != null) { + properties.put("SourceClass", source.getClass().getSimpleName()); + properties.put("Source", source); + } + } + + private static final class LocalCompilation { + long timeCompilationStarted; + long timePartialEvaluationFinished; + long nodeCountPartialEval; + } + +}
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationPolymorphismListener.java Mon Oct 27 15:18:14 2014 +0100 @@ -0,0 +1,37 @@ +package com.oracle.graal.truffle.debug; + +import static com.oracle.graal.truffle.TruffleCompilerOptions.*; + +import java.util.*; + +import com.oracle.graal.api.code.*; +import com.oracle.graal.nodes.*; +import com.oracle.graal.truffle.*; +import com.oracle.truffle.api.nodes.*; + +public class TraceCompilationPolymorphismListener extends AbstractDebugCompilationListener { + + private TraceCompilationPolymorphismListener() { + } + + public static void install(GraalTruffleRuntime runtime) { + if (TraceTruffleCompilationPolymorphism.getValue()) { + runtime.addCompilationListener(new TraceCompilationPolymorphismListener()); + } + } + + @Override + public void notifyCompilationSuccess(OptimizedCallTarget target, StructuredGraph graph, CompilationResult result) { + super.notifyCompilationSuccess(target, graph, result); + target.nodeStream(true).filter(node -> node != null && (node.getCost() == NodeCost.MEGAMORPHIC || node.getCost() == NodeCost.POLYMORPHIC))// + .forEach(node -> { + NodeCost cost = node.getCost(); + Map<String, Object> props = new LinkedHashMap<>(); + props.put("simpleName", node.getClass().getSimpleName()); + props.put("subtree", "\n" + NodeUtil.printCompactTreeToString(node)); + String msg = cost == NodeCost.MEGAMORPHIC ? "megamorphic" : "polymorphic"; + log(0, msg, node.toString(), props); + }); + } + +}