Make richer latency stats

Makes a LatencyStats which provides some useful metrics, best explained there
and in LatencyMetrics.  This includes latency metrics, the "QPS" (e.g. the
number of acquire() per second), and load metrics.

Unfortunately I had to move from atomics to synchronized to accomplish this,
but I see no other way.

4 files changed, 144 insertions, 139 deletions

diff --git a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/AtomicDurationSumTest.java b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/AtomicDurationSumTest.java
deleted file mode 100644
index f1f9ce5950b..00000000000
--- a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/AtomicDurationSumTest.java
+++ /dev/null
@@ -1,80 +0,0 @@
-package com.yahoo.vespa.curator.stats;// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
-
-import org.junit.Test;
-
-import java.time.Duration;
-
-import static org.junit.Assert.assertEquals;
-
-/**
- * @author hakon
- */
-public class AtomicDurationSumTest {
-    private final AtomicDurationSum atomicDurationSum = new AtomicDurationSum();
-
-    @Test
-    public void test() {
-        assertAtomicDurationSum(Duration.ZERO, 0);
-        atomicDurationSum.add(Duration.ofMillis(3));
-        assertAtomicDurationSum(Duration.ofMillis(3), 1);
-        atomicDurationSum.add(Duration.ofMillis(5));
-        assertAtomicDurationSum(Duration.ofMillis(8), 2);
-        assertEquals(0.004, atomicDurationSum.get().averageDuration().get().toMillis() / 1000., 0.00001);
-
-        DurationSum durationSum = atomicDurationSum.getAndReset();
-        assertEquals(Duration.ofMillis(8), durationSum.duration());
-        assertEquals(2, durationSum.count());
-        assertAtomicDurationSum(Duration.ZERO, 0);
-    }
-
-    @Test
-    public void testNegatives() {
-        atomicDurationSum.add(Duration.ofMillis(-1));
-        assertAtomicDurationSum(Duration.ofMillis(-1), 1);
-    }
-
-    private void assertAtomicDurationSum(Duration expectedDuration, int expectedCount) {
-        DurationSum durationSum = atomicDurationSum.get();
-        assertEquals(expectedDuration, durationSum.duration());
-        assertEquals(expectedCount, durationSum.count());
-    }
-
-    @Test
-    public void encoding() {
-        assertEquals(40, AtomicDurationSum.DURATION_BITS);
-        assertEquals(24, AtomicDurationSum.COUNT_BITS);
-
-        assertEquals(0xFFFFFFFFFF000000L, AtomicDurationSum.DURATION_MASK);
-        assertEquals(0x0000000000FFFFFFL, AtomicDurationSum.COUNT_MASK);
-
-        // duration is signed
-        assertEquals(0xFFFFFF8000000000L, AtomicDurationSum.MIN_DURATION);
-        assertEquals(0x0000007FFFFFFFFFL, AtomicDurationSum.MAX_DURATION);
-
-        // count is unsigned
-        assertEquals(0x0000000000000000L, AtomicDurationSum.MIN_COUNT);
-        assertEquals(0x0000000000FFFFFFL, AtomicDurationSum.MAX_COUNT);
-
-        assertDurationEncoding(Duration.ZERO);
-        assertDurationEncoding(Duration.ofMillis(1));
-        assertDurationEncoding(Duration.ofMillis(-1));
-        assertDurationEncoding(Duration.ofMillis(AtomicDurationSum.MIN_DURATION));
-        assertDurationEncoding(Duration.ofMillis(AtomicDurationSum.MAX_DURATION));
-
-        assertCountEncoding(1L);
-        assertCountEncoding(AtomicDurationSum.MIN_COUNT);
-        assertCountEncoding(AtomicDurationSum.MAX_COUNT);
-        assertEquals(0L, AtomicDurationSum.decodeCount(AtomicDurationSum.MAX_COUNT + 1));
-    }
-
-    private void assertDurationEncoding(Duration duration) {
-        long encoded = AtomicDurationSum.encodeDuration(duration);
-        Duration decodedDuration = AtomicDurationSum.decodeDuration(encoded);
-        assertEquals(duration, decodedDuration);
-    }
-
-    private void assertCountEncoding(long count) {
-        int actualCount = AtomicDurationSum.decodeCount(count);
-        assertEquals(count, actualCount);
-    }
-}
\ No newline at end of file
diff --git a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LatencyStatsTest.java b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LatencyStatsTest.java
new file mode 100644
index 00000000000..981b3571056
--- /dev/null
+++ b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LatencyStatsTest.java
@@ -0,0 +1,144 @@
+package com.yahoo.vespa.curator.stats;// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+
+import com.yahoo.vespa.curator.stats.LatencyStats.ActiveInterval;
+import org.junit.Test;
+
+import java.util.function.LongSupplier;
+
+import static org.junit.Assert.assertEquals;
+
+public class LatencyStatsTest {
+    private final NanoTimeSupplier nanoTimeSupplier = new NanoTimeSupplier();
+    private final LatencyStats stats = new LatencyStats(nanoTimeSupplier);
+
+    @Test
+    public void defaults() {
+        assertNoActivity(stats.getLatencyMetrics());
+        assertNoActivity(stats.getLatencyMetricsAndStartNewPeriod());
+        assertNoActivity(stats.getLatencyMetricsAndStartNewPeriod());
+    }
+
+    @Test
+    public void oneInterval() {
+        ActiveInterval activeInterval = stats.startNewInterval();
+
+        int micros = 1_234_567;
+        nanoTimeSupplier.addMicros(micros);
+        activeInterval.close();
+
+        nanoTimeSupplier.addMicros(32_000_000 - micros);
+        var latencyMetrics = stats.getLatencyMetricsAndStartNewPeriod();
+        // 1.234567 gets truncated to 1.234 (rounding to 1.235 would also be fine)
+        assertDoubleEquals(1.234f, latencyMetrics.latencySeconds());
+        assertDoubleEquals(1.234f, latencyMetrics.maxLatencySeconds());
+        assertDoubleEquals(1.234f, latencyMetrics.maxActiveLatencySeconds());
+        // 1 / 32 = 0.03125
+        assertDoubleEquals(0.031f, latencyMetrics.startHz());
+        assertDoubleEquals(0.031f, latencyMetrics.endHz());
+        // 1.234567 / 32 rounded to 0.039 (truncating to 0.038 would also be fine)
+        assertDoubleEquals(0.039f, latencyMetrics.load());
+        assertEquals(1, latencyMetrics.maxLoad());
+        assertEquals(0, latencyMetrics.currentLoad());
+
+        assertNoActivity();
+    }
+
+    @Test
+    public void manyIntervals() {
+        nanoTimeSupplier.addSeconds(1);
+        ActiveInterval activeInterval1 = stats.startNewInterval();
+        nanoTimeSupplier.addSeconds(1);
+        ActiveInterval activeInterval2 = stats.startNewInterval();
+
+        assertLatencyMetrics(
+                0.0,  // latency: No intervals have ended
+                0.0,  // maxLatency: No intervals have ended
+                1.0,  // maxActiveLatency:  First interval has lasted 1s
+                1.0,  // startHz:  There have been 2 starts in 2 seconds
+                0.0,  // endHz:  There have been 0 endings of intervals
+                0.5,  // load:  First second had 0 active intervals, second second had 1.
+                2,  // maxLoad:  There are now 2 active intervals
+                2);  // currentLoad:  There are now 2 active intervals
+
+        nanoTimeSupplier.addSeconds(1);
+        ActiveInterval activeInterval3 = stats.startNewInterval();
+
+        nanoTimeSupplier.addSeconds(1);
+        activeInterval1.close();
+        activeInterval3.close();
+
+        assertLatencyMetrics(
+                2.0,  // latency: 2 intervals ended: 3s and 1s
+                3.0,
+                3.0,  // maxActiveLatency:  both interval 1 and 2 have 3s latency
+                0.75,  // startHz: 3 started in 4s
+                0.5,
+                1.5,  // load: 1s of each of 0, 1, 2, and 3 active intervals.
+                3,
+                1);
+    }
+
+    @Test
+    public void intervalsCrossingPeriods() {
+        nanoTimeSupplier.addSeconds(1);
+        ActiveInterval activeInterval1 = stats.startNewInterval();
+        nanoTimeSupplier.addSeconds(1);
+
+        stats.getLatencyMetricsAndStartNewPeriod();
+        assertLatencyMetrics(
+                0, 0, 1,  // maxActiveLatency:  One active interval has latency 1s
+                0, 0,
+                1, 1, 1);  // all loads are 1
+
+        nanoTimeSupplier.addSeconds(1);
+        activeInterval1.close();
+        assertLatencyMetrics(
+                2, 2, 2,
+                0, 1,  // startHz, endHz
+                1, 1, 0);  // currentLoad just dropped to 0
+    }
+
+    private void assertLatencyMetrics(double latencySeconds, double maxLatencySeconds, double maxActiveLatencySeconds,
+                                      double startHz, double endHz,
+                                      double load, int maxLoad, int currentLoad) {
+        var latencyMetrics = stats.getLatencyMetrics();
+        assertDoubleEquals(latencySeconds, latencyMetrics.latencySeconds());
+        assertDoubleEquals(maxLatencySeconds, latencyMetrics.maxLatencySeconds());
+        assertDoubleEquals(maxActiveLatencySeconds, latencyMetrics.maxActiveLatencySeconds());
+        assertDoubleEquals(startHz, latencyMetrics.startHz());
+        assertDoubleEquals(endHz, latencyMetrics.endHz());
+        assertDoubleEquals(load, latencyMetrics.load());
+        assertEquals(maxLoad, latencyMetrics.maxLoad());
+        assertEquals(currentLoad, latencyMetrics.currentLoad());
+    }
+
+    private void assertNoActivity() { assertNoActivity(stats.getLatencyMetricsAndStartNewPeriod()); }
+
+    private void assertNoActivity(LatencyMetrics latencyMetrics) {
+        assertDoubleEquals(0.0, latencyMetrics.latencySeconds());
+        assertDoubleEquals(0.0, latencyMetrics.maxLatencySeconds());
+        assertDoubleEquals(0.0, latencyMetrics.maxActiveLatencySeconds());
+        assertDoubleEquals(0.0, latencyMetrics.startHz());
+        assertDoubleEquals(0.0, latencyMetrics.endHz());
+        assertDoubleEquals(0.0, latencyMetrics.load());
+        assertEquals(0, latencyMetrics.maxLoad());
+        assertEquals(0, latencyMetrics.currentLoad());
+    }
+
+    private void assertDoubleEquals(double expected, double actual) {
+        assertEquals(expected, actual, 1e-5);
+    }
+
+    private static class NanoTimeSupplier implements LongSupplier {
+        // The initial nano time should not matter
+        private long nanoTime = 0x678abf4967L;
+
+        public void addSeconds(int seconds) { nanoTime += seconds * 1_000_000_000L; }
+        public void addMillis(int millis) { nanoTime += millis * 1_000_000L; }
+        public void addMicros(int micros) { nanoTime += micros * 1_000L; }
+        public void addNanos(int nanos) { nanoTime += nanos; }
+
+        @Override
+        public long getAsLong() { return nanoTime; }
+    }
+}
\ No newline at end of file
diff --git a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LatencyStoreTest.java b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LatencyStoreTest.java
deleted file mode 100644
index 119dccca229..00000000000
--- a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LatencyStoreTest.java
+++ /dev/null
@@ -1,52 +0,0 @@
-package com.yahoo.vespa.curator.stats;// Copyright Verizon Media. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
-
-import com.yahoo.test.ManualClock;
-import org.junit.Test;
-
-import java.time.Duration;
-
-import static org.junit.Assert.assertEquals;
-
-/**
- * @author hakon
- */
-public class LatencyStoreTest {
-    private final ManualClock clock = new ManualClock();
-    private final LatencyStore store = new LatencyStore(clock);
-
-    @Test
-    public void verifyDefaultAndEmpty() {
-        assertGetLatencyMetrics(0, 0.000f, 0f);
-        assertGetAndResetLatencyMetrics(0, 0.000f, 0f);
-        assertGetLatencyMetrics(0, 0.000f, 0f);
-    }
-
-    @Test
-    public void commonCase() {
-        store.reportLatency(Duration.ofMillis(2));
-        store.reportLatency(Duration.ofMillis(6));
-        clock.advance(Duration.ofMillis(2));
-        assertGetLatencyMetrics(2, 0.004f, 4f);
-        clock.advance(Duration.ofMillis(14));
-        assertGetAndResetLatencyMetrics(2, 0.004f, 0.5f);
-        assertGetLatencyMetrics(0, 0.000f, 0f);
-    }
-
-    private void assertGetLatencyMetrics(int count, float average, float load) {
-        LatencyMetrics latencyMetrics = store.getLatencyMetrics();
-        assertEquals(count, latencyMetrics.count());
-        assertDoubleEquals(average, latencyMetrics.averageInSeconds());
-        assertDoubleEquals(load, latencyMetrics.load());
-    }
-
-    private void assertGetAndResetLatencyMetrics(int count, float average, float load) {
-        LatencyMetrics latencyMetrics = store.getAndResetLatencyMetrics();
-        assertEquals(count, latencyMetrics.count());
-        assertDoubleEquals(average, latencyMetrics.averageInSeconds());
-        assertDoubleEquals(load, latencyMetrics.load());
-    }
-
-    private static void assertDoubleEquals(float expected, float actual) {
-        assertEquals(expected, actual, 1e-6);
-    }
-}
\ No newline at end of file
diff --git a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java
index a7715eb9756..d673655c798 100644
--- a/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java
+++ b/zkfacade/src/test/java/com/yahoo/vespa/curator/stats/LockTest.java
@@ -86,9 +86,6 @@ public class LockTest {
         assertEquals(expected.getAndResetAcquireSucceededCount(), actual.getAndResetAcquireSucceededCount());
         assertEquals(expected.getAndResetReleaseCount(), actual.getAndResetReleaseCount());
         assertEquals(expected.getAndResetReleaseFailedCount(), actual.getAndResetReleaseFailedCount());
-
-        assertEquals(expected.getAcquiringNow(), actual.getAcquiringNow());
-        assertEquals(expected.getLockedNow(), actual.getLockedNow());
     }
 
     @Test
@@ -121,7 +118,6 @@ public class LockTest {
         expectedMetrics.setCumulativeAcquireCount(1);
         expectedMetrics.setAcquireSucceededCount(1);
         expectedMetrics.setCumulativeAcquireSucceededCount(1);
-        expectedMetrics.setLockedNow(1);
         assertLockMetrics(expectedMetrics);
 
         // reenter
@@ -131,7 +127,6 @@ public class LockTest {
         expectedMetrics.setCumulativeAcquireCount(2);
         expectedMetrics.setAcquireSucceededCount(1); // reset to 0 above, +1
         expectedMetrics.setCumulativeAcquireSucceededCount(2);
-        expectedMetrics.setLockedNow(2);
         assertLockMetrics(expectedMetrics);
 
         // inner-most closes
@@ -140,14 +135,12 @@ public class LockTest {
         expectedMetrics.setAcquireSucceededCount(0); // reset to 0 above
         expectedMetrics.setReleaseCount(1);
         expectedMetrics.setCumulativeReleaseCount(1);
-        expectedMetrics.setLockedNow(1);
         assertLockMetrics(expectedMetrics);
 
         // outer-most closes
         lock.close();
         expectedMetrics.setReleaseCount(1);  // reset to 0 above, +1
         expectedMetrics.setCumulativeReleaseCount(2);
-        expectedMetrics.setLockedNow(0);
         assertLockMetrics(expectedMetrics);
     }