Mercurial > hg > truffle

changeset 11873:8a201c64cd18

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
in-depth profiling of allocations and monitors
author Lukas Stadler <lukas.stadler@jku.at>
date Wed, 02 Oct 2013 15:05:04 +0200
parents 5501a34d43bb
children e0041af765c5
files graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/replacements/MonitorSnippets.java graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/replacements/NewObjectSnippets.java
diffstat 2 files changed, 98 insertions(+), 20 deletions(-) [+]
line wrap: on
line diff
--- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/replacements/MonitorSnippets.java	Wed Oct 02 15:04:04 2013 +0200
+++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/replacements/MonitorSnippets.java	Wed Oct 02 15:05:04 2013 +0200
@@ -40,14 +40,17 @@
 import com.oracle.graal.graph.iterators.*;
 import com.oracle.graal.hotspot.nodes.*;
 import com.oracle.graal.nodes.*;
+import com.oracle.graal.nodes.debug.*;
 import com.oracle.graal.nodes.extended.*;
 import com.oracle.graal.nodes.java.*;
 import com.oracle.graal.nodes.java.MethodCallTargetNode.InvokeKind;
 import com.oracle.graal.nodes.spi.*;
 import com.oracle.graal.nodes.type.*;
+import com.oracle.graal.options.*;
 import com.oracle.graal.phases.common.*;
 import com.oracle.graal.replacements.*;
 import com.oracle.graal.replacements.Snippet.ConstantParameter;
+import com.oracle.graal.replacements.Snippet.Fold;
 import com.oracle.graal.replacements.SnippetTemplate.AbstractTemplates;
 import com.oracle.graal.replacements.SnippetTemplate.Arguments;
 import com.oracle.graal.replacements.SnippetTemplate.SnippetInfo;
@@ -63,6 +66,22 @@
  */
 public class MonitorSnippets implements Snippets {
 
+    public static class Options {
+
+        //@formatter:off
+        @Option(help = "")
+        private static final OptionValue<Boolean> ProfileMonitors = new OptionValue<>(false);
+        //@formatter:on
+    }
+
+    private static final boolean PROFILE_CONTEXT = false;
+
+    @Fold
+    @SuppressWarnings("unused")
+    private static boolean doProfile(String path) {
+        return Options.ProfileMonitors.getValue();
+    }
+
     /**
      * Monitor operations on objects whose type contains this substring will be traced.
      */
@@ -118,7 +137,7 @@
                 trace(trace, "              tmp: 0x%016lx\n", tmp);
                 if (probability(FREQUENT_PROBABILITY, tmp.equal(0))) {
                     // Object is already biased to current thread -> done
-                    traceObject(trace, "+lock{bias:existing}", object);
+                    traceObject(trace, "+lock{bias:existing}", object, true);
                     return;
                 }
 
@@ -154,13 +173,13 @@
                         trace(trace, "       biasedMark: 0x%016lx\n", biasedMark);
                         if (probability(VERY_FAST_PATH_PROBABILITY, compareAndSwap(object, markOffset(), unbiasedMark, biasedMark, MARK_WORD_LOCATION).equal(unbiasedMark))) {
                             // Object is now biased to current thread -> done
-                            traceObject(trace, "+lock{bias:acquired}", object);
+                            traceObject(trace, "+lock{bias:acquired}", object, true);
                             return;
                         }
                         // If the biasing toward our thread failed, this means that another thread
                         // owns the bias and we need to revoke that bias. The revocation will occur
                         // in the interpreter runtime.
-                        traceObject(trace, "+lock{stub:revoke}", object);
+                        traceObject(trace, "+lock{stub:revoke}", object, true);
                         monitorenterStub(MONITORENTER, object, lock);
                         return;
                     } else {
@@ -174,13 +193,13 @@
                         trace(trace, "       biasedMark: 0x%016lx\n", biasedMark);
                         if (probability(VERY_FAST_PATH_PROBABILITY, compareAndSwap(object, markOffset(), mark, biasedMark, MARK_WORD_LOCATION).equal(mark))) {
                             // Object is now biased to current thread -> done
-                            traceObject(trace, "+lock{bias:transfer}", object);
+                            traceObject(trace, "+lock{bias:transfer}", object, true);
                             return;
                         }
                         // If the biasing toward our thread failed, then another thread
                         // succeeded in biasing it toward itself and we need to revoke that
                         // bias. The revocation will occur in the runtime in the slow case.
-                        traceObject(trace, "+lock{stub:epoch-expired}", object);
+                        traceObject(trace, "+lock{stub:epoch-expired}", object, true);
                         monitorenterStub(MONITORENTER, object, lock);
                         return;
                     }
@@ -237,16 +256,16 @@
             final Word stackPointer = stackPointer();
             if (probability(VERY_SLOW_PATH_PROBABILITY, currentMark.subtract(stackPointer).and(alignedMask.subtract(pageSize())).notEqual(0))) {
                 // Most likely not a recursive lock, go into a slow runtime call
-                traceObject(trace, "+lock{stub:failed-cas}", object);
+                traceObject(trace, "+lock{stub:failed-cas}", object, true);
                 monitorenterStub(MONITORENTER, object, lock);
                 return;
             } else {
                 // Recursively locked => write 0 to the lock slot
                 lock.writeWord(lockDisplacedMarkOffset(), Word.zero(), DISPLACED_MARK_WORD_LOCATION);
-                traceObject(trace, "+lock{recursive}", object);
+                traceObject(trace, "+lock{recursive}", object, true);
             }
         } else {
-            traceObject(trace, "+lock{cas}", object);
+            traceObject(trace, "+lock{cas}", object, true);
         }
     }
 
@@ -263,7 +282,7 @@
         // BeginLockScope nodes do not read from object so a use of object
         // cannot float about the null check above
         final Word lock = beginLockScope(lockDepth);
-        traceObject(trace, "+lock{stub}", object);
+        traceObject(trace, "+lock{stub}", object, true);
         monitorenterStub(MONITORENTER, object, lock);
     }
 
@@ -282,7 +301,7 @@
             if (probability(FREQUENT_PROBABILITY, mark.and(biasedLockMaskInPlace()).equal(Word.unsigned(biasedLockPattern())))) {
                 endLockScope();
                 decCounter();
-                traceObject(trace, "-lock{bias}", object);
+                traceObject(trace, "-lock{bias}", object, false);
                 return;
             }
         }
@@ -295,7 +314,7 @@
 
         if (displacedMark.equal(0)) {
             // Recursive locking => done
-            traceObject(trace, "-lock{recursive}", object);
+            traceObject(trace, "-lock{recursive}", object, false);
         } else {
             verifyOop(object);
             // Test if object's mark word is pointing to the displaced mark word, and if so, restore
@@ -304,10 +323,10 @@
             if (probability(VERY_SLOW_PATH_PROBABILITY, DirectCompareAndSwapNode.compareAndSwap(object, markOffset(), lock, displacedMark, MARK_WORD_LOCATION).notEqual(lock))) {
                 // The object's mark word was not pointing to the displaced header,
                 // we do unlocking via runtime call.
-                traceObject(trace, "-lock{stub}", object);
+                traceObject(trace, "-lock{stub}", object, false);
                 MonitorExitStubCall.call(object, lockDepth);
             } else {
-                traceObject(trace, "-lock{cas}", object);
+                traceObject(trace, "-lock{cas}", object, false);
             }
         }
         endLockScope();
@@ -320,13 +339,16 @@
     @Snippet
     public static void monitorexitStub(Object object, @ConstantParameter int lockDepth, @ConstantParameter boolean trace) {
         verifyOop(object);
-        traceObject(trace, "-lock{stub}", object);
+        traceObject(trace, "-lock{stub}", object, false);
         MonitorExitStubCall.call(object, lockDepth);
         endLockScope();
         decCounter();
     }
 
-    private static void traceObject(boolean enabled, String action, Object object) {
+    private static void traceObject(boolean enabled, String action, Object object, boolean enter) {
+        if (doProfile(action)) {
+            DynamicCounterNode.counter(action, enter ? "~monitorenter" : "~monitorexit", 1, PROFILE_CONTEXT);
+        }
         if (enabled) {
             Log.print(action);
             Log.print(' ');
--- a/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/replacements/NewObjectSnippets.java	Wed Oct 02 15:04:04 2013 +0200
+++ b/graal/com.oracle.graal.hotspot/src/com/oracle/graal/hotspot/replacements/NewObjectSnippets.java	Wed Oct 02 15:05:04 2013 +0200
@@ -34,17 +34,21 @@
 import com.oracle.graal.api.code.*;
 import com.oracle.graal.api.meta.*;
 import com.oracle.graal.debug.*;
+import com.oracle.graal.graph.*;
 import com.oracle.graal.graph.Node.ConstantNodeParameter;
 import com.oracle.graal.graph.Node.NodeIntrinsic;
 import com.oracle.graal.hotspot.meta.*;
 import com.oracle.graal.hotspot.nodes.*;
 import com.oracle.graal.nodes.*;
+import com.oracle.graal.nodes.debug.*;
 import com.oracle.graal.nodes.extended.*;
 import com.oracle.graal.nodes.java.*;
 import com.oracle.graal.nodes.spi.*;
 import com.oracle.graal.nodes.type.*;
+import com.oracle.graal.options.*;
 import com.oracle.graal.replacements.*;
 import com.oracle.graal.replacements.Snippet.ConstantParameter;
+import com.oracle.graal.replacements.Snippet.Fold;
 import com.oracle.graal.replacements.Snippet.VarargsParameter;
 import com.oracle.graal.replacements.SnippetTemplate.AbstractTemplates;
 import com.oracle.graal.replacements.SnippetTemplate.Arguments;
@@ -59,6 +63,20 @@
 
     public static final LocationIdentity INIT_LOCATION = new NamedLocationIdentity("Initialization");
 
+    public static class Options {
+
+        //@formatter:off
+        @Option(help = "")
+        private static final OptionValue<Boolean> ProfileAllocations = new OptionValue<>(false);
+        //@formatter:on
+    }
+
+    static enum ProfileMode {
+        AllocatingMethods, InstanceOrArray, AllocatedTypes, AllocatedTypesInMethods, Total
+    }
+
+    public static final ProfileMode PROFILE_MODE = ProfileMode.Total;
+
     @Snippet
     public static Word allocate(int size) {
         Word thread = thread();
@@ -76,8 +94,41 @@
         return Word.zero();
     }
 
+    @Fold
+    private static String createName(String path, String typeContext) {
+        switch (PROFILE_MODE) {
+            case AllocatingMethods:
+                return "";
+            case InstanceOrArray:
+                return path;
+            case AllocatedTypes:
+            case AllocatedTypesInMethods:
+                return typeContext;
+            case Total:
+                return "bytes";
+            default:
+                throw GraalInternalError.shouldNotReachHere();
+        }
+    }
+
+    @Fold
+    @SuppressWarnings("unused")
+    private static boolean doProfile(String path, String typeContext) {
+        return Options.ProfileAllocations.getValue();
+    }
+
+    private static void profileAllocation(String path, long size, String typeContext) {
+        if (doProfile(path, typeContext)) {
+            String name = createName(path, typeContext);
+
+            boolean context = PROFILE_MODE == ProfileMode.AllocatingMethods || PROFILE_MODE == ProfileMode.AllocatedTypesInMethods;
+            DynamicCounterNode.counter(name, "~bytes", size, context);
+            DynamicCounterNode.counter(name, "~sites", 1, context);
+        }
+    }
+
     @Snippet
-    public static Object allocateInstance(@ConstantParameter int size, Word hub, Word prototypeMarkWord, @ConstantParameter boolean fillContents) {
+    public static Object allocateInstance(@ConstantParameter int size, Word hub, Word prototypeMarkWord, @ConstantParameter boolean fillContents, @ConstantParameter String typeContext) {
         Object result;
         Word thread = thread();
         Word top = readTlabTop(thread);
@@ -90,6 +141,7 @@
             new_stub.inc();
             result = NewInstanceStubCall.call(hub);
         }
+        profileAllocation("instance", size, typeContext);
         return piCast(verifyOop(result), StampFactory.forNodeIntrinsic());
     }
 
@@ -99,15 +151,16 @@
     public static final int MAX_ARRAY_FAST_PATH_ALLOCATION_LENGTH = 0x00FFFFFF;
 
     @Snippet
-    public static Object allocateArray(Word hub, int length, Word prototypeMarkWord, @ConstantParameter int headerSize, @ConstantParameter int log2ElementSize, @ConstantParameter boolean fillContents) {
+    public static Object allocateArray(Word hub, int length, Word prototypeMarkWord, @ConstantParameter int headerSize, @ConstantParameter int log2ElementSize,
+                    @ConstantParameter boolean fillContents, @ConstantParameter String typeContext) {
         if (!belowThan(length, MAX_ARRAY_FAST_PATH_ALLOCATION_LENGTH)) {
             // This handles both negative array sizes and very large array sizes
             DeoptimizeNode.deopt(DeoptimizationAction.None, DeoptimizationReason.RuntimeConstraint);
         }
-        return allocateArrayImpl(hub, length, prototypeMarkWord, headerSize, log2ElementSize, fillContents);
+        return allocateArrayImpl(hub, length, prototypeMarkWord, headerSize, log2ElementSize, fillContents, typeContext);
     }
 
-    private static Object allocateArrayImpl(Word hub, int length, Word prototypeMarkWord, int headerSize, int log2ElementSize, boolean fillContents) {
+    private static Object allocateArrayImpl(Word hub, int length, Word prototypeMarkWord, int headerSize, int log2ElementSize, boolean fillContents, String typeContext) {
         Object result;
         int alignment = wordSize();
         int allocationSize = computeArrayAllocationSize(length, alignment, headerSize, log2ElementSize);
@@ -123,6 +176,7 @@
             newarray_stub.inc();
             result = NewArrayStubCall.call(hub, length);
         }
+        profileAllocation("array", allocationSize, typeContext);
         return piArrayCast(verifyOop(result), length, StampFactory.forNodeIntrinsic());
     }
 
@@ -156,7 +210,7 @@
         int log2ElementSize = (layoutHelper >> layoutHelperLog2ElementSizeShift()) & layoutHelperLog2ElementSizeMask();
         Word prototypeMarkWord = hub.readWord(prototypeMarkWordOffset(), PROTOTYPE_MARK_WORD_LOCATION);
 
-        return allocateArrayImpl(hub, length, prototypeMarkWord, headerSize, log2ElementSize, fillContents);
+        return allocateArrayImpl(hub, length, prototypeMarkWord, headerSize, log2ElementSize, fillContents, "dynamic type");
     }
 
     /**
@@ -261,6 +315,7 @@
             args.add("hub", hub);
             args.add("prototypeMarkWord", type.prototypeMarkWord());
             args.addConst("fillContents", newInstanceNode.fillContents());
+            args.addConst("typeContext", MetaUtil.toJavaName(type, false));
 
             SnippetTemplate template = template(args);
             Debug.log("Lowering allocateInstance in %s: node=%s, template=%s, arguments=%s", graph, newInstanceNode, template, args);
@@ -286,6 +341,7 @@
             args.addConst("headerSize", headerSize);
             args.addConst("log2ElementSize", log2ElementSize);
             args.addConst("fillContents", newArrayNode.fillContents());
+            args.addConst("typeContext", MetaUtil.toJavaName(arrayType, false));
 
             SnippetTemplate template = template(args);
             Debug.log("Lowering allocateArray in %s: node=%s, template=%s, arguments=%s", graph, newArrayNode, template, args);