changeset 17174:2cb007e99ed0

added support for getting the flat time from a DebugTimer
author Doug Simon <doug.simon@oracle.com>
date Mon, 22 Sep 2014 14:26:49 +0200
parents 6c299422ba23
children 63870b298b39
files graal/com.oracle.graal.debug.test/src/com/oracle/graal/debug/test/DebugTimerTest.java graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugTimer.java graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/TimerImpl.java
diffstat 3 files changed, 182 insertions(+), 19 deletions(-) [+]
line wrap: on
line diff
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/graal/com.oracle.graal.debug.test/src/com/oracle/graal/debug/test/DebugTimerTest.java	Mon Sep 22 14:26:49 2014 +0200
@@ -0,0 +1,118 @@
+/*
+ * Copyright (c) 2013, 2013, 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.graal.debug.test;
+
+import static org.junit.Assert.*;
+
+import org.junit.*;
+
+import com.oracle.graal.debug.*;
+import com.oracle.graal.debug.internal.*;
+
+public class DebugTimerTest {
+
+    private static void sleep(long millis) {
+        try {
+            Thread.sleep(millis);
+        } catch (InterruptedException e) {
+        }
+    }
+
+    @Test
+    public void test1() {
+        DebugConfig debugConfig = Debug.fixedConfig(0, 0, false, false, true, false, null, null, System.out);
+        try (DebugConfigScope dcs = new DebugConfigScope(debugConfig); Debug.Scope s = Debug.scope("DebugTimerTest")) {
+
+            DebugTimer timerA = Debug.timer("TimerA");
+            DebugTimer timerB = Debug.timer("TimerB");
+
+            try (TimerCloseable a1 = timerA.start()) {
+                sleep(50);
+                try (TimerCloseable b1 = timerB.start()) {
+                    sleep(50);
+                }
+            }
+
+            Assert.assertTrue(timerB.getCurrentValue() < timerA.getCurrentValue());
+            if (timerA.getFlat() != null && timerB.getFlat() != null) {
+                assertTrue(timerB.getFlat().getCurrentValue() < timerA.getFlat().getCurrentValue());
+                assertEquals(timerA.getFlat().getCurrentValue(), timerA.getCurrentValue() - timerB.getFlat().getCurrentValue(), 10D);
+            }
+        }
+    }
+
+    @Test
+    public void test2() {
+        DebugConfig debugConfig = Debug.fixedConfig(0, 0, false, false, true, false, null, null, System.out);
+        try (DebugConfigScope dcs = new DebugConfigScope(debugConfig); Debug.Scope s = Debug.scope("DebugTimerTest")) {
+            DebugTimer timerC = Debug.timer("TimerC");
+            try (TimerCloseable c1 = timerC.start()) {
+                sleep(50);
+                try (TimerCloseable c2 = timerC.start()) {
+                    sleep(50);
+                    try (TimerCloseable c3 = timerC.start()) {
+                        sleep(50);
+                        try (TimerCloseable c4 = timerC.start()) {
+                            sleep(50);
+                            try (TimerCloseable c5 = timerC.start()) {
+                                sleep(50);
+                            }
+                        }
+                    }
+                }
+            }
+            if (timerC.getFlat() != null) {
+                assertEquals(timerC.getFlat().getCurrentValue(), timerC.getCurrentValue());
+            }
+        }
+    }
+
+    @Test
+    public void test3() {
+        DebugConfig debugConfig = Debug.fixedConfig(0, 0, false, false, true, false, null, null, System.out);
+        try (DebugConfigScope dcs = new DebugConfigScope(debugConfig); Debug.Scope s = Debug.scope("DebugTimerTest")) {
+
+            DebugTimer timerD = Debug.timer("TimerD");
+            DebugTimer timerE = Debug.timer("TimerE");
+
+            try (TimerCloseable d1 = timerD.start()) {
+                sleep(50);
+                try (TimerCloseable e1 = timerE.start()) {
+                    sleep(50);
+                    try (TimerCloseable d2 = timerD.start()) {
+                        sleep(50);
+                        try (TimerCloseable d3 = timerD.start()) {
+                            sleep(50);
+                        }
+                    }
+                }
+            }
+
+            Assert.assertTrue(timerE.getCurrentValue() < timerD.getCurrentValue());
+            if (timerD.getFlat() != null && timerE.getFlat() != null) {
+                assertTrue(timerE.getFlat().getCurrentValue() < timerD.getFlat().getCurrentValue());
+                assertEquals(timerD.getFlat().getCurrentValue(), timerD.getCurrentValue() - timerE.getFlat().getCurrentValue(), 10D);
+            }
+        }
+    }
+}
--- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugTimer.java	Mon Sep 22 14:25:42 2014 +0200
+++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugTimer.java	Mon Sep 22 14:26:49 2014 +0200
@@ -67,4 +67,14 @@
      * Gets the time unit of this timer.
      */
     TimeUnit getTimeUnit();
+
+    /**
+     * Gets the timer recording the amount time spent within a timed scope minus the time spent in
+     * any nested timed scopes.
+     *
+     * @return null if this timer does not support flat timing
+     */
+    default DebugTimer getFlat() {
+        return null;
+    }
 }
--- a/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/TimerImpl.java	Mon Sep 22 14:25:42 2014 +0200
+++ b/graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/TimerImpl.java	Mon Sep 22 14:26:49 2014 +0200
@@ -43,17 +43,33 @@
      */
     private static final ThreadLocal<AbstractTimer> currentTimer = new ThreadLocal<>();
 
-    private final DebugValue flat;
+    private final FlatTimer flat;
+
+    static class FlatTimer extends DebugValue implements DebugTimer {
+        private final TimerImpl accm;
+
+        public FlatTimer(TimerImpl accm, String name) {
+            super(name + "_Flat", accm.isConditional());
+            this.accm = accm;
+        }
+
+        @Override
+        public String toString(long value) {
+            return valueToString(value);
+        }
+
+        public TimeUnit getTimeUnit() {
+            return accm.getTimeUnit();
+        }
+
+        public TimerCloseable start() {
+            return accm.start();
+        }
+    }
 
     public TimerImpl(String name, boolean conditional) {
         super(name + "_Accm", conditional);
-        this.flat = new DebugValue(name + "_Flat", conditional) {
-
-            @Override
-            public String toString(long value) {
-                return valueToString(value);
-            }
-        };
+        this.flat = new FlatTimer(this, name);
     }
 
     @Override
@@ -68,9 +84,9 @@
 
             AbstractTimer result;
             if (threadMXBean.isCurrentThreadCpuTimeSupported()) {
-                result = new CpuTimeTimer(startTime);
+                result = new CpuTimeTimer(this, startTime);
             } else {
-                result = new SystemNanosTimer(startTime);
+                result = new SystemNanosTimer(this, startTime);
             }
             currentTimer.set(result);
             return result;
@@ -83,6 +99,10 @@
         return String.format("%d.%d ms", value / 1000000, (value / 100000) % 10);
     }
 
+    public DebugTimer getFlat() {
+        return flat;
+    }
+
     @Override
     public String toString(long value) {
         return valueToString(value);
@@ -92,14 +112,16 @@
         return TimeUnit.NANOSECONDS;
     }
 
-    private abstract class AbstractTimer implements TimerCloseable {
+    private static abstract class AbstractTimer implements TimerCloseable {
 
         private final AbstractTimer parent;
+        private final TimerImpl timer;
         private final long startTime;
         private long nestedTimeToSubtract;
 
-        private AbstractTimer(long startTime) {
+        private AbstractTimer(TimerImpl timer, long startTime) {
             this.parent = currentTimer.get();
+            this.timer = timer;
             this.startTime = startTime;
         }
 
@@ -108,12 +130,25 @@
             long endTime = currentTime();
             long timeSpan = endTime - startTime;
             if (parent != null) {
-                parent.nestedTimeToSubtract += timeSpan;
+                if (timer != parent.timer) {
+                    parent.nestedTimeToSubtract += timeSpan;
+
+                    // Look for our timer in an outer timing scope and fix up
+                    // the adjustment to the flat time
+                    AbstractTimer ancestor = parent.parent;
+                    while (ancestor != null) {
+                        if (ancestor.timer == timer) {
+                            ancestor.nestedTimeToSubtract -= timeSpan;
+                            break;
+                        }
+                        ancestor = ancestor.parent;
+                    }
+                }
             }
             currentTimer.set(parent);
             long flatTime = timeSpan - nestedTimeToSubtract;
-            TimerImpl.this.addToCurrentValue(timeSpan);
-            flat.addToCurrentValue(flatTime);
+            timer.addToCurrentValue(timeSpan);
+            timer.flat.addToCurrentValue(flatTime);
         }
 
         protected abstract long currentTime();
@@ -121,8 +156,8 @@
 
     private final class SystemNanosTimer extends AbstractTimer {
 
-        public SystemNanosTimer(long startTime) {
-            super(startTime);
+        public SystemNanosTimer(TimerImpl timer, long startTime) {
+            super(timer, startTime);
         }
 
         @Override
@@ -133,8 +168,8 @@
 
     private final class CpuTimeTimer extends AbstractTimer {
 
-        public CpuTimeTimer(long startTime) {
-            super(startTime);
+        public CpuTimeTimer(TimerImpl timer, long startTime) {
+            super(timer, startTime);
         }
 
         @Override