# HG changeset patch # User Doug Simon # Date 1395243009 -3600 # Node ID aa7bcf1fa4234e819a45b5fbd52f2bea423d19ea # Parent bd106238e8857e8a4c5921712fa02ab005f58f56 expanded Debug API to avoid any allocation for timer and metric creation if debugging is disabled diff -r bd106238e885 -r aa7bcf1fa423 graal/com.oracle.graal.compiler/src/com/oracle/graal/compiler/GraalCompiler.java --- a/graal/com.oracle.graal.compiler/src/com/oracle/graal/compiler/GraalCompiler.java Wed Mar 19 15:21:43 2014 +0100 +++ b/graal/com.oracle.graal.compiler/src/com/oracle/graal/compiler/GraalCompiler.java Wed Mar 19 16:30:09 2014 +0100 @@ -289,9 +289,10 @@ if (Debug.isMeterEnabled()) { List ldp = compilationResult.getDataReferences(); - DebugMetric[] dms = new DebugMetric[Kind.values().length]; + Kind[] kindValues = Kind.values(); + DebugMetric[] dms = new DebugMetric[kindValues.length]; for (int i = 0; i < dms.length; i++) { - dms[i] = Debug.metric("DataPatches-" + Kind.values()[i].toString()); + dms[i] = Debug.metric("DataPatches-%s", kindValues[i]); } for (DataPatch dp : ldp) { diff -r bd106238e885 -r aa7bcf1fa423 graal/com.oracle.graal.debug/src/com/oracle/graal/debug/Debug.java --- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/Debug.java Wed Mar 19 15:21:43 2014 +0100 +++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/Debug.java Wed Mar 19 16:30:09 2014 +0100 @@ -23,6 +23,7 @@ package com.oracle.graal.debug; import static com.oracle.graal.debug.Debug.Initialization.*; +import static java.util.FormattableFlags.*; import java.io.*; import java.util.*; @@ -167,9 +168,9 @@ * @return the scope entered by this method which will be exited when its {@link Scope#close()} * method is called */ - public static Scope scope(CharSequence name, Object... context) { + public static Scope scope(Object name, Object... context) { if (ENABLED) { - return DebugScope.getInstance().scope(name, null, context); + return DebugScope.getInstance().scope(convertFormatArg(name).toString(), null, context); } else { return null; } @@ -380,13 +381,86 @@ * A disabled metric has virtually no overhead. */ public static DebugMetric metric(CharSequence name) { - if (enabledMetrics != null && enabledMetrics.contains(name.toString())) { - return new MetricImpl(name.toString(), false); - } else if (ENABLED) { - return new MetricImpl(name.toString(), true); - } else { + if (enabledMetrics == null && !ENABLED) { return VOID_METRIC; } + return createMetric("%s", name, null); + } + + public static String applyFormattingFlagsAndWidth(String s, int flags, int width) { + if (flags == 0 && width < 0) { + return s; + } + StringBuilder sb = new StringBuilder(s); + + // apply width and justification + int len = sb.length(); + if (len < width) { + for (int i = 0; i < width - len; i++) { + if ((flags & LEFT_JUSTIFY) == LEFT_JUSTIFY) { + sb.append(' '); + } else { + sb.insert(0, ' '); + } + } + } + + String res = sb.toString(); + if ((flags & UPPERCASE) == UPPERCASE) { + res = res.toUpperCase(); + } + return res; + } + + /** + * Creates a debug metric. Invoking this method is equivalent to: + * + *
+     * Debug.metric(format, arg, null)
+     * 
+ * + * except that the string formatting only happens if metering is enabled. + * + * @see #metric(String, Object, Object) + */ + public static DebugMetric metric(String format, Object arg) { + if (enabledMetrics == null && !ENABLED) { + return VOID_METRIC; + } + return createMetric(format, arg, null); + } + + /** + * Creates a debug metric. Invoking this method is equivalent to: + * + *
+     * Debug.metric(String.format(format, arg1, arg2))
+     * 
+ * + * except that the string formatting only happens if metering is enabled. In addition, each + * argument is subject to the following type based conversion before being passed as an argument + * to {@link String#format(String, Object...)}: + * + *
+     *     Type          | Conversion
+     * ------------------+-----------------
+     *  java.lang.Class  | arg.getSimpleName()
+     *                   |
+     * 
+ * + * @see #metric(CharSequence) + */ + public static DebugMetric metric(String format, Object arg1, Object arg2) { + if (enabledMetrics == null && !ENABLED) { + return VOID_METRIC; + } + return createMetric(format, arg1, arg2); + } + + private static DebugMetric createMetric(String format, Object arg1, Object arg2) { + String name = formatDebugName(format, arg1, arg2); + boolean conditional = enabledMetrics != null && enabledMetrics.contains(name); + return new MetricImpl(name, conditional); } /** @@ -533,13 +607,72 @@ * A disabled timer has virtually no overhead. */ public static DebugTimer timer(CharSequence name) { - if (enabledTimers != null && enabledTimers.contains(name.toString())) { - return new TimerImpl(name.toString(), false); - } else if (ENABLED) { - return new TimerImpl(name.toString(), true); - } else { + if (enabledTimers == null && !ENABLED) { + return VOID_TIMER; + } + return createTimer("%s", name, null); + } + + /** + * Creates a debug timer. Invoking this method is equivalent to: + * + *
+     * Debug.timer(format, arg, null)
+     * 
+ * + * except that the string formatting only happens if timing is enabled. + * + * @see #timer(String, Object, Object) + */ + public static DebugTimer timer(String format, Object arg) { + if (enabledTimers == null && !ENABLED) { return VOID_TIMER; } + return createTimer(format, arg, null); + } + + /** + * Creates a debug timer. Invoking this method is equivalent to: + * + *
+     * Debug.timer(String.format(format, arg1, arg2))
+     * 
+ * + * except that the string formatting only happens if timing is enabled. In addition, each + * argument is subject to the following type based conversion before being passed as an argument + * to {@link String#format(String, Object...)}: + * + *
+     *     Type          | Conversion
+     * ------------------+-----------------
+     *  java.lang.Class  | arg.getSimpleName()
+     *                   |
+     * 
+ * + * @see #timer(CharSequence) + */ + public static DebugTimer timer(String format, Object arg1, Object arg2) { + if (enabledTimers == null && !ENABLED) { + return VOID_TIMER; + } + return createTimer(format, arg1, arg2); + } + + public static Object convertFormatArg(Object arg) { + if (arg instanceof Class) { + return ((Class) arg).getSimpleName(); + } + return arg; + } + + private static String formatDebugName(String format, Object arg1, Object arg2) { + return String.format(format, convertFormatArg(arg1), convertFormatArg(arg2)); + } + + private static DebugTimer createTimer(String format, Object arg1, Object arg2) { + String name = formatDebugName(format, arg1, arg2); + boolean conditional = enabledTimers != null && enabledTimers.contains(name); + return new TimerImpl(name, conditional); } private static final DebugTimer VOID_TIMER = new DebugTimer() { diff -r bd106238e885 -r aa7bcf1fa423 graal/com.oracle.graal.graph/src/com/oracle/graal/graph/NodeClass.java --- a/graal/com.oracle.graal.graph/src/com/oracle/graal/graph/NodeClass.java Wed Mar 19 15:21:43 2014 +0100 +++ b/graal/com.oracle.graal.graph/src/com/oracle/graal/graph/NodeClass.java Wed Mar 19 16:30:09 2014 +0100 @@ -234,7 +234,7 @@ } isLeafNode = (this.inputOffsets.length == 0 && this.successorOffsets.length == 0); - nodeIterableCount = Debug.metric("NodeIterable_" + shortName); + nodeIterableCount = Debug.metric("NodeIterable_%s", shortName); } @Override diff -r bd106238e885 -r aa7bcf1fa423 graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/meta/HotSpotMethod.java --- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/meta/HotSpotMethod.java Wed Mar 19 15:21:43 2014 +0100 +++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/meta/HotSpotMethod.java Wed Mar 19 16:30:09 2014 +0100 @@ -23,11 +23,15 @@ package com.oracle.graal.hotspot.meta; import static com.oracle.graal.api.meta.MetaUtil.*; +import static com.oracle.graal.debug.Debug.*; +import static java.util.FormattableFlags.*; + +import java.util.*; import com.oracle.graal.api.meta.*; import com.oracle.graal.hotspot.*; -public abstract class HotSpotMethod extends CompilerObject implements JavaMethod { +public abstract class HotSpotMethod extends CompilerObject implements JavaMethod, Formattable { private static final long serialVersionUID = 7167491397941960839L; protected String name; @@ -54,4 +58,9 @@ String fmt = String.format("HotSpotMethod<%%%c.%%n(%%p)%s>", h, suffix); return format(fmt, this); } + + public void formatTo(Formatter formatter, int flags, int width, int precision) { + String base = (flags & ALTERNATE) == ALTERNATE ? getName() : toString(); + formatter.format(applyFormattingFlagsAndWidth(base, flags & ~ALTERNATE, width)); + } } diff -r bd106238e885 -r aa7bcf1fa423 graal/com.oracle.graal.phases/src/com/oracle/graal/phases/BasePhase.java --- a/graal/com.oracle.graal.phases/src/com/oracle/graal/phases/BasePhase.java Wed Mar 19 15:21:43 2014 +0100 +++ b/graal/com.oracle.graal.phases/src/com/oracle/graal/phases/BasePhase.java Wed Mar 19 16:30:09 2014 +0100 @@ -36,38 +36,7 @@ */ public abstract class BasePhase { - /** - * Phase name lazily computed from the phase class. - */ - class Name extends LazyName { - - @Override - public String createString() { - String s = BasePhase.this.getClass().getSimpleName(); - if (s.endsWith("Phase")) { - return s.substring(0, s.length() - "Phase".length()); - } - return s; - } - } - - /** - * Lazily computed debug value name composed of a prefix and a phase's name. - */ - class DebugValueName extends LazyName { - final String prefix; - - public DebugValueName(String prefix) { - this.prefix = prefix; - } - - @Override - public String createString() { - return prefix + name; - } - } - - private final CharSequence name; + private CharSequence name; private final DebugTimer phaseTimer; private final DebugMetric phaseMetric; @@ -80,17 +49,15 @@ } protected BasePhase() { - name = new Name(); - assert checkName(name.toString()); - phaseTimer = Debug.timer(new DebugValueName("PhaseTime_")); - phaseMetric = Debug.metric(new DebugValueName("PhaseCount_")); + phaseTimer = Debug.timer("PhaseTime_%s", getClass()); + phaseMetric = Debug.metric("PhaseCount_%s", getClass()); } protected BasePhase(String name) { assert checkName(name); this.name = name; - phaseTimer = Debug.timer(new DebugValueName("PhaseTime_")); - phaseMetric = Debug.metric(new DebugValueName("PhaseCount_")); + phaseTimer = Debug.timer("PhaseTime_%s", getClass()); + phaseMetric = Debug.metric("PhaseCount_%s", getClass()); } protected CharSequence getDetailedName() { @@ -102,7 +69,7 @@ } public final void apply(final StructuredGraph graph, final C context, final boolean dumpGraph) { - try (TimerCloseable a = phaseTimer.start(); Scope s = Debug.scope(name, this)) { + try (TimerCloseable a = phaseTimer.start(); Scope s = Debug.scope(getClass(), this)) { BasePhase.this.run(graph, context); phaseMetric.increment(); if (dumpGraph) { @@ -115,6 +82,13 @@ } public final CharSequence getName() { + if (name == null) { + String s = BasePhase.this.getClass().getSimpleName(); + if (s.endsWith("Phase")) { + s = s.substring(0, s.length() - "Phase".length()); + } + name = s; + } return name; } diff -r bd106238e885 -r aa7bcf1fa423 graal/com.oracle.graal.replacements/src/com/oracle/graal/replacements/ReplacementsImpl.java --- a/graal/com.oracle.graal.replacements/src/com/oracle/graal/replacements/ReplacementsImpl.java Wed Mar 19 15:21:43 2014 +0100 +++ b/graal/com.oracle.graal.replacements/src/com/oracle/graal/replacements/ReplacementsImpl.java Wed Mar 19 16:30:09 2014 +0100 @@ -99,7 +99,7 @@ FrameStateProcessing frameStateProcessing = method.getAnnotation(Snippet.class).removeAllFrameStates() ? FrameStateProcessing.Removal : FrameStateProcessing.CollapseFrameForSingleSideEffect; StructuredGraph newGraph = makeGraph(method, recursiveEntry, recursiveEntry, inliningPolicy(method), frameStateProcessing); - Debug.metric(new MethodDebugValueName("SnippetNodeCount", method)).add(newGraph.getNodeCount()); + Debug.metric("SnippetNodeCount[%#s]", method).add(newGraph.getNodeCount()); if (!UseSnippetGraphCache) { return newGraph; } diff -r bd106238e885 -r aa7bcf1fa423 graal/com.oracle.graal.replacements/src/com/oracle/graal/replacements/SnippetTemplate.java --- a/graal/com.oracle.graal.replacements/src/com/oracle/graal/replacements/SnippetTemplate.java Wed Mar 19 15:21:43 2014 +0100 +++ b/graal/com.oracle.graal.replacements/src/com/oracle/graal/replacements/SnippetTemplate.java Wed Mar 19 16:30:09 2014 +0100 @@ -24,6 +24,8 @@ import static com.oracle.graal.api.meta.LocationIdentity.*; import static com.oracle.graal.api.meta.MetaUtil.*; +import static com.oracle.graal.debug.Debug.*; +import static java.util.FormattableFlags.*; import java.io.*; import java.lang.reflect.*; @@ -97,8 +99,8 @@ protected SnippetInfo(ResolvedJavaMethod method) { this.method = method; - instantiationCounter = Debug.metric(new MethodDebugValueName("SnippetInstantiationCount", method)); - instantiationTimer = Debug.timer(new MethodDebugValueName("SnippetInstantiationTime", method)); + instantiationCounter = Debug.metric("SnippetInstantiationCount[%#s]", method); + instantiationTimer = Debug.timer("SnippetInstantiationTime[%#s]", method); assert Modifier.isStatic(method.getModifiers()) : "snippet method must be static: " + MetaUtil.format("%H.%n", method); int count = method.getSignature().getParameterCount(false); constantParameters = new boolean[count]; @@ -176,7 +178,7 @@ * {@link SnippetTemplate#instantiate instantiated} * */ - public static class Arguments { + public static class Arguments implements Formattable { protected final SnippetInfo info; protected final CacheKey cacheKey; @@ -243,6 +245,30 @@ result.append(">"); return result.toString(); } + + public void formatTo(Formatter formatter, int flags, int width, int precision) { + if ((flags & ALTERNATE) == 0) { + formatter.format(applyFormattingFlagsAndWidth(toString(), flags, width)); + } else { + StringBuilder sb = new StringBuilder(); + sb.append(info.method.getName()).append('('); + String sep = ""; + for (int i = 0; i < info.getParameterCount(); i++) { + if (info.isConstantParameter(i)) { + sb.append(sep); + if (info.names[i] != null) { + sb.append(info.names[i]); + } else { + sb.append(i); + } + sb.append('=').append(values[i]); + sep = ", "; + } + } + sb.append(")"); + formatter.format(applyFormattingFlagsAndWidth(sb.toString(), flags & ~ALTERNATE, width)); + } + } } /** @@ -440,38 +466,13 @@ return false; } - private static String debugValueName(String category, Arguments args) { - if (Debug.isEnabled()) { - StringBuilder result = new StringBuilder(category).append('['); - SnippetInfo info = args.info; - result.append(info.method.getName()).append('('); - String sep = ""; - for (int i = 0; i < info.getParameterCount(); i++) { - if (info.isConstantParameter(i)) { - result.append(sep); - if (info.names[i] != null) { - result.append(info.names[i]); - } else { - result.append(i); - } - result.append('=').append(args.values[i]); - sep = ", "; - } - } - result.append(")]"); - return result.toString(); - - } - return null; - } - /** * Creates a snippet template. */ protected SnippetTemplate(final Providers providers, Arguments args) { StructuredGraph snippetGraph = providers.getReplacements().getSnippet(args.info.method); - instantiationTimer = Debug.timer(debugValueName("SnippetTemplateInstantiationTime", args)); - instantiationCounter = Debug.metric(debugValueName("SnippetTemplateInstantiationCount", args)); + instantiationTimer = Debug.timer("SnippetTemplateInstantiationTime[%#s]", args); + instantiationCounter = Debug.metric("SnippetTemplateInstantiationCount[%#s]", args); ResolvedJavaMethod method = snippetGraph.method(); Signature signature = method.getSignature(); @@ -665,7 +666,7 @@ } } - Debug.metric(debugValueName("SnippetTemplateNodeCount", args)).add(nodes.size()); + Debug.metric("SnippetTemplateNodeCount[%#s]", args).add(nodes.size()); args.info.notifyNewTemplate(); Debug.dump(snippet, "SnippetTemplate final state"); }