AutoFormattingTime cleanup and complete unittests

-- Underlying system now uses long nano times to be more consistent with standard java practice
-- Updated a few places in the code that were converting from nanoseconds to double seconds to use the new nanoseconds interface directly
-- Bringing us to 100% test coverage with clover with AutoFormattingTimeUnitTest
This commit is contained in:
Mark DePristo 2013-01-02 08:46:11 -05:00
parent c1c5737f80
commit 12f4c6307e
6 changed files with 229 additions and 22 deletions

View File

@ -284,7 +284,7 @@ public abstract class MicroScheduler implements MicroSchedulerMBean {
protected boolean abortExecution() {
final boolean abort = engine.exceedsRuntimeLimit(progressMeter.getRuntimeInNanoseconds(), TimeUnit.NANOSECONDS);
if ( abort ) {
final AutoFormattingTime aft = new AutoFormattingTime(TimeUnit.SECONDS.convert(engine.getRuntimeLimitInNanoseconds(), TimeUnit.NANOSECONDS), 1, 4);
final AutoFormattingTime aft = new AutoFormattingTime(engine.getRuntimeLimitInNanoseconds(), -1, 4);
logger.info("Aborting execution (cleanly) because the runtime has exceeded the requested maximum " + aft);
}
return abort;

View File

@ -50,7 +50,7 @@ public class ExactCallLogger implements Cloneable {
return String.format("ExactCall %s:%d alleles=%s nSamples=%s orig.pNonRef=%.2f orig.runtime=%s",
vc.getChr(), vc.getStart(), vc.getAlleles(), vc.getNSamples(),
originalCall.getLog10PosteriorOfAFGT0(),
new AutoFormattingTime(runtime / 1e9).toString());
new AutoFormattingTime(runtime).toString());
}
}

View File

@ -1,32 +1,104 @@
package org.broadinstitute.sting.utils;
import java.util.concurrent.TimeUnit;
/**
* Simple utility class that makes it convenient to print unit adjusted times
* Conveniently print a time with an automatically determined time unit
*
* For example, if the amount of time is 10^6 seconds, instead of printing
* out 10^6 seconds, prints out 11.57 days instead.
*
* Dynamically uses time units:
*
* - seconds: s
* - minutes: m
* - hours : h
* - days : d
* - weeks : w
*
* @author depristo
* @since 2009
*/
public class AutoFormattingTime {
private static final double NANOSECONDS_PER_SECOND = 1e9;
/**
* Width a la format's %WIDTH.PERCISIONf
*/
private final int width; // for format
/**
* Precision a la format's %WIDTH.PERCISIONf
*/
private final int precision; // for format
double timeInSeconds; // in Seconds
private final String formatString;
/**
* The elapsed time in nanoseconds
*/
private final long nanoTime;
/**
* Create a new autoformatting time with elapsed time nanoTime in nanoseconds
* @param nanoTime the elapsed time in nanoseconds
* @param width the width >= 0 (a la format's %WIDTH.PERCISIONf) to use to display the format, or -1 if none is required
* @param precision the precision to display the time at. Must be >= 0;
*/
public AutoFormattingTime(final long nanoTime, final int width, int precision) {
if ( width < -1 ) throw new IllegalArgumentException("Width " + width + " must be >= -1");
if ( precision < 0 ) throw new IllegalArgumentException("Precision " + precision + " must be >= 0");
public AutoFormattingTime(double timeInSeconds, final int width, int precision) {
this.width = width;
this.timeInSeconds = timeInSeconds;
this.nanoTime = nanoTime;
this.precision = precision;
this.formatString = "%" + width + "." + precision + "f %s";
}
public AutoFormattingTime(double timeInSeconds, int precision) {
this(timeInSeconds, 6, precision);
/**
* @see #AutoFormattingTime(long, int, int) but with default width and precision
* @param nanoTime
*/
public AutoFormattingTime(final long nanoTime) {
this(nanoTime, 6, 1);
}
/**
* @see #AutoFormattingTime(long, int, int) but with time specificied as a double in seconds
*/
public AutoFormattingTime(final double timeInSeconds, final int width, final int precision) {
this(secondsToNano(timeInSeconds), width, precision);
}
/**
* @see #AutoFormattingTime(long) but with time specificied as a double in seconds
*/
public AutoFormattingTime(double timeInSeconds) {
this(timeInSeconds, 1);
this(timeInSeconds, 6, 1);
}
/**
* Precomputed format string suitable for string.format with the required width and precision
*/
private String getFormatString() {
final StringBuilder b = new StringBuilder("%");
if ( width != -1 )
b.append(width);
b.append(".").append(precision).append("f %s");
return b.toString();
}
/**
* Get the time associated with this object in nanoseconds
* @return the time in nanoseconds
*/
public long getTimeInNanoSeconds() {
return nanoTime;
}
/**
* Get the time associated with this object in seconds, as a double
* @return time in seconds as a double
*/
public double getTimeInSeconds() {
return timeInSeconds;
return TimeUnit.NANOSECONDS.toSeconds(getTimeInNanoSeconds());
}
/**
@ -44,15 +116,16 @@ public class AutoFormattingTime {
}
/**
* Instead of 10000 s, returns 2.8 hours
* @return
* Get a string representation of this time, automatically converting the time
* to a human readable unit with width and precision provided during construction
* @return a non-null string
*/
public String toString() {
double unitTime = timeInSeconds;
double unitTime = getTimeInSeconds();
String unit = "s";
if ( timeInSeconds > 120 ) {
unitTime = timeInSeconds / 60; // minutes
if ( unitTime > 120 ) {
unitTime /= 60; // minutes
unit = "m";
if ( unitTime > 120 ) {
@ -64,13 +137,24 @@ public class AutoFormattingTime {
unit = "d";
if ( unitTime > 20 ) {
unitTime /= 7; // days
unitTime /= 7; // weeks
unit = "w";
}
}
}
}
return String.format(formatString, unitTime, unit);
return String.format(getFormatString(), unitTime, unit);
}
/**
* Convert a time in seconds as a double into nanoseconds as a long
* @param timeInSeconds an elapsed time in seconds, as a double
* @return an equivalent value in nanoseconds as a long
*/
private static long secondsToNano(final double timeInSeconds) {
return (long)(NANOSECONDS_PER_SECOND * timeInSeconds);
}
}

View File

@ -133,7 +133,7 @@ public class ThreadEfficiencyMonitor {
*/
public synchronized void printUsageInformation(final Logger logger, final Priority priority) {
logger.debug("Number of threads monitored: " + getnThreadsAnalyzed());
logger.debug("Total runtime " + new AutoFormattingTime(TimeUnit.MILLISECONDS.toSeconds(getTotalTime())));
logger.debug("Total runtime " + new AutoFormattingTime(TimeUnit.MILLISECONDS.toNanos(getTotalTime())));
for ( final State state : State.values() ) {
logger.debug(String.format("\tPercent of time spent %s is %.2f", state.getUserFriendlyName(), getStatePercent(state)));
}

View File

@ -0,0 +1,117 @@
/*
* Copyright (c) 2012 The Broad Institute
*
* Permission is hereby granted, free of charge, to any person
* obtaining a copy of this software and associated documentation
* files (the "Software"), to deal in the Software without
* restriction, including without limitation the rights to use,
* copy, modify, merge, publish, distribute, sublicense, and/or sell
* copies of the Software, and to permit persons to whom the
* Software is furnished to do so, subject to the following
* conditions:
*
* The above copyright notice and this permission notice shall be
* included in all copies or substantial portions of the Software.
*
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES
* OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
* NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT
* HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY,
* WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
* FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR
* THE USE OR OTHER DEALINGS IN THE SOFTWARE.
*/
package org.broadinstitute.sting;
import org.broadinstitute.sting.utils.AutoFormattingTime;
import org.testng.Assert;
import org.testng.annotations.DataProvider;
import org.testng.annotations.Test;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.TimeUnit;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
/**
* UnitTests for the AutoFormatting
*
* User: depristo
* Date: 8/24/12
* Time: 11:25 AM
* To change this template use File | Settings | File Templates.
*/
public class AutoFormattingTimeUnitTest extends BaseTest {
@DataProvider(name = "AutoFormattingTimeUnitSelection")
public Object[][] makeTimeData() {
List<Object[]> tests = new ArrayList<Object[]>();
tests.add(new Object[]{TimeUnit.SECONDS.toNanos(10), "s"});
tests.add(new Object[]{TimeUnit.MINUTES.toNanos(10), "m"});
tests.add(new Object[]{TimeUnit.HOURS.toNanos(10), "h"});
tests.add(new Object[]{TimeUnit.DAYS.toNanos(10), "d"});
tests.add(new Object[]{TimeUnit.DAYS.toNanos(1000), "w"});
return tests.toArray(new Object[][]{});
}
@Test(dataProvider = "AutoFormattingTimeUnitSelection")
public void testUnitSelection(final long nano, final String expectedUnit) throws InterruptedException {
final AutoFormattingTime time = new AutoFormattingTime(nano);
testBasic(time, nano, time.getWidth(), time.getPrecision());
Assert.assertTrue(time.toString().endsWith(expectedUnit), "TimeUnit " + time.toString() + " didn't contain expected time unit " + expectedUnit);
}
@Test(dataProvider = "AutoFormattingTimeUnitSelection")
public void testSecondsAsDouble(final long nano, final String expectedUnit) throws InterruptedException {
final double inSeconds = nano * 1e-9;
final long nanoFromSeconds = (long)(inSeconds * 1e9);
final AutoFormattingTime time = new AutoFormattingTime(inSeconds);
testBasic(time, nanoFromSeconds, time.getWidth(), time.getPrecision());
}
@DataProvider(name = "AutoFormattingTimeWidthAndPrecision")
public Object[][] makeTimeWidthAndPrecision() {
List<Object[]> tests = new ArrayList<Object[]>();
for ( final int width : Arrays.asList(-1, 1, 2, 6, 20) ) {
for ( final int precision : Arrays.asList(1, 2) ) {
tests.add(new Object[]{100.123456 * 1e9, width, precision});
tests.add(new Object[]{0.123456 * 1e9, width, precision});
}
}
return tests.toArray(new Object[][]{});
}
@Test(dataProvider = "AutoFormattingTimeWidthAndPrecision")
public void testWidthAndPrecision(final double inSeconds, final int width, final int precision) throws InterruptedException {
final AutoFormattingTime time = new AutoFormattingTime(inSeconds, width, precision);
final long nanoFromSeconds = (long)(inSeconds * 1e9);
testBasic(time, nanoFromSeconds, width, precision);
final Matcher match = matchToString(time);
match.matches();
final String widthString = match.group(1);
final String precisionString = match.group(2);
if ( width != -1 ) {
final int actualWidth = widthString.length() + 1 + precisionString.length();
Assert.assertTrue(actualWidth >= width, "width string '" + widthString + "' not >= the expected width " + width);
}
Assert.assertEquals(precisionString.length(), precision, "precision string '" + precisionString + "' not the expected precision " + precision);
}
private static Matcher matchToString(final AutoFormattingTime time) {
Pattern pattern = Pattern.compile("(\\s*\\d*)\\.(\\d*) \\w");
return pattern.matcher(time.toString());
}
private static void testBasic(final AutoFormattingTime aft, final long nano, final int expectedWidth, final int expectedPrecision) {
Assert.assertEquals(aft.getTimeInNanoSeconds(), nano);
assertEqualsDoubleSmart(aft.getTimeInSeconds(), nano * 1e-9, 1e-3, "Time in seconds not within tolerance of nanoSeconds");
Assert.assertEquals(aft.getWidth(), expectedWidth);
Assert.assertEquals(aft.getPrecision(), expectedPrecision);
Assert.assertNotNull(aft.toString(), "TimeUnit toString returned null");
final Matcher match = matchToString(aft);
Assert.assertTrue(match.matches(), "toString " + aft.toString() + " doesn't match our expected format");
}
}

View File

@ -301,7 +301,11 @@ public abstract class BaseTest {
Assert.assertTrue(actualSet.equals(expectedSet), info); // note this is necessary due to testng bug for set comps
}
public static final void assertEqualsDoubleSmart(final double actual, final double expected, final double tolerance) {
public static void assertEqualsDoubleSmart(final double actual, final double expected, final double tolerance) {
assertEqualsDoubleSmart(actual, expected, tolerance, null);
}
public static void assertEqualsDoubleSmart(final double actual, final double expected, final double tolerance, final String message) {
if ( Double.isNaN(expected) ) // NaN == NaN => false unfortunately
Assert.assertTrue(Double.isNaN(actual), "expected is nan, actual is not");
else if ( Double.isInfinite(expected) ) // NaN == NaN => false unfortunately
@ -309,7 +313,9 @@ public abstract class BaseTest {
else {
final double delta = Math.abs(actual - expected);
final double ratio = Math.abs(actual / expected - 1.0);
Assert.assertTrue(delta < tolerance || ratio < tolerance, "expected = " + expected + " actual = " + actual + " not within tolerance " + tolerance);
Assert.assertTrue(delta < tolerance || ratio < tolerance, "expected = " + expected + " actual = " + actual
+ " not within tolerance " + tolerance
+ (message == null ? "" : "message: " + message));
}
}
}