From 6adcebb247eb8173563505cbbfc19db04f8d3b50 Mon Sep 17 00:00:00 2001 From: Jon Chambers Date: Wed, 17 Jun 2020 14:41:42 -0400 Subject: [PATCH] Return to just using counters instead of timers for measuring experiment outcomes. --- .../textsecuregcm/experiment/Experiment.java | 83 +++++++------------ .../experiment/ExperimentTest.java | 47 +++++------ 2 files changed, 52 insertions(+), 78 deletions(-) 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 57ea3c701..2d4bdbd62 100644 --- a/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java +++ b/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java @@ -1,26 +1,26 @@ package org.whispersystems.textsecuregcm.experiment; -import com.codahale.metrics.MetricRegistry; import com.google.common.annotations.VisibleForTesting; +import io.micrometer.core.instrument.Counter; import io.micrometer.core.instrument.Metrics; -import io.micrometer.core.instrument.Timer; import java.util.Objects; import java.util.concurrent.CompletionStage; -import java.util.concurrent.TimeUnit; import java.util.function.Supplier; +import static com.codahale.metrics.MetricRegistry.name; + /** * An experiment compares the results of two operations and records metrics to assess how frequently they match. */ public class Experiment { - private final Timer matchTimer; - private final Timer errorTimer; + private final Counter matchCounter; + private final Counter errorCounter; - private final Timer bothPresentMismatchTimer; - private final Timer controlNullMismatchTimer; - private final Timer experimentNullMismatchTimer; + private final Counter bothPresentMismatchCounter; + private final Counter controlNullMismatchCounter; + private final Counter experimentNullMismatchCounter; private static final String OUTCOME_TAG = "outcome"; private static final String MATCH_OUTCOME = "match"; @@ -33,77 +33,54 @@ public class Experiment { private static final String EXPERIMENT_NULL_MISMATCH = "experimentResultNull"; public Experiment(final String... names) { - this(buildTimer(MATCH_OUTCOME, names).register(Metrics.globalRegistry), - buildTimer(ERROR_OUTCOME, names).register(Metrics.globalRegistry), - buildTimer(MISMATCH_OUTCOME, names).tag(MISMATCH_TYPE_TAG, BOTH_PRESENT_MISMATCH).register(Metrics.globalRegistry), - buildTimer(MISMATCH_OUTCOME, names).tag(MISMATCH_TYPE_TAG, CONTROL_NULL_MISMATCH).register(Metrics.globalRegistry), - buildTimer(MISMATCH_OUTCOME, names).tag(MISMATCH_TYPE_TAG, EXPERIMENT_NULL_MISMATCH).register(Metrics.globalRegistry)); - } - - private static Timer.Builder buildTimer(final String outcome, final String... names) { - if (names == null || names.length == 0) { - throw new IllegalArgumentException("Experiments must have a name"); - } - - return Timer.builder(MetricRegistry.name(Experiment.class, names)) - .tag(OUTCOME_TAG, outcome) - .publishPercentileHistogram(); + this(Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MATCH_OUTCOME), + Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, ERROR_OUTCOME), + Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MISMATCH_OUTCOME, MISMATCH_TYPE_TAG, BOTH_PRESENT_MISMATCH), + Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MISMATCH_OUTCOME, MISMATCH_TYPE_TAG, CONTROL_NULL_MISMATCH), + Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MISMATCH_OUTCOME, MISMATCH_TYPE_TAG, EXPERIMENT_NULL_MISMATCH)); } @VisibleForTesting - Experiment(final Timer matchTimer, final Timer errorTimer, final Timer bothPresentMismatchTimer, final Timer controlNullMismatchTimer, final Timer experimentNullMismatchTimer) { - this.matchTimer = matchTimer; - this.errorTimer = errorTimer; + Experiment(final Counter matchCounter, final Counter errorCounter, final Counter bothPresentMismatchCounter, final Counter controlNullMismatchCounter, final Counter experimentNullMismatchCounter) { + this.matchCounter = matchCounter; + this.errorCounter = errorCounter; - this.bothPresentMismatchTimer = bothPresentMismatchTimer; - this.controlNullMismatchTimer = controlNullMismatchTimer; - this.experimentNullMismatchTimer = experimentNullMismatchTimer; + this.bothPresentMismatchCounter = bothPresentMismatchCounter; + this.controlNullMismatchCounter = controlNullMismatchCounter; + this.experimentNullMismatchCounter = experimentNullMismatchCounter; } public void compareFutureResult(final T expected, final CompletionStage experimentStage) { - // We're assuming that we get the experiment completion stage as soon as possible after it's started, but this - // start time will inescapably have some "wiggle" to it. - final long start = System.nanoTime(); - experimentStage.whenComplete((actual, cause) -> { - final long duration = System.nanoTime() - start; - if (cause != null) { - recordError(duration); + errorCounter.increment(); } else { - recordResult(duration, expected, actual); + recordResult(expected, actual); } }); } public void compareSupplierResult(final T expected, final Supplier experimentSupplier) { - final long start = System.nanoTime(); - try { - final T result = experimentSupplier.get(); - recordResult(System.nanoTime() - start, expected, result); + recordResult(expected, experimentSupplier.get()); } catch (final Exception e) { - recordError(System.nanoTime() - start); + errorCounter.increment(); } } - private void recordError(final long durationNanos) { - errorTimer.record(durationNanos, TimeUnit.NANOSECONDS); - } - - private void recordResult(final long durationNanos, final T expected, final T actual) { - final Timer timer; + private void recordResult(final T expected, final T actual) { + final Counter counter; if (Objects.equals(expected, actual)) { - timer = matchTimer; + counter = matchCounter; } else if (expected == null) { - timer = controlNullMismatchTimer; + counter = controlNullMismatchCounter; } else if (actual == null) { - timer = experimentNullMismatchTimer; + counter = experimentNullMismatchCounter; } else { - timer = bothPresentMismatchTimer; + counter = bothPresentMismatchCounter; } - timer.record(durationNanos, TimeUnit.NANOSECONDS); + counter.increment(); } } 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 424339d91..7c7ba29e9 100644 --- a/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java +++ b/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java @@ -1,95 +1,92 @@ package org.whispersystems.textsecuregcm.experiment; -import io.micrometer.core.instrument.Timer; +import io.micrometer.core.instrument.Counter; import org.junit.Before; import org.junit.Test; import java.util.concurrent.CompletableFuture; -import java.util.concurrent.TimeUnit; -import static org.mockito.ArgumentMatchers.anyLong; -import static org.mockito.ArgumentMatchers.eq; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.verify; public class ExperimentTest { - private Timer matchTimer; - private Timer errorTimer; - private Timer bothPresentMismatchTimer; - private Timer controlNullMismatchTimer; - private Timer experimentNullMismatchTimer; + private Counter matchCounter; + private Counter errorCounter; + private Counter bothPresentMismatchCounter; + private Counter controlNullMismatchCounter; + private Counter experimentNullMismatchCounter; private Experiment experiment; @Before public void setUp() { - matchTimer = mock(Timer.class); - errorTimer = mock(Timer.class); - bothPresentMismatchTimer = mock(Timer.class); - controlNullMismatchTimer = mock(Timer.class); - experimentNullMismatchTimer = mock(Timer.class); + matchCounter = mock(Counter.class); + errorCounter = mock(Counter.class); + bothPresentMismatchCounter = mock(Counter.class); + controlNullMismatchCounter = mock(Counter.class); + experimentNullMismatchCounter = mock(Counter.class); - experiment = new Experiment(matchTimer, errorTimer, bothPresentMismatchTimer, controlNullMismatchTimer, experimentNullMismatchTimer); + experiment = new Experiment(matchCounter, errorCounter, bothPresentMismatchCounter, controlNullMismatchCounter, experimentNullMismatchCounter); } @Test public void compareFutureResultMatch() { experiment.compareFutureResult(12, CompletableFuture.completedFuture(12)); - verify(matchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(matchCounter).increment(); } @Test public void compareFutureResultMismatchBothPresent() { experiment.compareFutureResult(12, CompletableFuture.completedFuture(77)); - verify(bothPresentMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(bothPresentMismatchCounter).increment(); } @Test public void compareFutureResultMismatchControlNull() { experiment.compareFutureResult(null, CompletableFuture.completedFuture(77)); - verify(controlNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(controlNullMismatchCounter).increment(); } @Test public void compareFutureResultMismatchExperimentNull() { experiment.compareFutureResult(12, CompletableFuture.completedFuture(null)); - verify(experimentNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(experimentNullMismatchCounter).increment(); } @Test public void compareFutureResultError() { experiment.compareFutureResult(12, CompletableFuture.failedFuture(new RuntimeException("OH NO"))); - verify(errorTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(errorCounter).increment(); } @Test public void compareSupplierResultMatch() { experiment.compareSupplierResult(12, () -> 12); - verify(matchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(matchCounter).increment(); } @Test public void compareSupplierResultMismatchBothPresent() { experiment.compareSupplierResult(12, () -> 77); - verify(bothPresentMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(bothPresentMismatchCounter).increment(); } @Test public void compareSupplierResultMismatchControlNull() { experiment.compareSupplierResult(null, () -> 77); - verify(controlNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(controlNullMismatchCounter).increment(); } @Test public void compareSupplierResultMismatchExperimentNull() { experiment.compareSupplierResult(12, () -> null); - verify(experimentNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(experimentNullMismatchCounter).increment(); } @Test public void compareSupplierResultError() { experiment.compareSupplierResult(12, () -> { throw new RuntimeException("OH NO"); }); - verify(errorTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + verify(errorCounter).increment(); } }