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 8fa8fd9c9..163729671 100644 --- a/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java +++ b/service/src/main/java/org/whispersystems/textsecuregcm/experiment/Experiment.java @@ -2,11 +2,9 @@ package org.whispersystems.textsecuregcm.experiment; import com.codahale.metrics.MetricRegistry; import com.google.common.annotations.VisibleForTesting; -import io.micrometer.core.instrument.MeterRegistry; import io.micrometer.core.instrument.Metrics; -import io.micrometer.core.instrument.Tag; +import io.micrometer.core.instrument.Timer; -import java.util.List; import java.util.Objects; import java.util.concurrent.CompletionStage; import java.util.concurrent.TimeUnit; @@ -17,28 +15,35 @@ import java.util.function.Supplier; */ public class Experiment { - private final String timerName; - private final MeterRegistry meterRegistry; - - static final String OUTCOME_TAG = "outcome"; - static final String CAUSE_TAG = "cause"; + private final Timer matchTimer; + private final Timer mismatchTimer; + private final Timer errorTimer; + static final String OUTCOME_TAG = "outcome"; static final String MATCH_OUTCOME = "match"; static final String MISMATCH_OUTCOME = "mismatch"; static final String ERROR_OUTCOME = "error"; public Experiment(final String... names) { - this(Metrics.globalRegistry, names); + this(buildTimer(MATCH_OUTCOME, names), buildTimer(MISMATCH_OUTCOME, names), buildTimer(ERROR_OUTCOME, names)); } - @VisibleForTesting - Experiment(final MeterRegistry meterRegistry, final String... names) { + private static Timer buildTimer(final String outcome, final String... names) { if (names == null || names.length == 0) { throw new IllegalArgumentException("Experiments must have a name"); } - this.timerName = MetricRegistry.name(getClass(), names); - this.meterRegistry = meterRegistry; + return Timer.builder(MetricRegistry.name(Experiment.class, names)) + .tag(OUTCOME_TAG, outcome) + .publishPercentileHistogram() + .register(Metrics.globalRegistry); + } + + @VisibleForTesting + Experiment(final Timer matchTimer, final Timer mismatchTimer, final Timer errorTimer) { + this.matchTimer = matchTimer; + this.mismatchTimer = mismatchTimer; + this.errorTimer = errorTimer; } public void compareFutureResult(final T expected, final CompletionStage experimentStage) { @@ -50,7 +55,7 @@ public class Experiment { final long duration = System.nanoTime() - start; if (cause != null) { - recordError(duration, cause); + recordError(duration); } else { recordResult(duration, expected, actual); } @@ -64,23 +69,20 @@ public class Experiment { final T result = experimentSupplier.get(); recordResult(System.nanoTime() - start, expected, result); } catch (final Exception e) { - recordError(System.nanoTime() - start, e); + recordError(System.nanoTime() - start); } } - private void recordError(final long durationNanos, final Throwable cause) { - meterRegistry.timer(timerName, - List.of(Tag.of(OUTCOME_TAG, ERROR_OUTCOME), Tag.of(CAUSE_TAG, cause.getClass().getSimpleName()))) - .record(durationNanos, TimeUnit.NANOSECONDS); + private void recordError(final long durationNanos) { + errorTimer.record(durationNanos, TimeUnit.NANOSECONDS); } private void recordResult(final long durationNanos, final T expected, final T actual) { final boolean shouldIgnore = actual == null && expected != null; if (!shouldIgnore) { - meterRegistry.timer(timerName, - List.of(Tag.of(OUTCOME_TAG, Objects.equals(expected, actual) ? MATCH_OUTCOME : MISMATCH_OUTCOME))) - .record(durationNanos, TimeUnit.NANOSECONDS); + final Timer timer = Objects.equals(expected, actual) ? matchTimer : mismatchTimer; + timer.record(durationNanos, TimeUnit.NANOSECONDS); } } } 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 2cff0151f..c8db7e890 100644 --- a/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java +++ b/service/src/test/java/org/whispersystems/textsecuregcm/experiment/ExperimentTest.java @@ -1,8 +1,11 @@ package org.whispersystems.textsecuregcm.experiment; +import io.micrometer.core.instrument.Meter; import io.micrometer.core.instrument.MeterRegistry; import io.micrometer.core.instrument.Tag; import io.micrometer.core.instrument.Timer; +import io.micrometer.core.instrument.distribution.DistributionStatisticConfig; +import org.LatencyUtils.PauseDetector; import org.junit.Before; import org.junit.Test; import org.mockito.ArgumentCaptor; @@ -21,146 +24,71 @@ import static org.mockito.ArgumentMatchers.eq; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.verifyNoMoreInteractions; import static org.mockito.Mockito.when; public class ExperimentTest { - private MeterRegistry meterRegistry; + private Timer matchTimer; + private Timer mismatchTimer; + private Timer errorTimer; + + private Experiment experiment; @Before public void setUp() { - meterRegistry = mock(MeterRegistry.class); + matchTimer = mock(Timer.class); + mismatchTimer = mock(Timer.class); + errorTimer = mock(Timer.class); + + experiment = new Experiment(matchTimer, mismatchTimer, errorTimer); } @Test public void compareFutureResultMatch() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareFutureResult(12, CompletableFuture.completedFuture(12)); - - @SuppressWarnings("unchecked") final ArgumentCaptor> tagCaptor = ArgumentCaptor.forClass(Iterable.class); - - verify(meterRegistry).timer(anyString(), tagCaptor.capture()); - - final Set tags = getTagSet(tagCaptor.getValue()); - assertEquals(tags, Set.of(Tag.of(Experiment.OUTCOME_TAG, Experiment.MATCH_OUTCOME))); - - verify(timer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + experiment.compareFutureResult(12, CompletableFuture.completedFuture(12)); + verify(matchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); } @Test public void compareFutureResultMismatch() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareFutureResult(12, CompletableFuture.completedFuture(77)); - - @SuppressWarnings("unchecked") final ArgumentCaptor> tagCaptor = ArgumentCaptor.forClass(Iterable.class); - - verify(meterRegistry).timer(anyString(), tagCaptor.capture()); - - final Set tags = getTagSet(tagCaptor.getValue()); - assertEquals(tags, Set.of(Tag.of(Experiment.OUTCOME_TAG, Experiment.MISMATCH_OUTCOME))); - - verify(timer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + experiment.compareFutureResult(12, CompletableFuture.completedFuture(77)); + verify(mismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); } @Test public void compareFutureResultError() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareFutureResult(12, CompletableFuture.failedFuture(new RuntimeException("OH NO"))); - - @SuppressWarnings("unchecked") final ArgumentCaptor> tagCaptor = ArgumentCaptor.forClass(Iterable.class); - - verify(meterRegistry).timer(anyString(), tagCaptor.capture()); - - final Set tags = getTagSet(tagCaptor.getValue()); - assertEquals(tags, Set.of(Tag.of(Experiment.OUTCOME_TAG, Experiment.ERROR_OUTCOME), Tag.of(Experiment.CAUSE_TAG, "RuntimeException"))); - - verify(timer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + experiment.compareFutureResult(12, CompletableFuture.failedFuture(new RuntimeException("OH NO"))); + verify(errorTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); } @Test public void compareFutureResultNoExperimentData() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareFutureResult(12, CompletableFuture.completedFuture(null)); - - verify(timer, never()).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + experiment.compareFutureResult(12, CompletableFuture.completedFuture(null)); + verifyNoMoreInteractions(matchTimer, mismatchTimer, errorTimer); } @Test public void compareSupplierResultMatch() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareSupplierResult(12, () -> 12); - - @SuppressWarnings("unchecked") final ArgumentCaptor> tagCaptor = ArgumentCaptor.forClass(Iterable.class); - - verify(meterRegistry).timer(anyString(), tagCaptor.capture()); - - final Set tags = getTagSet(tagCaptor.getValue()); - assertEquals(tags, Set.of(Tag.of(Experiment.OUTCOME_TAG, Experiment.MATCH_OUTCOME))); - - verify(timer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + experiment.compareSupplierResult(12, () -> 12); + verify(matchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); } @Test public void compareSupplierResultMismatch() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareSupplierResult(12, () -> 77); - - @SuppressWarnings("unchecked") final ArgumentCaptor> tagCaptor = ArgumentCaptor.forClass(Iterable.class); - - verify(meterRegistry).timer(anyString(), tagCaptor.capture()); - - final Set tags = getTagSet(tagCaptor.getValue()); - assertEquals(tags, Set.of(Tag.of(Experiment.OUTCOME_TAG, Experiment.MISMATCH_OUTCOME))); - - verify(timer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + experiment.compareSupplierResult(12, () -> 77); + verify(mismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); } @Test public void compareSupplierResultError() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareSupplierResult(12, () -> { throw new RuntimeException("OH NO"); }); - - @SuppressWarnings("unchecked") final ArgumentCaptor> tagCaptor = ArgumentCaptor.forClass(Iterable.class); - - verify(meterRegistry).timer(anyString(), tagCaptor.capture()); - - final Set tags = getTagSet(tagCaptor.getValue()); - assertEquals(tags, Set.of(Tag.of(Experiment.OUTCOME_TAG, Experiment.ERROR_OUTCOME), Tag.of(Experiment.CAUSE_TAG, "RuntimeException"))); - - verify(timer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); + experiment.compareSupplierResult(12, () -> { throw new RuntimeException("OH NO"); }); + verify(errorTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); } @Test public void compareSupplierResultNoExperimentData() { - final Timer timer = mock(Timer.class); - when(meterRegistry.timer(anyString(), ArgumentMatchers.>any())).thenReturn(timer); - - new Experiment(meterRegistry, "test").compareSupplierResult(12, () -> null); - - verify(timer, never()).record(anyLong(), eq(TimeUnit.NANOSECONDS)); - } - - private static Set getTagSet(final Iterable tags) { - final Set tagSet = new HashSet<>(); - - for (final Tag tag : tags) { - tagSet.add(tag); - } - - return tagSet; + experiment.compareSupplierResult(12, () -> null); + verifyNoMoreInteractions(mismatchTimer, mismatchTimer, errorTimer); } }