Mercurial > hg > truffle
changeset 21934:c493ec4605e9
Truffle: direct all log output to GraalTruffleRuntime#log
line wrap: on
line diff
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/GraalTruffleRuntime.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/GraalTruffleRuntime.java Thu Jun 11 20:46:30 2015 +0200 @@ -28,6 +28,7 @@ import com.oracle.jvmci.code.CompilationResult; import com.oracle.jvmci.meta.MetaAccessProvider; import com.oracle.jvmci.meta.ResolvedJavaMethod; + import static com.oracle.graal.truffle.TruffleCompilerOptions.*; import java.util.*; @@ -83,6 +84,10 @@ return bestFactory; } + public void log(String message) { + TTY.out().println(message); + } + protected void installDefaultListeners() { TraceCompilationFailureListener.install(this); TraceCompilationListener.install(this);
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/OptimizedCallTarget.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/OptimizedCallTarget.java Thu Jun 11 20:46:30 2015 +0200 @@ -105,6 +105,10 @@ this.nodeRewritingAssumption = new CyclicAssumption("nodeRewritingAssumption of " + rootNode.toString()); } + public final void log(String message) { + runtime.log(message); + } + public final boolean isCompiling() { return compiling; }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/PartialEvaluator.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/PartialEvaluator.java Thu Jun 11 20:46:30 2015 +0200 @@ -289,7 +289,7 @@ new GraphBuilderPhase.Instance(providers.getMetaAccess(), providers.getStampProvider(), providers.getConstantReflection(), newConfig, TruffleCompiler.Optimizations, null).apply(graph); if (PrintTruffleExpansionHistogram.getValue()) { - histogramPlugin.print(callTarget, System.out); + histogramPlugin.print(callTarget); } } @@ -337,7 +337,7 @@ decoder.decode(graph, graph.method(), loopExplosionPlugin, invocationPlugins, inlineInvokePlugins, parameterPlugin); if (PrintTruffleExpansionHistogram.getValue()) { - histogramPlugin.print(callTarget, System.out); + histogramPlugin.print(callTarget); } } @@ -386,29 +386,29 @@ graph.maybeCompress(); if (TruffleCompilerOptions.TraceTrufflePerformanceWarnings.getValue()) { - reportPerformanceWarnings(graph); + reportPerformanceWarnings(callTarget, graph); } } - private static void reportPerformanceWarnings(StructuredGraph graph) { + private static void reportPerformanceWarnings(OptimizedCallTarget target, StructuredGraph graph) { ArrayList<ValueNode> warnings = new ArrayList<>(); for (MethodCallTargetNode call : graph.getNodes(MethodCallTargetNode.TYPE)) { if (call.targetMethod().getAnnotation(TruffleBoundary.class) == null && call.targetMethod().getAnnotation(TruffleCallBoundary.class) == null) { - TracePerformanceWarningsListener.logPerformanceWarning(String.format("not inlined %s call to %s (%s)", call.invokeKind(), call.targetMethod(), call), null); + TracePerformanceWarningsListener.logPerformanceWarning(target, String.format("not inlined %s call to %s (%s)", call.invokeKind(), call.targetMethod(), call), null); warnings.add(call); } } for (CheckCastNode cast : graph.getNodes().filter(CheckCastNode.class)) { if (cast.type().findLeafConcreteSubtype() == null) { - TracePerformanceWarningsListener.logPerformanceWarning(String.format("non-leaf type checkcast: %s (%s)", cast.type().getName(), cast), null); + TracePerformanceWarningsListener.logPerformanceWarning(target, String.format("non-leaf type checkcast: %s (%s)", cast.type().getName(), cast), null); warnings.add(cast); } } for (InstanceOfNode instanceOf : graph.getNodes().filter(InstanceOfNode.class)) { if (instanceOf.type().findLeafConcreteSubtype() == null) { - TracePerformanceWarningsListener.logPerformanceWarning(String.format("non-leaf type instanceof: %s (%s)", instanceOf.type().getName(), instanceOf), null); + TracePerformanceWarningsListener.logPerformanceWarning(target, String.format("non-leaf type instanceof: %s (%s)", instanceOf.type().getName(), instanceOf), null); warnings.add(instanceOf); } } @@ -452,12 +452,13 @@ } private static TruffleInliningDecision getDecision(TruffleInlining inlining, OptimizedDirectCallNode callNode) { + OptimizedCallTarget target = callNode.getCallTarget(); TruffleInliningDecision decision = inlining.findByCall(callNode); if (decision == null) { if (TruffleCompilerOptions.TraceTrufflePerformanceWarnings.getValue()) { Map<String, Object> properties = new LinkedHashMap<>(); properties.put("callNode", callNode); - TracePerformanceWarningsListener.logPerformanceWarning("A direct call within the Truffle AST is not reachable anymore. Call node could not be inlined.", properties); + TracePerformanceWarningsListener.logPerformanceWarning(target, "A direct call within the Truffle AST is not reachable anymore. Call node could not be inlined.", properties); } } @@ -466,7 +467,7 @@ Map<String, Object> properties = new LinkedHashMap<>(); properties.put("originalTarget", decision.getTarget()); properties.put("callNode", callNode); - TracePerformanceWarningsListener.logPerformanceWarning(String.format("CallTarget changed during compilation. Call node could not be inlined."), properties); + TracePerformanceWarningsListener.logPerformanceWarning(target, String.format("CallTarget changed during compilation. Call node could not be inlined."), properties); } return null; }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/AbstractDebugCompilationListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/AbstractDebugCompilationListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -22,18 +22,14 @@ */ package com.oracle.graal.truffle.debug; -import com.oracle.jvmci.code.CompilationResult; -import java.io.*; import java.util.*; import com.oracle.graal.nodes.*; import com.oracle.graal.truffle.*; -import com.oracle.jvmci.debug.*; +import com.oracle.jvmci.code.*; public abstract class AbstractDebugCompilationListener implements GraalTruffleCompilationListener { - protected static final PrintStream OUT = TTY.out().out(); - public void notifyCompilationQueued(OptimizedCallTarget target) { } @@ -67,7 +63,7 @@ public void notifyStartup(GraalTruffleRuntime runtime) { } - public static void log(int indent, String msg, String details, Map<String, Object> properties) { + public static void log(OptimizedCallTarget target, int indent, String msg, String details, Map<String, Object> properties) { int spaceIndent = indent * 2; StringBuilder sb = new StringBuilder(); sb.append(String.format("[truffle] %-16s ", msg)); @@ -97,7 +93,7 @@ sb.append(String.format(" %" + length + "s ", propertyBuilder.toString())); } } - OUT.println(sb.toString()); + target.log(sb.toString()); } public static void addASTSizeProperty(OptimizedCallTarget target, Map<String, Object> properties) {
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/CompilationStatisticsListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/CompilationStatisticsListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -22,11 +22,9 @@ */ package com.oracle.graal.truffle.debug; -import com.oracle.jvmci.code.CompilationResult; import static java.util.function.Function.*; import static java.util.stream.Collectors.*; -import java.io.*; import java.util.*; import java.util.function.*; import java.util.stream.*; @@ -34,6 +32,7 @@ import com.oracle.graal.nodes.*; import com.oracle.graal.truffle.*; import com.oracle.graal.truffle.TruffleInlining.CallTreeNodeVisitor; +import com.oracle.jvmci.code.*; import com.oracle.truffle.api.nodes.*; import com.oracle.truffle.api.nodes.Node; @@ -204,102 +203,102 @@ } @Override - public void notifyShutdown(GraalTruffleRuntime runtime) { - printStatistics(runtime, OUT); + public void notifyShutdown(GraalTruffleRuntime rt) { + printStatistics(rt); } - public void printStatistics(GraalTruffleRuntime runtime, PrintStream out) { + public void printStatistics(GraalTruffleRuntime rt) { long endTime = System.nanoTime(); - out.println("Truffle compilation statistics:"); - printStatistic("Compilations", compilations); - printStatistic(" Success", success); - printStatistic(" Failed", failures); - printStatistic(" Interrupted", compilations - (success + failures)); - printStatistic("Invalidated", invalidations); - printStatistic("Queues", queues); - printStatistic("Dequeues", dequeues); - printStatistic("Splits", splits); - printStatistic("Compilation Accuracy", 1.0 - invalidations / (double) compilations); - printStatistic("Queue Accuracy", 1.0 - dequeues / (double) queues); - printStatistic("Compilation Utilization", compilationTime.getSum() / (double) (endTime - firstCompilation)); - printStatistic("Remaining Compilation Queue", runtime.getQueuedCallTargets().size()); - printStatistic("Times defered until compilation", deferCompilations); + rt.log("Truffle compilation statistics:"); + printStatistic(rt, "Compilations", compilations); + printStatistic(rt, " Success", success); + printStatistic(rt, " Failed", failures); + printStatistic(rt, " Interrupted", compilations - (success + failures)); + printStatistic(rt, "Invalidated", invalidations); + printStatistic(rt, "Queues", queues); + printStatistic(rt, "Dequeues", dequeues); + printStatistic(rt, "Splits", splits); + printStatistic(rt, "Compilation Accuracy", 1.0 - invalidations / (double) compilations); + printStatistic(rt, "Queue Accuracy", 1.0 - dequeues / (double) queues); + printStatistic(rt, "Compilation Utilization", compilationTime.getSum() / (double) (endTime - firstCompilation)); + printStatistic(rt, "Remaining Compilation Queue", rt.getQueuedCallTargets().size()); + printStatistic(rt, "Times defered until compilation", deferCompilations); - printStatisticTime("Time to queue", timeToQueue); - printStatisticTime("Time to compilation", timeToCompilation); + printStatisticTime(rt, "Time to queue", timeToQueue); + printStatisticTime(rt, "Time to compilation", timeToCompilation); - printStatisticTime("Compilation time", compilationTime); - printStatisticTime(" Truffle Tier", compilationTimeTruffleTier); - printStatisticTime(" Graal Tier", compilationTimeGraalTier); - printStatisticTime(" Code Installation", compilationTimeCodeInstallation); + printStatisticTime(rt, "Compilation time", compilationTime); + printStatisticTime(rt, " Truffle Tier", compilationTimeTruffleTier); + printStatisticTime(rt, " Graal Tier", compilationTimeGraalTier); + printStatisticTime(rt, " Code Installation", compilationTimeCodeInstallation); - printStatistic("Truffle node count", nodeCount); - printStatistic(" Trivial", nodeCountTrivial); - printStatistic(" Non Trivial", nodeCountNonTrivial); - printStatistic(" Monomorphic", nodeCountMonomorphic); - printStatistic(" Polymorphic", nodeCountPolymorphic); - printStatistic(" Megamorphic", nodeCountMegamorphic); - printStatistic("Truffle call count", callCount); - printStatistic(" Indirect", callCountIndirect); - printStatistic(" Direct", callCountDirect); - printStatistic(" Dispatched", callCountDirectDispatched); - printStatistic(" Inlined", callCountDirectInlined); - printStatistic(" ----------"); - printStatistic(" Cloned", callCountDirectCloned); - printStatistic(" Not Cloned", callCountDirectNotCloned); - printStatistic("Truffle loops", loopCount); - printStatistic("Graal node count"); - printStatistic(" After Truffle Tier", truffleTierNodeCount); - printStatistic(" After Graal Tier", graalTierNodeCount); + printStatistic(rt, "Truffle node count", nodeCount); + printStatistic(rt, " Trivial", nodeCountTrivial); + printStatistic(rt, " Non Trivial", nodeCountNonTrivial); + printStatistic(rt, " Monomorphic", nodeCountMonomorphic); + printStatistic(rt, " Polymorphic", nodeCountPolymorphic); + printStatistic(rt, " Megamorphic", nodeCountMegamorphic); + printStatistic(rt, "Truffle call count", callCount); + printStatistic(rt, " Indirect", callCountIndirect); + printStatistic(rt, " Direct", callCountDirect); + printStatistic(rt, " Dispatched", callCountDirectDispatched); + printStatistic(rt, " Inlined", callCountDirectInlined); + printStatistic(rt, " ----------"); + printStatistic(rt, " Cloned", callCountDirectCloned); + printStatistic(rt, " Not Cloned", callCountDirectNotCloned); + printStatistic(rt, "Truffle loops", loopCount); + printStatistic(rt, "Graal node count"); + printStatistic(rt, " After Truffle Tier", truffleTierNodeCount); + printStatistic(rt, " After Graal Tier", graalTierNodeCount); - printStatistic("Graal comilation result"); - printStatistic(" Code size", compilationResultCodeSize); - printStatistic(" Total frame size", compilationResultTotalFrameSize); - printStatistic(" Exception handlers", compilationResultExceptionHandlers); - printStatistic(" Infopoints", compilationResultInfopoints); - compilationResultInfopointStatistics.printStatistics(identity()); - printStatistic(" Marks", compilationResultMarks); - printStatistic(" Data references", compilationResultDataPatches); + printStatistic(rt, "Graal comilation result"); + printStatistic(rt, " Code size", compilationResultCodeSize); + printStatistic(rt, " Total frame size", compilationResultTotalFrameSize); + printStatistic(rt, " Exception handlers", compilationResultExceptionHandlers); + printStatistic(rt, " Infopoints", compilationResultInfopoints); + compilationResultInfopointStatistics.printStatistics(rt, identity()); + printStatistic(rt, " Marks", compilationResultMarks); + printStatistic(rt, " Data references", compilationResultDataPatches); if (TruffleCompilerOptions.TruffleCompilationStatisticDetails.getValue()) { - printStatistic("Truffle nodes"); - nodeStatistics.printStatistics(Class::getSimpleName); - printStatistic("Graal nodes after Truffle tier"); - truffleTierNodeStatistics.printStatistics(Class::getSimpleName); - printStatistic("Graal nodes after Graal tier"); - graalTierNodeStatistics.printStatistics(Class::getSimpleName); + printStatistic(rt, "Truffle nodes"); + nodeStatistics.printStatistics(rt, Class::getSimpleName); + printStatistic(rt, "Graal nodes after Truffle tier"); + truffleTierNodeStatistics.printStatistics(rt, Class::getSimpleName); + printStatistic(rt, "Graal nodes after Graal tier"); + graalTierNodeStatistics.printStatistics(rt, Class::getSimpleName); } } - private static void printStatistic(String label) { - OUT.printf(" %-50s: %n", label); + private static void printStatistic(GraalTruffleRuntime rt, String label) { + rt.log(String.format(" %-50s: ", label)); } - private static void printStatistic(String label, int value) { - OUT.printf(" %-50s: %d%n", label, value); + private static void printStatistic(GraalTruffleRuntime rt, String label, int value) { + rt.log(String.format(" %-50s: %d", label, value)); } - private static void printStatistic(String label, double value) { - OUT.printf(" %-50s: %f%n", label, value); + private static void printStatistic(GraalTruffleRuntime rt, String label, double value) { + rt.log(String.format(" %-50s: %f", label, value)); } - private static void printStatistic(String label, IntSummaryStatistics value) { - OUT.printf(" %-50s: count=%4d, sum=%8d, min=%8d, average=%12.2f, max=%8d %n", label, value.getCount(), value.getSum(), value.getMin(), value.getAverage(), value.getMax()); + private static void printStatistic(GraalTruffleRuntime rt, String label, IntSummaryStatistics value) { + rt.log(String.format(" %-50s: count=%4d, sum=%8d, min=%8d, average=%12.2f, max=%8d ", label, value.getCount(), value.getSum(), value.getMin(), value.getAverage(), value.getMax())); } - private static void printStatisticTime(String label, LongSummaryStatistics value) { - OUT.printf(" %-50s: count=%4d, sum=%8d, min=%8d, average=%12.2f, max=%8d (milliseconds)%n", label, value.getCount(), value.getSum() / 1000000, value.getMin() / 1000000, - value.getAverage() / 1e6, value.getMax() / 1000000); + private static void printStatisticTime(GraalTruffleRuntime rt, String label, LongSummaryStatistics value) { + rt.log(String.format(" %-50s: count=%4d, sum=%8d, min=%8d, average=%12.2f, max=%8d (milliseconds)", label, value.getCount(), value.getSum() / 1000000, value.getMin() / 1000000, + value.getAverage() / 1e6, value.getMax() / 1000000)); } private static final class IdentityStatistics<T> { final Map<T, IntSummaryStatistics> types = new HashMap<>(); - public void printStatistics(Function<T, String> toStringFunction) { + public void printStatistics(GraalTruffleRuntime rt, Function<T, String> toStringFunction) { types.keySet().stream().sorted(Comparator.comparing(c -> -types.get(c).getSum())).// forEach(c -> { - printStatistic(String.format(" %s", toStringFunction.apply(c)), types.get(c)); + printStatistic(rt, String.format(" %s", toStringFunction.apply(c)), types.get(c)); }); }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/HistogramInlineInvokePlugin.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/HistogramInlineInvokePlugin.java Thu Jun 11 20:46:30 2015 +0200 @@ -22,7 +22,6 @@ */ package com.oracle.graal.truffle.debug; -import java.io.*; import java.util.*; import com.oracle.graal.graph.*; @@ -81,13 +80,13 @@ statistics.accept(current); } - public void print(OptimizedCallTarget target, PrintStream out) { - out.printf("Truffle expansion histogram for %s%n", target); - out.println(" Invocations = Number of expanded invocations"); - out.println(" Nodes = Number of non-trival Graal nodes created for this method during partial evaluation."); - out.println(" Calls = Number of not expanded calls created for this method during partial evaluation."); - out.printf(" %-11s |Nodes %5s %5s %5s %8s |Calls %5s %5s %5s %8s | Method Name%n", "Invocations", "Sum", "Min", "Max", "Avg", "Sum", "Min", "Max", "Avg"); - histogram.values().stream().filter(statistics -> statistics.shallowCount.getSum() > 0).sorted().forEach(statistics -> statistics.print(out)); + public void print(OptimizedCallTarget target) { + target.log(String.format("Truffle expansion histogram for %s", target)); + target.log(" Invocations = Number of expanded invocations"); + target.log(" Nodes = Number of non-trival Graal nodes created for this method during partial evaluation."); + target.log(" Calls = Number of not expanded calls created for this method during partial evaluation."); + target.log(String.format(" %-11s |Nodes %5s %5s %5s %8s |Calls %5s %5s %5s %8s | Method Name", "Invocations", "Sum", "Min", "Max", "Avg", "Sum", "Min", "Max", "Avg")); + histogram.values().stream().filter(statistics -> statistics.shallowCount.getSum() > 0).sorted().forEach(statistics -> statistics.print(target)); } private static class MethodStatistics implements Comparable<MethodStatistics> { @@ -102,11 +101,11 @@ this.method = method; } - public void print(PrintStream out) { - out.printf(" %11d | %5d %5d %5d %8.2f | %5d %5d %5d %8.2f | %s%n", // + public void print(OptimizedCallTarget target) { + target.log(String.format(" %11d | %5d %5d %5d %8.2f | %5d %5d %5d %8.2f | %s", // count, shallowCount.getSum(), shallowCount.getMin(), shallowCount.getMax(), // shallowCount.getAverage(), callCount.getSum(), callCount.getMin(), callCount.getMax(), // - callCount.getAverage(), method.format("%h.%n(%p)")); + callCount.getAverage(), method.format("%h.%n(%p)"))); } public int compareTo(MethodStatistics o) {
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/PrintCallTargetProfiling.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/PrintCallTargetProfiling.java Thu Jun 11 20:46:30 2015 +0200 @@ -60,9 +60,9 @@ int totalInterpretedCallCount = 0; int totalInvalidationCount = 0; - OUT.println(); - OUT.printf(" %-50s | %-15s || %-15s | %-15s || %-15s | %-15s | %-15s || %3s \n", "Call Target", "Total Calls", "Interp. Calls", "Opt. Calls", "Direct Calls", "Inlined Calls", - "Indirect Calls", "Invalidations"); + runtime.log(""); // empty line + runtime.log(String.format(" %-50s | %-15s || %-15s | %-15s || %-15s | %-15s | %-15s || %3s ", "Call Target", "Total Calls", "Interp. Calls", "Opt. Calls", "Direct Calls", "Inlined Calls", + "Indirect Calls", "Invalidations")); for (OptimizedCallTarget uniqueCallTarget : uniqueSortedTargets) { List<OptimizedCallTarget> allCallTargets = groupedTargets.get(uniqueCallTarget); int directCallCount = sumCalls(allCallTargets, p -> p.getDirectCallCount()); @@ -80,14 +80,14 @@ totalTotalCallCount += totalCallCount; if (totalCallCount > 0) { - OUT.printf(" %-50s | %15d || %15d | %15d || %15d | %15d | %15d || %3d\n", uniqueCallTarget, totalCallCount, interpreterCallCount, totalCallCount - interpreterCallCount, - directCallCount, inlinedCallCount, indirectCallCount, invalidationCount); + runtime.log(String.format(" %-50s | %15d || %15d | %15d || %15d | %15d | %15d || %3d", uniqueCallTarget, totalCallCount, interpreterCallCount, totalCallCount - interpreterCallCount, + directCallCount, inlinedCallCount, indirectCallCount, invalidationCount)); } } - OUT.printf(" %-50s | %15d || %15d | %15d || %15d | %15d | %15d || %3d\n", "Total", totalTotalCallCount, totalInterpretedCallCount, totalTotalCallCount - totalInterpretedCallCount, - totalDirectCallCount, totalInlinedCallCount, totalIndirectCallCount, totalInvalidationCount); + runtime.log(String.format(" %-50s | %15d || %15d | %15d || %15d | %15d | %15d || %3d", "Total", totalTotalCallCount, totalInterpretedCallCount, totalTotalCallCount - + totalInterpretedCallCount, totalDirectCallCount, totalInlinedCallCount, totalIndirectCallCount, totalInvalidationCount)); }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationASTListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationASTListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -22,15 +22,14 @@ */ package com.oracle.graal.truffle.debug; -import com.oracle.jvmci.code.CompilationResult; import static com.oracle.graal.truffle.TruffleCompilerOptions.*; -import java.io.*; import java.util.*; import com.oracle.graal.nodes.*; import com.oracle.graal.truffle.*; import com.oracle.graal.truffle.TruffleInlining.CallTreeNodeVisitor; +import com.oracle.jvmci.code.*; import com.oracle.truffle.api.nodes.*; public final class TraceCompilationASTListener extends AbstractDebugCompilationListener { @@ -43,11 +42,11 @@ @Override public void notifyCompilationSuccess(OptimizedCallTarget target, StructuredGraph graph, CompilationResult result) { - log(0, "opt AST", target.toString(), target.getDebugProperties()); - printCompactTree(new PrintWriter(OUT), target); + log(target, 0, "opt AST", target.toString(), target.getDebugProperties()); + printCompactTree(target); } - private static void printCompactTree(PrintWriter p, OptimizedCallTarget target) { + private static void printCompactTree(OptimizedCallTarget target) { target.accept(new CallTreeNodeVisitor() { public boolean visit(List<TruffleInlining> decisionStack, Node node) { @@ -55,13 +54,14 @@ return true; } int level = CallTreeNodeVisitor.getNodeDepth(decisionStack, node); + StringBuilder indent = new StringBuilder(); for (int i = 0; i < level; i++) { - p.print(" "); + indent.append(" "); } Node parent = node.getParent(); if (parent == null) { - p.println(node.getClass().getSimpleName()); + target.log(String.format("%s%s", indent, node.getClass().getSimpleName())); } else { String fieldName = "unknownField"; NodeFieldAccessor[] fields = NodeClass.get(parent).getFields(); @@ -81,15 +81,11 @@ } } } - p.print(fieldName); - p.print(" = "); - p.println(node.getClass().getSimpleName()); + target.log(String.format("%s%s = %s", indent, fieldName, node.getClass().getSimpleName())); } - p.flush(); return true; } }, true); } - }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationCallTreeListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationCallTreeListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -22,7 +22,6 @@ */ package com.oracle.graal.truffle.debug; -import com.oracle.jvmci.code.CompilationResult; import static com.oracle.graal.truffle.TruffleCompilerOptions.*; import java.util.*; @@ -30,6 +29,7 @@ import com.oracle.graal.nodes.*; import com.oracle.graal.truffle.*; import com.oracle.graal.truffle.TruffleInlining.CallTreeNodeVisitor; +import com.oracle.jvmci.code.*; import com.oracle.truffle.api.nodes.*; public final class TraceCompilationCallTreeListener extends AbstractDebugCompilationListener { @@ -45,7 +45,7 @@ @Override public void notifyCompilationSuccess(OptimizedCallTarget target, StructuredGraph graph, CompilationResult result) { - log(0, "opt call tree", target.toString(), target.getDebugProperties()); + log(target, 0, "opt call tree", target.toString(), target.getDebugProperties()); logTruffleCallTree(target); } @@ -65,10 +65,10 @@ addASTSizeProperty(callNode.getCurrentCallTarget(), properties); properties.putAll(callNode.getCurrentCallTarget().getDebugProperties()); properties.put("Stamp", callNode.getCurrentCallTarget().getArgumentStamp()); - log(depth, "opt call tree", callNode.getCurrentCallTarget().toString() + dispatched, properties); + log(compilable, depth, "opt call tree", callNode.getCurrentCallTarget().toString() + dispatched, properties); } else if (node instanceof OptimizedIndirectCallNode) { int depth = decisionStack == null ? 0 : decisionStack.size() - 1; - log(depth, "opt call tree", "<indirect>", new LinkedHashMap<String, Object>()); + log(compilable, depth, "opt call tree", "<indirect>", new LinkedHashMap<String, Object>()); } return true; }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationFailureListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationFailureListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -44,7 +44,7 @@ if (isPermanentBailout(t) || PrintBailout.getValue()) { Map<String, Object> properties = new LinkedHashMap<>(); properties.put("Reason", t.toString()); - log(0, "opt fail", target.toString(), properties); + log(target, 0, "opt fail", target.toString(), properties); } }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -47,7 +47,7 @@ @Override public void notifyCompilationQueued(OptimizedCallTarget target) { if (TraceTruffleCompilationDetails.getValue()) { - log(0, "opt queued", target.toString(), target.getDebugProperties()); + log(target, 0, "opt queued", target.toString(), target.getDebugProperties()); } } @@ -57,7 +57,7 @@ Map<String, Object> properties = new LinkedHashMap<>(); addSourceInfo(properties, source); properties.put("Reason", reason); - log(0, "opt unqueued", target.toString(), properties); + log(target, 0, "opt unqueued", target.toString(), properties); } } @@ -73,7 +73,7 @@ @Override public void notifyCompilationStarted(OptimizedCallTarget target) { if (TraceTruffleCompilationDetails.getValue()) { - log(0, "opt start", target.toString(), target.getDebugProperties()); + log(target, 0, "opt start", target.toString(), target.getDebugProperties()); } LocalCompilation compilation = new LocalCompilation(); compilation.timeCompilationStarted = System.nanoTime(); @@ -117,7 +117,7 @@ properties.put("CodeSize", result.getTargetCodeSize()); properties.put("Source", formatSourceSection(target.getRootNode().getSourceSection())); - log(0, "opt done", target.toString(), properties); + log(target, 0, "opt done", target.toString(), properties); super.notifyCompilationSuccess(target, graph, result); currentCompilation.set(null); } @@ -131,7 +131,7 @@ Map<String, Object> properties = new LinkedHashMap<>(); addSourceInfo(properties, source); properties.put("Reason", reason); - log(0, "opt invalidated", target.toString(), properties); + log(target, 0, "opt invalidated", target.toString(), properties); } private static void addSourceInfo(Map<String, Object> properties, Object source) {
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationPolymorphismListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceCompilationPolymorphismListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -52,7 +52,7 @@ 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); + log(target, 0, msg, node.toString(), props); }); }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceInliningListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceInliningListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -45,19 +45,19 @@ return; } - log(0, "inline start", target.toString(), target.getDebugProperties()); - logInliningDecisionRecursive(inlining, 1); - log(0, "inline done", target.toString(), target.getDebugProperties()); + log(target, 0, "inline start", target.toString(), target.getDebugProperties()); + logInliningDecisionRecursive(target, inlining, 1); + log(target, 0, "inline done", target.toString(), target.getDebugProperties()); } - private static void logInliningDecisionRecursive(TruffleInlining result, int depth) { + private void logInliningDecisionRecursive(OptimizedCallTarget target, TruffleInlining result, int depth) { for (TruffleInliningDecision decision : result) { TruffleInliningProfile profile = decision.getProfile(); boolean inlined = decision.isInline(); String msg = inlined ? "inline success" : "inline failed"; - log(depth, msg, decision.getProfile().getCallNode().getCurrentCallTarget().toString(), profile.getDebugProperties()); + log(target, depth, msg, decision.getProfile().getCallNode().getCurrentCallTarget().toString(), profile.getDebugProperties()); if (inlined) { - logInliningDecisionRecursive(decision, depth + 1); + logInliningDecisionRecursive(target, decision, depth + 1); } } }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TracePerformanceWarningsListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TracePerformanceWarningsListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -43,8 +43,8 @@ return TraceTrufflePerformanceWarnings.getValue(); } - public static void logPerformanceWarning(String details, Map<String, Object> properties) { - log(0, "perf warn", details, properties); + public static void logPerformanceWarning(OptimizedCallTarget target, String details, Map<String, Object> properties) { + log(target, 0, "perf warn", details, properties); } }
--- a/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceSplittingListener.java Fri Jun 12 11:32:39 2015 +0200 +++ b/graal/com.oracle.graal.truffle/src/com/oracle/graal/truffle/debug/TraceSplittingListener.java Thu Jun 11 20:46:30 2015 +0200 @@ -47,7 +47,7 @@ public void notifyCompilationSplit(OptimizedDirectCallNode callNode) { OptimizedCallTarget callTarget = callNode.getCallTarget(); String label = String.format("split %3s-%-4s-%-4s ", splitCount++, callNode.getCurrentCallTarget().getCloneIndex(), callNode.getCallCount()); - AbstractDebugCompilationListener.log(0, label, callTarget.toString(), callTarget.getDebugProperties()); + log(callTarget, 0, label, callTarget.toString(), callTarget.getDebugProperties()); if (TruffleSplittingNew.getValue()) { Map<TruffleStamp, OptimizedCallTarget> splitTargets = callTarget.getSplitVersions(); @@ -60,8 +60,8 @@ private static void logProfile(TruffleStamp stamp, OptimizedCallTarget target) { String id = String.format("@%8h %s", target.hashCode(), target.getSourceCallTarget() == null ? "orig." : "split"); - OUT.printf("%16s%-20sCallers: %3d, Nodes:%10s %s%n", "", id, target.getKnownCallSiteCount(), // - String.format("%d (%d/%d)", count(target, NodeCost.MONOMORPHIC), count(target, NodeCost.POLYMORPHIC), count(target, NodeCost.MEGAMORPHIC)), stamp); + target.log(String.format("%16s%-20sCallers: %3d, Nodes:%10s %s", "", id, target.getKnownCallSiteCount(), // + String.format("%d (%d/%d)", count(target, NodeCost.MONOMORPHIC), count(target, NodeCost.POLYMORPHIC), count(target, NodeCost.MEGAMORPHIC)), stamp)); } private static int count(OptimizedCallTarget target, final NodeCost otherCost) {