# HG changeset patch # User Doug Simon # Date 1411388809 -7200 # Node ID 2cb007e99ed062bc62f47c00d064a411557f3db0 # Parent 6c299422ba2399b38bf2473ac339daf21ae015f3 added support for getting the flat time from a DebugTimer diff -r 6c299422ba23 -r 2cb007e99ed0 graal/com.oracle.graal.debug.test/src/com/oracle/graal/debug/test/DebugTimerTest.java --- /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); + } + } + } +} diff -r 6c299422ba23 -r 2cb007e99ed0 graal/com.oracle.graal.debug/src/com/oracle/graal/debug/DebugTimer.java --- 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; + } } diff -r 6c299422ba23 -r 2cb007e99ed0 graal/com.oracle.graal.debug/src/com/oracle/graal/debug/internal/TimerImpl.java --- 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 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