Mercurial > hg > truffle
changeset 4406:961895157a38
Tentative implementation of Meter and Time.
line wrap: on
line diff
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/Debug.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/Debug.java Sun Jan 29 01:56:43 2012 +0100 @@ -22,9 +22,7 @@ */ package com.oracle.max.graal.debug; -import com.oracle.max.graal.debug.internal.DebugScope; -import com.oracle.max.graal.debug.internal.MetricImpl; -import com.oracle.max.graal.debug.internal.TimerImpl; +import com.oracle.max.graal.debug.internal.*; import java.util.*; import java.util.concurrent.*; @@ -133,7 +131,7 @@ } public static DebugMetric metric(String name) { - if (ENABLED && DebugScope.getInstance().isMeterEnabled()) { + if (ENABLED) { return new MetricImpl(name); } else { return VOID_METRIC; @@ -187,7 +185,7 @@ }; public static DebugTimer timer(String name) { - if (ENABLED && DebugScope.getInstance().isTimeEnabled()) { + if (ENABLED) { return new TimerImpl(name); } else { return VOID_TIMER; @@ -195,7 +193,6 @@ } private static final DebugTimer VOID_TIMER = new DebugTimer() { - public void start() { } - public void stop() { } + public TimerCloseable start() { return TimerImpl.VOID_CLOSEABLE; } }; }
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/DebugTimer.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/DebugTimer.java Sun Jan 29 01:56:43 2012 +0100 @@ -22,7 +22,8 @@ */ package com.oracle.max.graal.debug; +import com.oracle.max.graal.debug.internal.*; + public interface DebugTimer { - void start(); - void stop(); + TimerCloseable start(); }
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/DebugScope.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/DebugScope.java Sun Jan 29 01:56:43 2012 +0100 @@ -28,12 +28,13 @@ import com.oracle.max.graal.debug.*; - public final class DebugScope { private static ThreadLocal<DebugScope> instanceTL = new ThreadLocal<>(); private static ThreadLocal<DebugConfig> configTL = new ThreadLocal<>(); private static ThreadLocal<RuntimeException> lastExceptionThrownTL = new ThreadLocal<>(); + private static DebugTimer scopeTime = Debug.timer("ScopeTime"); + private static DebugMetric scopeCount = Debug.metric("ScopeCount"); private final DebugScope parent; @@ -42,6 +43,7 @@ private List<DebugScope> children; private DebugValueMap valueMap; private String qualifiedName; + private String name; private static final char SCOPE_SEP = '.'; @@ -53,8 +55,10 @@ public static DebugScope getInstance() { DebugScope result = instanceTL.get(); if (result == null) { - instanceTL.set(new DebugScope("", null)); - return instanceTL.get(); + DebugScope topLevelDebugScope = new DebugScope(Thread.currentThread().getName(), "", null); + instanceTL.set(topLevelDebugScope); + DebugValueMap.registerTopLevel(topLevelDebugScope.getValueMap()); + return topLevelDebugScope; } else { return result; } @@ -64,7 +68,8 @@ return configTL.get(); } - private DebugScope(String qualifiedName, DebugScope parent, Object... context) { + private DebugScope(String name, String qualifiedName, DebugScope parent, Object... context) { + this.name = name; this.parent = parent; this.context = context; this.qualifiedName = qualifiedName; @@ -109,16 +114,20 @@ DebugConfig oldConfig = getConfig(); DebugScope newChild = null; if (sandbox) { - newChild = new DebugScope(newName, null, newContext); + newChild = new DebugScope(newName, newName, null, newContext); setConfig(null); } else { newChild = oldContext.createChild(newName, newContext); } instanceTL.set(newChild); newChild.updateFlags(); - try { + scopeCount.increment(); + try (TimerCloseable a = scopeTime.start()) { return executeScope(runnable, callable); } finally { + if (!sandbox && newChild.hasValueMap()) { + getValueMap().addChild(newChild.getValueMap()); + } newChild.deactivate(); instanceTL.set(oldContext); setConfig(oldConfig); @@ -168,7 +177,8 @@ private RuntimeException interceptException(final RuntimeException e) { final DebugConfig config = getConfig(); if (config != null) { - return scope("InterceptException", null, new Callable<RuntimeException>(){ + return scope("InterceptException", null, new Callable<RuntimeException>() { + @Override public RuntimeException call() throws Exception { try { @@ -176,18 +186,23 @@ } catch (Throwable t) { return e; } - }}, false, new Object[]{e}); + } + }, false, new Object[] {e}); } return e; } private DebugValueMap getValueMap() { if (valueMap == null) { - valueMap = new DebugValueMap(); + valueMap = new DebugValueMap(name); } return valueMap; } + private boolean hasValueMap() { + return valueMap != null; + } + long getCurrentValue(int index) { return getValueMap().getCurrentValue(index); } @@ -201,7 +216,7 @@ if (this.qualifiedName.length() > 0) { newQualifiedName = this.qualifiedName + SCOPE_SEP + newName; } - DebugScope result = new DebugScope(newQualifiedName, this, newContext); + DebugScope result = new DebugScope(newName, newQualifiedName, this, newContext); if (children == null) { children = new ArrayList<>(4); } @@ -277,4 +292,3 @@ cachedOut = System.out; } } -
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/DebugValue.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/DebugValue.java Sun Jan 29 01:56:43 2012 +0100 @@ -44,11 +44,19 @@ private void ensureInitialized() { if (index == -1) { - index = KeyRegistry.register(name); + index = KeyRegistry.register(name, this); } } protected void addToCurrentValue(long timeSpan) { setCurrentValue(getCurrentValue() + timeSpan); } + + public int getIndex() { + return index; + } + + public String getName() { + return name; + } }
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/DebugValueMap.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/DebugValueMap.java Sun Jan 29 01:56:43 2012 +0100 @@ -22,11 +22,19 @@ */ package com.oracle.max.graal.debug.internal; -import java.util.Arrays; +import java.util.*; public class DebugValueMap { + private static List<DebugValueMap> topLevelMaps = new ArrayList<>(); + private long[] values; + private List<DebugValueMap> children; + private String name; + + public DebugValueMap(String name) { + this.name = name; + } public void setCurrentValue(int index, long l) { ensureSize(index); @@ -46,4 +54,96 @@ values = Arrays.copyOf(values, index + 1); } } + + private int capacity() { + return (values == null) ? 0 : values.length; + } + + public void addChild(DebugValueMap map) { + if (children == null) { + children = new ArrayList<>(4); + } + children.add(map); + } + + public List<DebugValueMap> getChildren() { + if (children == null) { + return Collections.emptyList(); + } else { + return Collections.unmodifiableList(children); + } + } + + public boolean hasChildren() { + return children != null && !children.isEmpty(); + } + + public String getName() { + return this.name; + } + + @Override + public String toString() { + return "DebugValueMap<" + getName() + ">"; + } + + public static synchronized void registerTopLevel(DebugValueMap map) { + topLevelMaps.add(map); + } + + public static synchronized List<DebugValueMap> getTopLevelMaps() { + return topLevelMaps; + } + + public void normalize() { + if (this.hasChildren()) { + Map<String, DebugValueMap> occurred = new HashMap<>(); + for (DebugValueMap map : this.children) { + String mapName = map.getName(); + if (!occurred.containsKey(mapName)) { + occurred.put(mapName, map); + map.normalize(); + } else { + occurred.get(mapName).mergeWith(map); + occurred.get(mapName).normalize(); + } + } + + if (occurred.values().size() < children.size()) { + // At least one duplicate was found. + children.clear(); + for (DebugValueMap map : occurred.values()) { + children.add(map); + map.normalize(); + } + } + } + } + + private void mergeWith(DebugValueMap map) { + if (map.hasChildren()) { + if (hasChildren()) { + children.addAll(map.children); + } else { + children = map.children; + } + map.children = null; + } + + int size = Math.max(this.capacity(), map.capacity()); + ensureSize(size); + for (int i = 0; i < size; ++i) { + long curValue = getCurrentValue(i); + long otherValue = map.getCurrentValue(i); + setCurrentValue(i, curValue + otherValue); + } + } + + public void group() { + List<DebugValueMap> oldChildren = new ArrayList<>(this.children); + this.children.clear(); + for (DebugValueMap map : oldChildren) { + mergeWith(map); + } + } }
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/KeyRegistry.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/KeyRegistry.java Sun Jan 29 01:56:43 2012 +0100 @@ -22,19 +22,22 @@ */ package com.oracle.max.graal.debug.internal; -import java.util.HashMap; -import java.util.Map; +import java.util.*; public class KeyRegistry { - private static int keyCount; private static Map<String, Integer> keyMap = new HashMap<>(); + private static List<DebugValue> debugValues = new ArrayList<>(); - public static synchronized int register(String name) { + public static synchronized int register(String name, DebugValue value) { if (!keyMap.containsKey(name)) { keyMap.put(name, keyCount++); + debugValues.add(value); } return keyMap.get(name); } + public static synchronized List<DebugValue> getDebugValues() { + return Collections.unmodifiableList(debugValues); + } }
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/MetricImpl.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/MetricImpl.java Sun Jan 29 01:56:43 2012 +0100 @@ -35,6 +35,8 @@ } public void add(int value) { - super.addToCurrentValue(value); + if (Debug.isMeterEnabled()) { + super.addToCurrentValue(value); + } } }
--- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/TimerCloseable.java Sun Jan 29 01:56:43 2012 +0100 @@ -0,0 +1,27 @@ +/* + * Copyright (c) 2012, 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.max.graal.debug.internal; + +public interface TimerCloseable extends AutoCloseable { + void close(); +}
--- a/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/TimerImpl.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.debug/src/com/oracle/max/graal/debug/internal/TimerImpl.java Sun Jan 29 01:56:43 2012 +0100 @@ -26,20 +26,29 @@ public final class TimerImpl extends DebugValue implements DebugTimer { - private long startTime = -1; + public static final TimerCloseable VOID_CLOSEABLE = new TimerCloseable() { + @Override + public void close() { + } + }; public TimerImpl(String name) { super(name); } @Override - public void start() { - startTime = System.currentTimeMillis(); - } - - @Override - public void stop() { - long timeSpan = System.currentTimeMillis() - startTime; - super.addToCurrentValue(timeSpan); + public TimerCloseable start() { + if (Debug.isTimeEnabled()) { + final long startTime = System.currentTimeMillis(); + return new TimerCloseable() { + @Override + public void close() { + long timeSpan = System.currentTimeMillis() - startTime; + TimerImpl.this.addToCurrentValue(timeSpan); + } + }; + } else { + return VOID_CLOSEABLE; + } } }
--- a/graal/com.oracle.max.graal.hotspot/src/com/oracle/max/graal/hotspot/bridge/VMToCompilerImpl.java Sun Jan 29 00:06:40 2012 +0100 +++ b/graal/com.oracle.max.graal.hotspot/src/com/oracle/max/graal/hotspot/bridge/VMToCompilerImpl.java Sun Jan 29 01:56:43 2012 +0100 @@ -24,6 +24,7 @@ package com.oracle.max.graal.hotspot.bridge; import java.lang.reflect.*; +import java.util.*; import java.util.concurrent.*; import com.oracle.max.cri.ci.*; @@ -33,6 +34,7 @@ import com.oracle.max.graal.compiler.phases.*; import com.oracle.max.graal.compiler.phases.PhasePlan.PhasePosition; import com.oracle.max.graal.debug.*; +import com.oracle.max.graal.debug.internal.*; import com.oracle.max.graal.hotspot.*; import com.oracle.max.graal.hotspot.Compiler; import com.oracle.max.graal.hotspot.ri.*; @@ -59,12 +61,15 @@ public final HotSpotTypePrimitive typeVoid; ThreadFactory compilerThreadFactory = new ThreadFactory() { + @Override public Thread newThread(Runnable r) { return new CompilerThread(r); } }; + private final class CompilerThread extends Thread { + public CompilerThread(Runnable r) { super(r); this.setName("GraalCompilerThread-" + this.getId()); @@ -81,6 +86,7 @@ super.run(); } } + private ThreadPoolExecutor compileQueue; public VMToCompilerImpl(Compiler compiler) { @@ -115,6 +121,7 @@ // Create queue status printing thread. if (GraalOptions.PrintQueue) { Thread t = new Thread() { + @Override public void run() { while (true) { @@ -132,9 +139,9 @@ } /** - * This method is the first method compiled during bootstrapping. Put any code in there that - * warms up compiler paths that are otherwise no exercised during bootstrapping and lead to later - * deoptimization when application code is compiled. + * This method is the first method compiled during bootstrapping. Put any code in there that warms up compiler paths + * that are otherwise no exercised during bootstrapping and lead to later deoptimization when application code is + * compiled. */ @SuppressWarnings("unused") @Deprecated @@ -175,9 +182,46 @@ } public void shutdownCompiler() throws Throwable { -// compiler.getCompiler().context.print(); +// compiler.getCompiler().context.print(); // TODO(tw): Print context results. compileQueue.shutdown(); + + if (Debug.isEnabled()) { + List<DebugValueMap> topLevelMaps = DebugValueMap.getTopLevelMaps(); + List<DebugValue> debugValues = KeyRegistry.getDebugValues(); + if (debugValues.size() > 0) { + for (DebugValueMap map : topLevelMaps) { + TTY.println("Showing the results for thread: " + map.getName()); + map.group(); + map.normalize(); + printMap(map, debugValues, 0); + } + } + } + } + + private void printMap(DebugValueMap map, List<DebugValue> debugValues, int level) { + + printIndent(level); + TTY.println(map.getName()); + for (DebugValue value : debugValues) { + long l = map.getCurrentValue(value.getIndex()); + if (l != 0) { + printIndent(level + 1); + TTY.println(value.getName() + "=" + l); + } + } + + for (DebugValueMap child : map.getChildren()) { + printMap(child, debugValues, level + 1); + } + } + + private static void printIndent(int level) { + for (int i = 0; i < level; ++i) { + TTY.print(" "); + } + TTY.print("|-> "); } @Override @@ -188,6 +232,7 @@ } Runnable runnable = new Runnable() { + public void run() { try { PhasePlan plan = new PhasePlan(); @@ -197,11 +242,7 @@ int index = compiledMethodCount++; final boolean printCompilation = GraalOptions.PrintCompilation && !TTY.isSuppressed(); if (printCompilation) { - TTY.println(String.format("Graal %4d %-70s %-45s %-50s ...", - index, - method.holder().name(), - method.name(), - method.signature().asString())); + TTY.println(String.format("Graal %4d %-70s %-45s %-50s ...", index, method.holder().name(), method.name(), method.signature().asString())); startTime = System.nanoTime(); } @@ -213,15 +254,8 @@ filter.remove(); if (printCompilation) { long time = (System.nanoTime() - startTime) / 100000; - TTY.println(String.format("Graal %4d %-70s %-45s %-50s | %3d.%dms %4dnodes %5dB", - index, - "", - "", - "", - time / 10, - time % 10, - 0, - (result != null ? result.targetCodeSize() : -1))); + TTY.println(String.format("Graal %4d %-70s %-45s %-50s | %3d.%dms %4dnodes %5dB", index, "", "", "", time / 10, time % 10, 0, (result != null ? result.targetCodeSize() + : -1))); } } compiler.getRuntime().installMethod(method, result);