Return to just using counters instead of timers for measuring experiment outcomes.

This commit is contained in:
Jon Chambers 2020-06-17 14:41:42 -04:00 committed by Jon Chambers
parent 4c1844e46a
commit 6adcebb247
2 changed files with 52 additions and 78 deletions

View File

@ -1,26 +1,26 @@
package org.whispersystems.textsecuregcm.experiment; package org.whispersystems.textsecuregcm.experiment;
import com.codahale.metrics.MetricRegistry;
import com.google.common.annotations.VisibleForTesting; import com.google.common.annotations.VisibleForTesting;
import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.Metrics; import io.micrometer.core.instrument.Metrics;
import io.micrometer.core.instrument.Timer;
import java.util.Objects; import java.util.Objects;
import java.util.concurrent.CompletionStage; import java.util.concurrent.CompletionStage;
import java.util.concurrent.TimeUnit;
import java.util.function.Supplier; 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. * An experiment compares the results of two operations and records metrics to assess how frequently they match.
*/ */
public class Experiment { public class Experiment {
private final Timer matchTimer; private final Counter matchCounter;
private final Timer errorTimer; private final Counter errorCounter;
private final Timer bothPresentMismatchTimer; private final Counter bothPresentMismatchCounter;
private final Timer controlNullMismatchTimer; private final Counter controlNullMismatchCounter;
private final Timer experimentNullMismatchTimer; private final Counter experimentNullMismatchCounter;
private static final String OUTCOME_TAG = "outcome"; private static final String OUTCOME_TAG = "outcome";
private static final String MATCH_OUTCOME = "match"; private static final String MATCH_OUTCOME = "match";
@ -33,77 +33,54 @@ public class Experiment {
private static final String EXPERIMENT_NULL_MISMATCH = "experimentResultNull"; private static final String EXPERIMENT_NULL_MISMATCH = "experimentResultNull";
public Experiment(final String... names) { public Experiment(final String... names) {
this(buildTimer(MATCH_OUTCOME, names).register(Metrics.globalRegistry), this(Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MATCH_OUTCOME),
buildTimer(ERROR_OUTCOME, names).register(Metrics.globalRegistry), Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, ERROR_OUTCOME),
buildTimer(MISMATCH_OUTCOME, names).tag(MISMATCH_TYPE_TAG, BOTH_PRESENT_MISMATCH).register(Metrics.globalRegistry), Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MISMATCH_OUTCOME, MISMATCH_TYPE_TAG, BOTH_PRESENT_MISMATCH),
buildTimer(MISMATCH_OUTCOME, names).tag(MISMATCH_TYPE_TAG, CONTROL_NULL_MISMATCH).register(Metrics.globalRegistry), Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MISMATCH_OUTCOME, MISMATCH_TYPE_TAG, CONTROL_NULL_MISMATCH),
buildTimer(MISMATCH_OUTCOME, names).tag(MISMATCH_TYPE_TAG, EXPERIMENT_NULL_MISMATCH).register(Metrics.globalRegistry)); Metrics.counter(name(Experiment.class, names), OUTCOME_TAG, MISMATCH_OUTCOME, MISMATCH_TYPE_TAG, EXPERIMENT_NULL_MISMATCH));
}
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();
} }
@VisibleForTesting @VisibleForTesting
Experiment(final Timer matchTimer, final Timer errorTimer, final Timer bothPresentMismatchTimer, final Timer controlNullMismatchTimer, final Timer experimentNullMismatchTimer) { Experiment(final Counter matchCounter, final Counter errorCounter, final Counter bothPresentMismatchCounter, final Counter controlNullMismatchCounter, final Counter experimentNullMismatchCounter) {
this.matchTimer = matchTimer; this.matchCounter = matchCounter;
this.errorTimer = errorTimer; this.errorCounter = errorCounter;
this.bothPresentMismatchTimer = bothPresentMismatchTimer; this.bothPresentMismatchCounter = bothPresentMismatchCounter;
this.controlNullMismatchTimer = controlNullMismatchTimer; this.controlNullMismatchCounter = controlNullMismatchCounter;
this.experimentNullMismatchTimer = experimentNullMismatchTimer; this.experimentNullMismatchCounter = experimentNullMismatchCounter;
} }
public <T> void compareFutureResult(final T expected, final CompletionStage<T> experimentStage) { public <T> void compareFutureResult(final T expected, final CompletionStage<T> 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) -> { experimentStage.whenComplete((actual, cause) -> {
final long duration = System.nanoTime() - start;
if (cause != null) { if (cause != null) {
recordError(duration); errorCounter.increment();
} else { } else {
recordResult(duration, expected, actual); recordResult(expected, actual);
} }
}); });
} }
public <T> void compareSupplierResult(final T expected, final Supplier<T> experimentSupplier) { public <T> void compareSupplierResult(final T expected, final Supplier<T> experimentSupplier) {
final long start = System.nanoTime();
try { try {
final T result = experimentSupplier.get(); recordResult(expected, experimentSupplier.get());
recordResult(System.nanoTime() - start, expected, result);
} catch (final Exception e) { } catch (final Exception e) {
recordError(System.nanoTime() - start); errorCounter.increment();
} }
} }
private void recordError(final long durationNanos) { private <T> void recordResult(final T expected, final T actual) {
errorTimer.record(durationNanos, TimeUnit.NANOSECONDS); final Counter counter;
}
private <T> void recordResult(final long durationNanos, final T expected, final T actual) {
final Timer timer;
if (Objects.equals(expected, actual)) { if (Objects.equals(expected, actual)) {
timer = matchTimer; counter = matchCounter;
} else if (expected == null) { } else if (expected == null) {
timer = controlNullMismatchTimer; counter = controlNullMismatchCounter;
} else if (actual == null) { } else if (actual == null) {
timer = experimentNullMismatchTimer; counter = experimentNullMismatchCounter;
} else { } else {
timer = bothPresentMismatchTimer; counter = bothPresentMismatchCounter;
} }
timer.record(durationNanos, TimeUnit.NANOSECONDS); counter.increment();
} }
} }

View File

@ -1,95 +1,92 @@
package org.whispersystems.textsecuregcm.experiment; package org.whispersystems.textsecuregcm.experiment;
import io.micrometer.core.instrument.Timer; import io.micrometer.core.instrument.Counter;
import org.junit.Before; import org.junit.Before;
import org.junit.Test; import org.junit.Test;
import java.util.concurrent.CompletableFuture; 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.mock;
import static org.mockito.Mockito.verify; import static org.mockito.Mockito.verify;
public class ExperimentTest { public class ExperimentTest {
private Timer matchTimer; private Counter matchCounter;
private Timer errorTimer; private Counter errorCounter;
private Timer bothPresentMismatchTimer; private Counter bothPresentMismatchCounter;
private Timer controlNullMismatchTimer; private Counter controlNullMismatchCounter;
private Timer experimentNullMismatchTimer; private Counter experimentNullMismatchCounter;
private Experiment experiment; private Experiment experiment;
@Before @Before
public void setUp() { public void setUp() {
matchTimer = mock(Timer.class); matchCounter = mock(Counter.class);
errorTimer = mock(Timer.class); errorCounter = mock(Counter.class);
bothPresentMismatchTimer = mock(Timer.class); bothPresentMismatchCounter = mock(Counter.class);
controlNullMismatchTimer = mock(Timer.class); controlNullMismatchCounter = mock(Counter.class);
experimentNullMismatchTimer = mock(Timer.class); experimentNullMismatchCounter = mock(Counter.class);
experiment = new Experiment(matchTimer, errorTimer, bothPresentMismatchTimer, controlNullMismatchTimer, experimentNullMismatchTimer); experiment = new Experiment(matchCounter, errorCounter, bothPresentMismatchCounter, controlNullMismatchCounter, experimentNullMismatchCounter);
} }
@Test @Test
public void compareFutureResultMatch() { public void compareFutureResultMatch() {
experiment.compareFutureResult(12, CompletableFuture.completedFuture(12)); experiment.compareFutureResult(12, CompletableFuture.completedFuture(12));
verify(matchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(matchCounter).increment();
} }
@Test @Test
public void compareFutureResultMismatchBothPresent() { public void compareFutureResultMismatchBothPresent() {
experiment.compareFutureResult(12, CompletableFuture.completedFuture(77)); experiment.compareFutureResult(12, CompletableFuture.completedFuture(77));
verify(bothPresentMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(bothPresentMismatchCounter).increment();
} }
@Test @Test
public void compareFutureResultMismatchControlNull() { public void compareFutureResultMismatchControlNull() {
experiment.compareFutureResult(null, CompletableFuture.completedFuture(77)); experiment.compareFutureResult(null, CompletableFuture.completedFuture(77));
verify(controlNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(controlNullMismatchCounter).increment();
} }
@Test @Test
public void compareFutureResultMismatchExperimentNull() { public void compareFutureResultMismatchExperimentNull() {
experiment.compareFutureResult(12, CompletableFuture.completedFuture(null)); experiment.compareFutureResult(12, CompletableFuture.completedFuture(null));
verify(experimentNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(experimentNullMismatchCounter).increment();
} }
@Test @Test
public void compareFutureResultError() { public void compareFutureResultError() {
experiment.compareFutureResult(12, CompletableFuture.failedFuture(new RuntimeException("OH NO"))); experiment.compareFutureResult(12, CompletableFuture.failedFuture(new RuntimeException("OH NO")));
verify(errorTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(errorCounter).increment();
} }
@Test @Test
public void compareSupplierResultMatch() { public void compareSupplierResultMatch() {
experiment.compareSupplierResult(12, () -> 12); experiment.compareSupplierResult(12, () -> 12);
verify(matchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(matchCounter).increment();
} }
@Test @Test
public void compareSupplierResultMismatchBothPresent() { public void compareSupplierResultMismatchBothPresent() {
experiment.compareSupplierResult(12, () -> 77); experiment.compareSupplierResult(12, () -> 77);
verify(bothPresentMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(bothPresentMismatchCounter).increment();
} }
@Test @Test
public void compareSupplierResultMismatchControlNull() { public void compareSupplierResultMismatchControlNull() {
experiment.compareSupplierResult(null, () -> 77); experiment.compareSupplierResult(null, () -> 77);
verify(controlNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(controlNullMismatchCounter).increment();
} }
@Test @Test
public void compareSupplierResultMismatchExperimentNull() { public void compareSupplierResultMismatchExperimentNull() {
experiment.compareSupplierResult(12, () -> null); experiment.compareSupplierResult(12, () -> null);
verify(experimentNullMismatchTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(experimentNullMismatchCounter).increment();
} }
@Test @Test
public void compareSupplierResultError() { public void compareSupplierResultError() {
experiment.compareSupplierResult(12, () -> { throw new RuntimeException("OH NO"); }); experiment.compareSupplierResult(12, () -> { throw new RuntimeException("OH NO"); });
verify(errorTimer).record(anyLong(), eq(TimeUnit.NANOSECONDS)); verify(errorCounter).increment();
} }
} }