diff --git a/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java b/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java index 5bd1d38c5..f049a84a4 100644 --- a/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java +++ b/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java @@ -15,7 +15,6 @@ import java.util.Optional; import java.util.concurrent.CompletableFuture; import java.util.concurrent.CompletionStage; import java.util.concurrent.Executor; -import java.util.concurrent.TimeUnit; import java.util.function.Supplier; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -72,65 +71,62 @@ public class Experiment { } public void compareFutureResult(final T expected, final CompletionStage experimentStage) { - final long startNanos = System.nanoTime(); + final Timer.Sample sample = Timer.start(); experimentStage.whenComplete((actual, cause) -> { - final long durationNanos = System.nanoTime() - startNanos; - if (cause != null) { - recordError(cause, durationNanos); + recordError(cause, sample); } else { - recordResult(expected, actual, durationNanos); + recordResult(expected, actual, sample); } }); } public void compareSupplierResult(final T expected, final Supplier experimentSupplier) { - final long startNanos = System.nanoTime(); + final Timer.Sample sample = Timer.start(); try { final T result = experimentSupplier.get(); - recordResult(expected, result, System.nanoTime() - startNanos); + recordResult(expected, result, sample); } catch (final Exception e) { - recordError(e, System.nanoTime() - startNanos); + recordError(e, sample); } } - public void compareSupplierResultAsync(final T expected, final Supplier experimentSupplier, - final Executor executor) { - final long startNanos = System.nanoTime(); + public void compareSupplierResultAsync(final T expected, final Supplier experimentSupplier, final Executor executor) { + final Timer.Sample sample = Timer.start(); try { compareFutureResult(expected, CompletableFuture.supplyAsync(experimentSupplier, executor)); } catch (final Exception e) { - recordError(e, System.nanoTime() - startNanos); + recordError(e, sample); } } - private void recordError(final Throwable cause, final long durationNanos) { + private void recordError(final Throwable cause, final Timer.Sample sample) { log.warn("Experiment {} threw an exception.", name, cause); - errorTimer.record(durationNanos, TimeUnit.NANOSECONDS); + sample.stop(errorTimer); } @VisibleForTesting - void recordResult(final T expected, final T actual, final long durationNanos) { + void recordResult(final T expected, final T actual, final Timer.Sample sample) { if (expected instanceof Optional && actual instanceof Optional) { - recordResult(((Optional) expected).orElse(null), ((Optional) actual).orElse(null), durationNanos); + recordResult(((Optional) expected).orElse(null), ((Optional) actual).orElse(null), sample); } else { - final Timer Timer; + final Timer timer; if (Objects.equals(expected, actual)) { - Timer = matchTimer; + timer = matchTimer; } else if (expected == null) { - Timer = controlNullMismatchTimer; + timer = controlNullMismatchTimer; } else if (actual == null) { - Timer = experimentNullMismatchTimer; + timer = experimentNullMismatchTimer; } else { - Timer = bothPresentMismatchTimer; + timer = bothPresentMismatchTimer; } - Timer.record(durationNanos, TimeUnit.NANOSECONDS); + sample.stop(timer); } } } diff --git a/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java b/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java index 667f4eea2..0dc6f446b 100644 --- a/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java +++ b/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java @@ -13,6 +13,7 @@ import static org.mockito.Mockito.mock; import static org.mockito.Mockito.reset; import static org.mockito.Mockito.verify; +import io.micrometer.core.instrument.MockClock; import io.micrometer.core.instrument.Timer; import java.util.Optional; import java.util.concurrent.CompletableFuture; @@ -104,13 +105,16 @@ class ExperimentTest { @ParameterizedTest @MethodSource - public void testRecordResult(final Object expected, final Object actual, final Experiment experiment, - final Timer expectedTimer) { + public void testRecordResult(final Object expected, final Object actual, final Experiment experiment, final Timer expectedTimer) { reset(expectedTimer); - final long durationNanos = 123; + final MockClock clock = new MockClock(); + final Timer.Sample sample = Timer.start(clock); - experiment.recordResult(expected, actual, durationNanos); + final long durationNanos = 123; + clock.add(durationNanos, TimeUnit.NANOSECONDS); + + experiment.recordResult(expected, actual, sample); verify(expectedTimer).record(durationNanos, TimeUnit.NANOSECONDS); }