Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix issue #79 (negative duration/elapsed time) #80

Merged
merged 2 commits into from
Mar 7, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 6 additions & 1 deletion src/main/java/net/obvj/performetrics/Counter.java
Original file line number Diff line number Diff line change
Expand Up @@ -275,8 +275,13 @@ void setUnitsAfter()
*/
private long elapsedTimeNanos()
{
// Let the "units after" be the current time if the actual "units after" were not set
long tempUnitsAfter = unitsAfterSet ? unitsAfter : type.getTime();
return tempUnitsAfter >= unitsBefore ? tempUnitsAfter - unitsBefore : -1;

// IMPORTANT: Although thread CPU time has nanoseconds precision, it is not 100# accurate,
// which means that sometimes the units before may be greater than the units after.
// In cases like this, it is better to return zero.
return tempUnitsAfter >= unitsBefore ? tempUnitsAfter - unitsBefore : 0;
}

/**
Expand Down
23 changes: 9 additions & 14 deletions src/main/java/net/obvj/performetrics/util/Duration.java
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,6 @@ public final class Duration implements Comparable<Duration>
private static final String MSG_SOURCE_TIME_UNIT_MUST_NOT_BE_NULL = "The source TimeUnit must not be null";
private static final String MSG_TARGET_TIME_UNIT_MUST_NOT_BE_NULL = "The target TimeUnit must not be null";
private static final String MSG_FORMAT_MUST_NOT_BE_NULL = "The format must not be null";
private static final String MSG_AMOUNT_MUST_BE_POSITIVE = "The duration amount must be a positive value";

private static final int SECONDS_PER_MINUTE = 60;
private static final int SECONDS_PER_HOUR = 60 * 60;
Expand Down Expand Up @@ -89,13 +88,12 @@ public final class Duration implements Comparable<Duration>
* duration.getNanoseconds() //returns: 0
* </pre>
*
* @param amount the amount of the duration, measured in terms of the time unit
* argument, not negative
* @param amount the amount of the duration (positive or negative), measured in terms of
* the time unit argument
* @param timeUnit the unit that the amount argument is measured in, not null
* @return a {@code Duration}, not null
*
* @throws NullPointerException if the specified time unit is null
* @throws IllegalArgumentException if the specified duration amount is negative
* @throws NullPointerException if the specified time unit is null
*/
public static Duration of(long amount, TimeUnit timeUnit)
{
Expand All @@ -117,8 +115,8 @@ public static Duration of(long amount, TimeUnit timeUnit)
* duration.getNanoseconds() //returns: 0
* </pre>
*
* @param amount the amount of the duration, measured in terms of the time unit
* argument, not negative
* @param amount the amount of the duration (positive or negative), measured in
* terms of the time unit argument
* @param temporalUnit the unit that the amount argument is measured in, not null
* @return a {@code Duration}, not null
*
Expand All @@ -128,10 +126,6 @@ public static Duration of(long amount, TimeUnit timeUnit)
*/
public static Duration of(long amount, TemporalUnit temporalUnit)
{
if (amount < 0)
{
throw new IllegalArgumentException(MSG_AMOUNT_MUST_BE_POSITIVE);
}
java.time.Duration internalDuration = java.time.Duration.of(amount, temporalUnit);
return new Duration(internalDuration);
}
Expand Down Expand Up @@ -334,11 +328,11 @@ public double toTimeUnit(TimeUnit timeUnit, int scale)
{
Objects.requireNonNull(timeUnit, MSG_TARGET_TIME_UNIT_MUST_NOT_BE_NULL);

BigDecimal targetSeconds = internalDuration.getSeconds() > 0
BigDecimal targetSeconds = internalDuration.getSeconds() != 0
? BigDecimal.valueOf(timeUnit.convert(internalDuration.getSeconds(), TimeUnit.SECONDS))
: BigDecimal.ZERO;

BigDecimal targetNanoseconds = internalDuration.getNano() > 0
BigDecimal targetNanoseconds = internalDuration.getNano() != 0
? convertNanosecondsPart(timeUnit, scale)
: BigDecimal.ZERO;

Expand Down Expand Up @@ -389,7 +383,8 @@ public Duration plus(Duration duration)
* <p>
* This instance is immutable and unaffected by this method call.
*
* @param amount the amount to add, measured in terms of the timeUnit argument
* @param amount the amount to add (positive or negative), measured in terms of the
* timeUnit argument
* @param timeUnit the unit that the amount to add is measured in, not null
*
* @return a {@code Duration} based on this duration with the specified duration added,
Expand Down
16 changes: 8 additions & 8 deletions src/main/java/net/obvj/performetrics/util/DurationFormat.java
Original file line number Diff line number Diff line change
Expand Up @@ -81,11 +81,11 @@ public Duration doParse(final String string)
@Override
public String doFormat(final Duration duration, boolean printLegend)
{
if (duration.getHours() > 0)
if (duration.getHours() != 0)
{
return DurationFormat.FULL.doFormat(duration, printLegend);
}
if (duration.getMinutes() > 0)
if (duration.getMinutes() != 0)
{
return String.format(MyTimeUnit.MINUTES.format, duration.getMinutes(),
duration.getSeconds(), duration.getNanoseconds())
Expand Down Expand Up @@ -126,11 +126,11 @@ public String doFormat(final Duration duration, boolean printLegend)
{
return format;
}
if (duration.getHours() > 0)
if (duration.getHours() != 0)
{
return format + legend(true, MyTimeUnit.HOURS.legend);
}
if (duration.getMinutes() > 0)
if (duration.getMinutes() != 0)
{
return format + legend(true, MyTimeUnit.MINUTES.legend);
}
Expand Down Expand Up @@ -245,10 +245,10 @@ public Duration doParse(final String string)
* The pattern for parsing durations in the format {@code [H:][M:]S[.ns]}.
*/
private static final Pattern HMS_PATTERN = Pattern.compile(
"^(((?<hours>\\d*):)?"
+ "((?<minutes>\\d*):))?"
+ "(?<seconds>\\d+)"
+ "([.,](?<nanoseconds>\\d+))?"
"^(((?<hours>-?\\d*):)?"
+ "((?<minutes>-?\\d*):))?"
+ "(?<seconds>-?\\d+)"
+ "([.,](?<nanoseconds>-?\\d+))?"
+ "(.)*"); // legend

static final String MSG_DURATION_MUST_NOT_BE_NULL = "The duration must not be null";
Expand Down
6 changes: 2 additions & 4 deletions src/test/java/net/obvj/performetrics/CounterTest.java
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,6 @@

import static java.util.concurrent.TimeUnit.NANOSECONDS;
import static java.util.concurrent.TimeUnit.SECONDS;
import static net.obvj.junit.utils.matchers.AdvancedMatchers.throwsException;
import static net.obvj.performetrics.ConversionMode.DOUBLE_PRECISION;
import static net.obvj.performetrics.ConversionMode.FAST;
import static net.obvj.performetrics.Counter.Type.CPU_TIME;
Expand Down Expand Up @@ -111,13 +110,12 @@ void elapsedTime_withUnitsBeforeSetOnly_returnsDifferenceBetweenUnitsBeforeAndCu
}

@Test
void elapsedTime_unitsAfterLowerThanUnitsBefore_negative1()
void elapsedTime_unitsAfterLowerThanUnitsBefore_zero()
{
Counter counter = new Counter(WALL_CLOCK_TIME);
counter.setUnitsBefore(5_000);
counter.setUnitsAfter(500);
assertThat(() -> counter.elapsedTime(), throwsException(IllegalArgumentException.class)
.withMessage("The duration amount must be a positive value"));
assertThat(counter.elapsedTime(), is(equalTo(Duration.ZERO)));
}

@Test
Expand Down
45 changes: 42 additions & 3 deletions src/test/java/net/obvj/performetrics/PerformetricsTestDrive.java
Original file line number Diff line number Diff line change
Expand Up @@ -26,11 +26,15 @@
import java.nio.file.Path;
import java.nio.file.Paths;
import java.util.*;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.stream.Collectors;
import java.util.stream.IntStream;

import net.obvj.performetrics.monitors.MonitoredCallable;
import net.obvj.performetrics.monitors.MonitoredRunnable;
import net.obvj.performetrics.util.Duration;
import net.obvj.performetrics.util.DurationFormat;
import net.obvj.performetrics.util.DurationUtils;
import net.obvj.performetrics.util.print.PrintStyle;

public class PerformetricsTestDrive
Expand All @@ -55,6 +59,9 @@ public static void main(String[] args) throws Exception

System.out.println("\n\n****************************************************\n");
testOnADifferentThread();

System.out.println("\n\n****************************************************\n");
loadTest();
}

private static void testStopwatch1() throws InterruptedException, IOException
Expand Down Expand Up @@ -152,10 +159,11 @@ public static BigInteger factorial(long x)
return BigInteger.valueOf(x).multiply(factorial(x - 1));
}

private static void testOnADifferentThread()
private static void testOnADifferentThread() throws InterruptedException
{
System.out.println("[main] Starting test on a different thread");
new Thread(() -> {
Thread t1 = new Thread(() ->
{
Performetrics.monitorOperation(() ->
{
String logFormat = "[%s] %s";
Expand All @@ -172,8 +180,39 @@ private static void testOnADifferentThread()
System.out.println(String.format(logFormat, threadName, size + " UUIDs generated and sorted"));
System.out.println();
}).printSummary(System.out, PrintStyle.SUMMARIZED_YAML);
}).start();;
});

t1.start();
System.out.println("[main] New thread started");
t1.join();
}

private static void loadTest()
{
System.out.println("[main] Starting load test...");

int repeatTimes = 1_000_000;
Map<Double, AtomicInteger> amounts = new HashMap<>();
List<Duration> durations = new ArrayList<>(repeatTimes);

for (int i = 0; i < repeatTimes; i++)
{
MonitoredRunnable runnable = Performetrics.monitorOperation(() -> factorial(100L),
WALL_CLOCK_TIME, USER_TIME, SYSTEM_TIME);
runnable.elapsedTime(WALL_CLOCK_TIME);
runnable.elapsedTime(USER_TIME);
Duration st = runnable.elapsedTime(SYSTEM_TIME);

durations.add(st);
amounts.computeIfAbsent(st.toSeconds(), k -> new AtomicInteger(0)).incrementAndGet();
}

System.out.println("[main] Load test finished");

System.out.print("[main] Computing average of elapsed SYSTEM_TIME... ");
System.out.println(DurationUtils.average(durations));

System.out.println(amounts);
}

}
47 changes: 38 additions & 9 deletions src/test/java/net/obvj/performetrics/util/DurationTest.java
Original file line number Diff line number Diff line change
Expand Up @@ -60,9 +60,11 @@ void of_validAmountAndTimeUnitAndSecondsPrecision_populatesAccordingly()
@Test
void of_negativeAmount_illegalArgumentException()
{
assertThat(() -> Duration.of(-1, NANOSECONDS),
throwsException(IllegalArgumentException.class)
.withMessage("The duration amount must be a positive value"));
Duration d1 = Duration.of(-1, SECONDS);
assertThat(d1.getHours(), is(equalTo(0L)));
assertThat(d1.getMinutes(), is(equalTo(0)));
assertThat(d1.getSeconds(), is(equalTo(-1)));
assertThat(d1.getNanoseconds(), is(equalTo(0)));
}

@Test
Expand All @@ -89,6 +91,11 @@ void toSeconds_validValues()
assertThat(Duration.of(3601, MINUTES ).toSeconds(), is(equalTo( 216060D)));
assertThat(Duration.of(2, HOURS ).toSeconds(), is(equalTo( 7200D)));
assertThat(Duration.of(100, HOURS ).toSeconds(), is(equalTo( 360000D)));

// Tests with negative durations
assertThat(Duration.of(-1, HOURS ).toSeconds(), is(equalTo( -3600D)));
assertThat(Duration.of(-1000000000, NANOSECONDS).toSeconds(), is(equalTo( -1D)));
assertThat(Duration.of(-1000000001, NANOSECONDS).toSeconds(), is(equalTo(-1.000000001D)));
}

@Test
Expand All @@ -115,6 +122,11 @@ void toTimeUnit_milliseconds_validValuesDefaultScale()
assertThat(Duration.of(3601, MINUTES ).toTimeUnit(MILLISECONDS), is(equalTo( 216060000D)));
assertThat(Duration.of(2, HOURS ).toTimeUnit(MILLISECONDS), is(equalTo( 7200000D)));
assertThat(Duration.of(100, HOURS ).toTimeUnit(MILLISECONDS), is(equalTo( 360000000D)));

// Tests with negative durations
assertThat(Duration.of(-1, HOURS ).toTimeUnit(MILLISECONDS), is(equalTo( -3600000D)));
assertThat(Duration.of(-1000000000, NANOSECONDS).toTimeUnit(MILLISECONDS), is(equalTo( -1000D)));
assertThat(Duration.of(-1000000001, NANOSECONDS).toTimeUnit(MILLISECONDS), is(equalTo(-1000.000001D)));
}

@Test
Expand All @@ -141,6 +153,11 @@ void toTimeUnit_millisecondsAndScale3_validValues()
assertThat(Duration.of(3601, MINUTES ).toTimeUnit(MILLISECONDS, 3), is(equalTo( 216060000D)));
assertThat(Duration.of(2, HOURS ).toTimeUnit(MILLISECONDS, 3), is(equalTo( 7200000D)));
assertThat(Duration.of(100, HOURS ).toTimeUnit(MILLISECONDS, 3), is(equalTo( 360000000D)));

// Tests with negative durations
assertThat(Duration.of(-1, HOURS ).toTimeUnit(MILLISECONDS, 3), is(equalTo(-3600000D)));
assertThat(Duration.of(-1000000000, NANOSECONDS).toTimeUnit(MILLISECONDS, 3), is(equalTo( -1000D)));
assertThat(Duration.of(-1000000001, NANOSECONDS).toTimeUnit(MILLISECONDS, 3), is(equalTo( -1000D)));
}

@Test
Expand Down Expand Up @@ -207,6 +224,10 @@ void plus_validDurations_success()
assertThat(Duration.of(1800, SECONDS ).plus(Duration.of(1800, SECONDS )), is(equalTo(Duration.of(1, HOURS))));
assertThat(Duration.of(3599, SECONDS ).plus(Duration.of(3601, SECONDS )), is(equalTo(Duration.of(2, HOURS))));
assertThat(Duration.of( 500, MILLISECONDS).plus(Duration.of( 500, MILLISECONDS)), is(equalTo(Duration.of(1, SECONDS))));

// Tests with negative durations
assertThat(Duration.of( 500, MILLISECONDS).plus(Duration.of(-500, MILLISECONDS)), is(equalTo(Duration.of(0, NANOSECONDS))));
assertThat(Duration.of(2000, MILLISECONDS).plus(Duration.of( -1, SECONDS )), is(equalTo(Duration.of(1, SECONDS))));
}

@Test
Expand All @@ -216,14 +237,19 @@ void plus_validDurationsAsLong_success()
assertThat(Duration.of(1800, SECONDS ).plus(1800, SECONDS ), is(equalTo(Duration.of(1, HOURS))));
assertThat(Duration.of(3599, SECONDS ).plus(3601, SECONDS ), is(equalTo(Duration.of(2, HOURS))));
assertThat(Duration.of( 500, MILLISECONDS).plus( 500, MILLISECONDS), is(equalTo(Duration.of(1, SECONDS))));

// Tests with negative durations
assertThat(Duration.of( 500, MILLISECONDS).plus(-500, MILLISECONDS), is(equalTo(Duration.of(0, NANOSECONDS))));
assertThat(Duration.of(2000, MILLISECONDS).plus( -1, SECONDS ), is(equalTo(Duration.of(1, SECONDS))));
}

@Test
void dividedBy_positiveDivisor_success()
{
assertThat(Duration.of( 2, HOURS ).dividedBy(2), is(equalTo(Duration.of( 1, HOURS))));
assertThat(Duration.of( 3, HOURS ).dividedBy(2), is(equalTo(Duration.of( 90, MINUTES))));
assertThat(Duration.of(1000, MILLISECONDS).dividedBy(5), is(equalTo(Duration.of(200, MILLISECONDS))));
assertThat(Duration.of( 2, HOURS ).dividedBy(2), is(equalTo(Duration.of( 1, HOURS))));
assertThat(Duration.of( 3, HOURS ).dividedBy(2), is(equalTo(Duration.of( 90, MINUTES))));
assertThat(Duration.of( 1000, MILLISECONDS).dividedBy(5), is(equalTo(Duration.of( 200, MILLISECONDS))));
assertThat(Duration.of(-1000, MILLISECONDS).dividedBy(5), is(equalTo(Duration.of(-200, MILLISECONDS))));
}

@Test
Expand All @@ -235,9 +261,10 @@ void internal_success()
@Test
void isZero_validDurations_success()
{
assertThat(Duration.of(0, HOURS ).isZero(), is(true));
assertThat(Duration.of(0, MILLISECONDS).isZero(), is(true));
assertThat(Duration.of(1, NANOSECONDS ).isZero(), is(false));
assertThat(Duration.of( 0, HOURS ).isZero(), is(true));
assertThat(Duration.of( 0, MILLISECONDS).isZero(), is(true));
assertThat(Duration.of( 1, NANOSECONDS ).isZero(), is(false));
assertThat(Duration.of(-1, NANOSECONDS ).isZero(), is(false));
}

@Test
Expand All @@ -252,13 +279,15 @@ void compareTo_lowerDurations_positive()
{
assertThat(Duration.of( 1, SECONDS ).compareTo(Duration.of(750, MILLISECONDS)), isPositive());
assertThat(Duration.of(100, NANOSECONDS).compareTo(Duration.of( 20, NANOSECONDS )), isPositive());
assertThat(Duration.of( 0, NANOSECONDS).compareTo(Duration.of( -2, NANOSECONDS )), isPositive());
}

@Test
void compareTo_lowerDurations_negative()
{
assertThat(Duration.of( 1, MILLISECONDS).compareTo(Duration.of(2000000, NANOSECONDS)), isNegative());
assertThat(Duration.of(40, MINUTES ).compareTo(Duration.of( 1, HOURS )), isNegative());
assertThat(Duration.of(-4, MINUTES ).compareTo(Duration.of( -3, MINUTES )), isNegative());
}

@Test
Expand Down
Loading