Repository: dropwizard/metrics
Pull request #3929 (2024-01-30 22:22:24)

Fix slowTickIfNecessary with infrequently used EWMA
EWMA.tickIfNecessary does an amount of work that is linear to the amount of time that has passed since the last time the EWMA was ticked. For infrequently used EWMA this can lead to pauses observed in the 700-800 millisecond range after a few hundred days.

It's not really necessary to perform every tick as all that is doing is slowly approaching the smallest representable positive number in a double. Instead pick a number close to zero and then bound the number of ticks to allow that to be reachable from the largest value representable by the EWMA. Actually approaching the smallest representable number is still measurably slow and not particularly useful.

aweisberg: It seems like versions prior to `4.2.x` are unmaintained so it's not possible to get this fixed in earlier versions?

More context on the issue and how it was found [CASSANDRA-19332](CASSANDRA-19332)
joschi: @aweisberg Thanks for your contribution!

> It seems like versions prior to `4.2.x` are unmaintained so it's not possible to get this fixed in earlier versions?

Yes, that's correct. Any version before Dropwizard Metrics 4.2.x is unmaintained.

Which version are you using exactly in Cassandra?
aweisberg: It's a mix, this is a list of active versions with 3.0/3.11 soon to be unsupported. 4.x will probably be supported for 5+ years. Not a big deal as the work around is to read all the Meters periodically.
5.0+ `4.2.19`
4.1 `3.1.5`
4.0 `3.1.5`
3.11 `3.1.5`
3.0 `3.1.0`

aweisberg: @joschi  what is the next step? I reworked the fix slightly to reset the `EWMA`s to the smallest representable positive value instead of performing even the bounded amount of ticks.

It doesn't set it to 0.0 because that was not the existing behavior which after the `EWMA` is first used will always at least have rate set to `Double.MIN_NORMAL`. Probably not important, but who knows what downstream stuff might not want that to change.
smiklosovic: @joschi would you mind to take a look at this please? Cassandra project would be very happy if this was included :)

Patch:
diff --git a/metrics-core/src/main/java/com/codahale/metrics/EWMA.java b/metrics-core/src/main/java/com/codahale/metrics/EWMA.java
index 2d2e65809..641bb728c 100644
--- a/metrics-core/src/main/java/com/codahale/metrics/EWMA.java
+++ b/metrics-core/src/main/java/com/codahale/metrics/EWMA.java
@@ -81,6 +81,14 @@ public class EWMA {
         uncounted.add(n);
     }
 
+    /**
+     * Set the rate to the smallest possible positive value. Used to avoid calling tick a large number of times.
+     */
+    public void reset() {
+        uncounted.reset();
+        rate = Double.MIN_NORMAL;
+    }
+
     /**
      * Mark the passage of time and decay the current rate accordingly.
      */
diff --git a/metrics-core/src/main/java/com/codahale/metrics/ExponentialMovingAverages.java b/metrics-core/src/main/java/com/codahale/metrics/ExponentialMovingAverages.java
index 9879d280e..0a12129c7 100644
--- a/metrics-core/src/main/java/com/codahale/metrics/ExponentialMovingAverages.java
+++ b/metrics-core/src/main/java/com/codahale/metrics/ExponentialMovingAverages.java
@@ -11,8 +11,28 @@ import java.util.concurrent.atomic.AtomicLong;
  */
 public class ExponentialMovingAverages implements MovingAverages {
 
+    /**
+     * If ticking would reduce even Long.MAX_VALUE in the 15 minute EWMA below this target then don't bother
+     * ticking in a loop and instead reset all the EWMAs.
+     */
+    private static final double maxTickZeroTarget = 0.0001;
+    private static final int maxTicks;
     private static final long TICK_INTERVAL = TimeUnit.SECONDS.toNanos(5);
 
+    static
+    {
+        int m3Ticks = 1;
+        final EWMA m3 = EWMA.fifteenMinuteEWMA();
+        m3.update(Long.MAX_VALUE);
+        do
+        {
+            m3.tick();
+            m3Ticks++;
+        }
+        while (m3.getRate(TimeUnit.SECONDS) > maxTickZeroTarget);
+        maxTicks = m3Ticks;
+    }
+
     private final EWMA m1Rate = EWMA.oneMinuteEWMA();
     private final EWMA m5Rate = EWMA.fiveMinuteEWMA();
     private final EWMA m15Rate = EWMA.fifteenMinuteEWMA();
@@ -51,10 +71,19 @@ public class ExponentialMovingAverages implements MovingAverages {
             final long newIntervalStartTick = newTick - age % TICK_INTERVAL;
             if (lastTick.compareAndSet(oldTick, newIntervalStartTick)) {
                 final long requiredTicks = age / TICK_INTERVAL;
-                for (long i = 0; i < requiredTicks; i++) {
-                    m1Rate.tick();
-                    m5Rate.tick();
-                    m15Rate.tick();
+                if (requiredTicks >= maxTicks) {
+                    m1Rate.reset();
+                    m5Rate.reset();
+                    m15Rate.reset();
+                }
+                else
+                {
+                    for (long i = 0; i < requiredTicks; i++)
+                    {
+                        m1Rate.tick();
+                        m5Rate.tick();
+                        m15Rate.tick();
+                    }
                 }
             }
         }
diff --git a/metrics-core/src/main/java/com/codahale/metrics/ScheduledReporter.java b/metrics-core/src/main/java/com/codahale/metrics/ScheduledReporter.java
index 4723cdfc8..bb7ad86c1 100644
--- a/metrics-core/src/main/java/com/codahale/metrics/ScheduledReporter.java
+++ b/metrics-core/src/main/java/com/codahale/metrics/ScheduledReporter.java
@@ -220,10 +220,13 @@ public abstract class ScheduledReporter implements Closeable, Reporter {
             executor.shutdown(); // Disable new tasks from being submitted
         }
 
-        try {
-            report(); // Report metrics one last time
-        } catch (Exception e) {
-            LOG.warn("Final reporting of metrics failed.", e);
+        if (this.scheduledFuture != null) {
+            // Reporter started, try to report metrics one last time
+            try {
+                report();
+            } catch (Exception e) {
+                LOG.warn("Final reporting of metrics failed.", e);
+            }
         }
 
         if (shutdownExecutorOnStop) {


Test patch:
diff --git a/metrics-core/src/test/java/com/codahale/metrics/ExponentialMovingAveragesTest.java b/metrics-core/src/test/java/com/codahale/metrics/ExponentialMovingAveragesTest.java
new file mode 100644
index 000000000..2a8494006
--- /dev/null
+++ b/metrics-core/src/test/java/com/codahale/metrics/ExponentialMovingAveragesTest.java
@@ -0,0 +1,26 @@
+package com.codahale.metrics;
+
+import java.util.concurrent.TimeUnit;
+
+import org.junit.Test;
+
+import static org.junit.Assert.assertEquals;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.when;
+
+public class ExponentialMovingAveragesTest
+{
+    @Test
+    public void testMaxTicks()
+    {
+        final Clock clock = mock(Clock.class);
+        when(clock.getTick()).thenReturn(0L, Long.MAX_VALUE);
+        final ExponentialMovingAverages ema = new ExponentialMovingAverages(clock);
+        ema.update(Long.MAX_VALUE);
+        ema.tickIfNecessary();
+        final long secondNanos = TimeUnit.SECONDS.toNanos(1);
+        assertEquals(ema.getM1Rate(), Double.MIN_NORMAL * secondNanos, 0.0);
+        assertEquals(ema.getM5Rate(), Double.MIN_NORMAL * secondNanos, 0.0);
+        assertEquals(ema.getM15Rate(), Double.MIN_NORMAL * secondNanos, 0.0);
+    }
+}
diff --git a/metrics-graphite/src/test/java/com/codahale/metrics/graphite/GraphiteReporterTest.java b/metrics-graphite/src/test/java/com/codahale/metrics/graphite/GraphiteReporterTest.java
index 3498b2ce6..240c0d26f 100644
--- a/metrics-graphite/src/test/java/com/codahale/metrics/graphite/GraphiteReporterTest.java
+++ b/metrics-graphite/src/test/java/com/codahale/metrics/graphite/GraphiteReporterTest.java
@@ -445,6 +445,7 @@ public class GraphiteReporterTest {
 
     @Test
     public void closesConnectionOnReporterStop() throws Exception {
+        reporter.start(1, TimeUnit.SECONDS);
         reporter.stop();
 
         final InOrder inOrder = inOrder(graphite);