Log warning about "function" meter re-registration (#6070)

Includes other "function" meters in the double registration check in addition to the existing check for Gauges.

See gh-5616
See gh-5688
See gh-5617

Author: jonatan-ivanov

docs/modules/ROOT/pages/concepts/counters.adoc

@@ -117,3 +117,11 @@ FunctionCounter counter = FunctionCounter
     .tags("region", "test") // optional
     .register(registry);
 ----
+
+WARNING: Attempting to construct a function-tracking counter with a primitive number or one of its `java.lang` object forms is always incorrect. These numbers are immutable. Thus, the function-tracking counter cannot ever be changed. Attempting to "re-register" the function-tracking counter with a different number does not work, as the registry maintains only one meter for each unique combination of name and tags. "Re-registering" a function-tracking counter can happen indirectly for example as the result of a `MeterFilter` modifying the name and/or the tags of two different function-tracking counter so that they will be the same after the filter is applied.
+
+Attempting to "re-register" a function-tracking counter will result in a warning like this:
+[source]
+----
+WARNING: This FunctionCounter has been already registered (MeterId{name='my.fc', tags=[]}), the registration will be ignored. Note that subsequent logs will be logged at debug level.
+----

docs/modules/ROOT/pages/concepts/gauges.adoc

@@ -44,6 +44,12 @@ This pattern should be less common than the `DoubleFunction` form. Remember that
 
 WARNING: Attempting to construct a gauge with a primitive number or one of its `java.lang` object forms is always incorrect. These numbers are immutable. Thus, the gauge cannot ever be changed. Attempting to "re-register" the gauge with a different number does not work, as the registry maintains only one meter for each unique combination of name and tags. "Re-registering" a gauge can happen indirectly for example as the result of a `MeterFilter` modifying the name and/or the tags of two different gauges so that they will be the same after the filter is applied.
 
+Attempting to "re-register" a gauge will result in a warning like this:
+[source]
+----
+WARNING: This Gauge has been already registered (MeterId{name='my.gauge', tags=[]}), the registration will be ignored. Note that subsequent logs will be logged at debug level.
+----
+
 == Gauge Fluent Builder
 
 The interface contains a fluent builder for gauges:

docs/modules/ROOT/pages/concepts/timers.adoc

@@ -182,6 +182,14 @@ FunctionTimer.builder("cache.gets.latency", cache,
     .register(registry);
 ----
 
+WARNING: Attempting to construct a function-tracking timer with a primitive number or one of its `java.lang` object forms is always incorrect. These numbers are immutable. Thus, the function-tracking timer cannot ever be changed. Attempting to "re-register" the function-tracking timer with a different number does not work, as the registry maintains only one meter for each unique combination of name and tags. "Re-registering" a function-tracking timer can happen indirectly for example as the result of a `MeterFilter` modifying the name and/or the tags of two different function-tracking timer so that they will be the same after the filter is applied.
+
+Attempting to "re-register" a function-tracking timer will result in a warning like this:
+[source]
+----
+WARNING: This FunctionTimer has been already registered (MeterId{name='my.ft', tags=[]}), the registration will be ignored. Note that subsequent logs will be logged at debug level.
+----
+
 == Pause Detection
 
 Micrometer uses the `LatencyUtils` package to compensate for https://highscalability.com/blog/2015/10/5/your-load-generator-is-probably-lying-to-you-take-the-red-pi.html[coordinated omission] -- extra latency arising from system and VM pauses that skew your latency statistics downward. Distribution statistics, such as percentiles and SLO counts, are influenced by a pause detector implementation that adds additional latency here and there to compensate for pauses.

micrometer-core/src/main/java/io/micrometer/core/instrument/MeterRegistry.java

@@ -67,8 +67,7 @@
  */
 public abstract class MeterRegistry {
 
-    private static final WarnThenDebugLogger gaugeDoubleRegistrationLogger = new WarnThenDebugLogger(
-            MeterRegistry.class);
+    private static final WarnThenDebugLogger doubleRegistrationLogger = new WarnThenDebugLogger(MeterRegistry.class);
 
     // @formatter:off
     private static final EnumMap<TimeUnit, String> BASE_TIME_UNIT_STRING_CACHE = Arrays.stream(TimeUnit.values())
@@ -640,7 +639,7 @@ private Meter getOrCreateMeter(@Nullable DistributionStatisticConfig config,
 
         Meter m = preFilterIdToMeterMap.get(originalId);
         if (m != null && !isStaleId(originalId)) {
-            checkAndWarnAboutGaugeDoubleRegistration(m);
+            checkAndWarnAboutDoubleRegistration(m);
             return m;
         }
 
@@ -653,7 +652,7 @@ private Meter getOrCreateMeter(@Nullable DistributionStatisticConfig config,
             if (isStaleId(originalId)) {
                 unmarkStaleId(originalId);
             }
-            checkAndWarnAboutGaugeDoubleRegistration(m);
+            checkAndWarnAboutDoubleRegistration(m);
         }
         else {
             if (isClosed()) {
@@ -712,12 +711,21 @@ private boolean unmarkStaleId(Id originalId) {
         return !stalePreFilterIds.isEmpty() && stalePreFilterIds.remove(originalId);
     }
 
-    private void checkAndWarnAboutGaugeDoubleRegistration(Meter meter) {
-        if (meter instanceof Gauge) {
-            gaugeDoubleRegistrationLogger.log(() -> String.format(
-                    "This Gauge has been already registered (%s), the Gauge registration will be ignored.",
-                    meter.getId()));
+    private void checkAndWarnAboutDoubleRegistration(Meter meter) {
+        if (meter instanceof Gauge) { // also TimeGauge
+            warnAboutDoubleRegistration("Gauge", meter.getId());
         }
+        else if (meter instanceof FunctionCounter) {
+            warnAboutDoubleRegistration("FunctionCounter", meter.getId());
+        }
+        else if (meter instanceof FunctionTimer) {
+            warnAboutDoubleRegistration("FunctionTimer", meter.getId());
+        }
+    }
+
+    private void warnAboutDoubleRegistration(String type, Meter.Id id) {
+        doubleRegistrationLogger.log(() -> String
+            .format("This %s has been already registered (%s), the registration will be ignored.", type, id));
     }
 
     private boolean accept(Meter.Id id) {

micrometer-test/src/main/java/io/micrometer/core/tck/MeterRegistryCompatibilityKit.java

@@ -472,6 +472,138 @@ void gaugesCannotBeRegisteredEffectivelyTwice() {
 
     }
 
+    @DisplayName("functionCounters")
+    @Nested
+    class FunctionCounterTck {
+
+        @Test
+        @DisplayName("functionCounters cannot be registered twice")
+        void functionCountersCannotBeRegisteredTwice() {
+            FunctionCounter.builder("my.fc", this, x -> 1).register(registry);
+            FunctionCounter.builder("my.fc", this, x -> 2).register(registry);
+            clock(registry).add(step());
+
+            assertThat(registry.get("my.fc").functionCounters()).hasSize(1);
+            assertThat(registry.get("my.fc").functionCounter().count()).isEqualTo(1);
+        }
+
+        @Test
+        @DisplayName("functionCounters cannot be registered effectively twice")
+        void functionCountersCannotBeRegisteredEffectivelyTwice() {
+            registry.config().meterFilter(MeterFilter.ignoreTags("ignored"));
+            FunctionCounter.builder("my.fc", this, x -> 3).tags("ignored", "3").register(registry);
+            FunctionCounter.builder("my.fc", this, x -> 4).tags("ignored", "4").register(registry);
+            clock(registry).add(step());
+
+            assertThat(registry.get("my.fc").functionCounters()).hasSize(1);
+            assertThat(registry.get("my.fc").functionCounter().count()).isEqualTo(3);
+        }
+
+    }
+
+    @DisplayName("functionTimers")
+    @Nested
+    class FunctionTimerTck {
+
+        @Test
+        @DisplayName("functionTimers cannot be registered twice")
+        void functionTimersCannotBeRegisteredTwice() {
+            FunctionTimer.builder("my.ft", this, x -> 1, x -> 100, TimeUnit.MILLISECONDS).register(registry);
+            FunctionTimer.builder("my.ft", this, x -> 2, x -> 200, TimeUnit.MILLISECONDS).register(registry);
+            clock(registry).add(step());
+
+            assertThat(registry.get("my.ft").functionTimers()).hasSize(1);
+            assertThat(registry.get("my.ft").functionTimer().count()).isEqualTo(1);
+            assertThat(registry.get("my.ft").functionTimer().totalTime(TimeUnit.MILLISECONDS)).isEqualTo(100);
+        }
+
+        @Test
+        @DisplayName("functionTimers cannot be registered effectively twice")
+        void functionTimersCannotBeRegisteredEffectivelyTwice() {
+            registry.config().meterFilter(MeterFilter.ignoreTags("ignored"));
+            FunctionTimer.builder("my.ft", this, x -> 3, x -> 300, TimeUnit.MILLISECONDS)
+                .tags("ignored", "3")
+                .register(registry);
+            FunctionTimer.builder("my.ft", this, x -> 4, x -> 400, TimeUnit.MILLISECONDS)
+                .tags("ignored", "4")
+                .register(registry);
+            clock(registry).add(step());
+
+            assertThat(registry.get("my.ft").functionTimers()).hasSize(1);
+            assertThat(registry.get("my.ft").functionTimer().count()).isEqualTo(3);
+            assertThat(registry.get("my.ft").functionTimer().totalTime(TimeUnit.MILLISECONDS)).isEqualTo(300);
+        }
+
+    }
+
+    @DisplayName("timeGauges")
+    @Nested
+    class TimeGaugeTck {
+
+        @Test
+        @DisplayName("timeGauges cannot be registered twice")
+        void timeGaugesCannotBeRegisteredTwice() {
+            TimeGauge.builder("my.tg", () -> 100, TimeUnit.MILLISECONDS).register(registry);
+            TimeGauge.builder("my.tg", () -> 200, TimeUnit.MILLISECONDS).register(registry);
+
+            assertThat(registry.get("my.tg").timeGauges()).hasSize(1);
+            assertThat(registry.get("my.tg").timeGauge().value(TimeUnit.MILLISECONDS)).isEqualTo(100);
+        }
+
+        @Test
+        @DisplayName("timeGauges cannot be registered effectively twice")
+        void timeGaugesCannotBeRegisteredEffectivelyTwice() {
+            registry.config().meterFilter(MeterFilter.ignoreTags("ignored"));
+            TimeGauge.builder("my.tg", () -> 300, TimeUnit.MILLISECONDS).tags("ignored", "3").register(registry);
+            TimeGauge.builder("my.tg", () -> 400, TimeUnit.MILLISECONDS).tags("ignored", "4").register(registry);
+
+            assertThat(registry.get("my.tg").timeGauges()).hasSize(1);
+            assertThat(registry.get("my.tg").timeGauge().value(TimeUnit.MILLISECONDS)).isEqualTo(300);
+        }
+
+    }
+
+    @DisplayName("multiGauges")
+    @Nested
+    class MultiGaugeTck {
+
+        @Test
+        @DisplayName("multiGauges can be registered twice because they take care about de-registering the previous Gauge if overwrite=true")
+        void multiGaugesCanBeRegisteredTwice() {
+            MultiGauge gauges = MultiGauge.builder("my.gauge").register(registry);
+            gauges.register(Collections.singletonList(MultiGauge.Row.of(Tags.of("test", "true"), 1)));
+
+            // no re-registration since overwrite is false by default
+            gauges.register(Collections.singletonList(MultiGauge.Row.of(Tags.of("test", "true"), 2)));
+            assertThat(registry.get("my.gauge").tags("test", "true").gauges()).hasSize(1);
+            assertThat(registry.get("my.gauge").tags("test", "true").gauge().value()).isEqualTo(1);
+
+            // re-registration since overwrite is set to true
+            gauges.register(Collections.singletonList(MultiGauge.Row.of(Tags.of("test", "true"), 3)), true);
+            assertThat(registry.get("my.gauge").tags("test", "true").gauges()).hasSize(1);
+            assertThat(registry.get("my.gauge").tags("test", "true").gauge().value()).isEqualTo(3);
+        }
+
+        @Test
+        @DisplayName("multiGauges can be registered effectively twice because they take care about de-registering the previous Gauge if overwrite=true")
+        void multiGaugesCanBeRegisteredEffectivelyTwice() {
+            registry.config().meterFilter(MeterFilter.ignoreTags("ignored"));
+            MultiGauge gauges = MultiGauge.builder("my.gauge").register(registry);
+            gauges.register(Collections.singletonList(MultiGauge.Row.of(Tags.of("ignored", "true"), 4)));
+
+            // no re-registration since overwrite is false by default
+            gauges.register(Collections.singletonList(MultiGauge.Row.of(Tags.of("ignored", "true"), 5)));
+            assertThat(registry.get("my.gauge").gauges()).hasSize(1);
+            assertThat(registry.get("my.gauge").gauge().value()).isEqualTo(4);
+
+            // re-registration since overwrite is set to true
+            gauges.register(Collections.singletonList(MultiGauge.Row.of(Tags.of("ignored", "true"), 6)), true);
+            assertThat(registry.get("my.gauge").gauges()).hasSize(1);
+            assertThat(registry.get("my.gauge").gauge().value()).isEqualTo(6);
+        }
+
+    }
+
     @DisplayName("long task timers")
     @Nested
     class LongTaskTimerTck {