Warn when a MeterFilter is configured after a meter is registered

In normal usage we would expect this should not happen, but there is nothing enforcing or encouraging it to not happen. This warns users via logging that it is happening and advises to correct it, if possible. Otherwise, we want to learn about why it is not fixable. The problem with configuring MeterFilters after a Meter has been registered is that such filters will not be applied to previously registered meters. This can result in a mix of metrics with all filters applied and only some filters applied, which is potentially hard to notice.

gradle/libs.versions.toml

@@ -164,6 +164,7 @@ jsr107 = { module = "org.jsr107.ri:cache-ri-impl", version.ref = "jsr107" }
 jsr305 = { module = "com.google.code.findbugs:jsr305", version.ref = "jsr305" }
 junitBom = { module = "org.junit:junit-bom", version.ref = "junit" }
 junitJupiter = { module = "org.junit.jupiter:junit-jupiter", version.ref = "junit" }
+junitLoggingExtention = "com.innoq:junit5-logging-extension:0.2.0"
 junitPlatformLauncher = { module = "org.junit.platform:junit-platform-launcher", version.ref = "junit-platform" }
 kafkaClients = { module = "org.apache.kafka:kafka-clients", version.ref = "kafka" }
 kafkaStreams = { module = "org.apache.kafka:kafka-streams", version.ref = "kafka" }

micrometer-core/build.gradle

@@ -156,6 +156,7 @@ dependencies {
     }
     // Needed for LogbackMetrics tests
     testImplementation libs.slf4jApi
+    testImplementation(libs.junitLoggingExtention)
 
     testImplementation 'org.mockito:mockito-core'
 

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

@@ -16,6 +16,8 @@
 package io.micrometer.core.instrument;
 
 import io.micrometer.common.lang.Nullable;
+import io.micrometer.common.util.internal.logging.InternalLogger;
+import io.micrometer.common.util.internal.logging.InternalLoggerFactory;
 import io.micrometer.core.annotation.Incubating;
 import io.micrometer.core.instrument.Meter.Id;
 import io.micrometer.core.instrument.config.MeterFilter;
@@ -776,6 +778,22 @@ public Config commonTags(String... tags) {
          * @return This configuration instance.
          */
         public synchronized Config meterFilter(MeterFilter filter) {
+            if (!meterMap.isEmpty()) {
+                InternalLogger logger = InternalLoggerFactory.getInstance(MeterRegistry.this.getClass());
+                String baseMessage = "A MeterFilter is being configured after a Meter has been registered to this registry. This is unexpected and should be corrected so all MeterFilters are configured before any Meters are registered. If that is not possible or you have a use case where it should be allowed, contact the Micrometer maintainers.";
+                if (logger.isDebugEnabled()) {
+                    String stackTrace = Arrays.stream(Thread.currentThread().getStackTrace())
+                        // skip getStackTrace frame and the call within this method
+                        .skip(2)
+                        .map(StackTraceElement::toString)
+                        .collect(Collectors.joining("\n\tat "));
+                    logger.debug(baseMessage + "\n" + stackTrace);
+                }
+                else {
+                    logger.warn(baseMessage
+                            + " Enable DEBUG level on this logger to see a stack trace of the call configuring this MeterFilter.");
+                }
+            }
             MeterFilter[] newFilters = new MeterFilter[filters.length + 1];
             System.arraycopy(filters, 0, newFilters, 0, filters.length);
             newFilters[filters.length] = filter;

micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryTest.java

@@ -15,6 +15,11 @@
  */
 package io.micrometer.core.instrument;
 
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import com.innoq.junit.jupiter.logging.Logging;
+import com.innoq.junit.jupiter.logging.LoggingEvents;
 import io.micrometer.core.Issue;
 import io.micrometer.core.instrument.config.MeterFilter;
 import io.micrometer.core.instrument.config.MeterFilterReply;
@@ -23,12 +28,13 @@
 import io.micrometer.core.instrument.noop.NoopCounter;
 import io.micrometer.core.instrument.noop.NoopTimer;
 import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
+import org.assertj.core.api.InstanceOfAssertFactories;
 import org.junit.jupiter.api.Test;
+import org.slf4j.LoggerFactory;
 
 import javax.annotation.Nonnull;
 
-import static org.assertj.core.api.Assertions.assertThat;
-import static org.assertj.core.api.Assertions.assertThatThrownBy;
+import static org.assertj.core.api.Assertions.*;
 
 /**
  * Tests for {@link MeterRegistry}.
@@ -221,4 +227,39 @@ void acceptPercentilesNullOrEmpty() {
         LongTaskTimer.builder("timer.percentiles.empty").publishPercentiles(new double[] {}).register(registry);
     }
 
+    @Test
+    void meterRegistrationBeforeMeterFilterConfig(@Logging LoggingEvents logEvents) {
+        registry.counter("counter");
+        registry.config().meterFilter(MeterFilter.commonTags(Tags.of("common", "tag")));
+
+        assertThat(logEvents.withLevel(Level.DEBUG)).isEmpty();
+        assertThat(logEvents.withLevel(Level.WARN)).singleElement()
+            .extracting(ILoggingEvent::getFormattedMessage, as(InstanceOfAssertFactories.STRING))
+            .contains("A MeterFilter is being configured after a Meter has been registered to this registry.")
+            .doesNotContain("MeterRegistryTest.meterRegistrationBeforeMeterFilterConfig")
+            .doesNotContain("\tat ");
+    }
+
+    @Test
+    void meterRegistrationBeforeMeterFilterConfigWithDebugLogging(@Logging LoggingEvents logEvents) {
+        Level priorLevel = ((Logger) LoggerFactory.getLogger(SimpleMeterRegistry.class)).getLevel();
+        ((Logger) LoggerFactory.getLogger(SimpleMeterRegistry.class)).setLevel(Level.DEBUG);
+        try {
+            registry.counter("counter");
+            registry.config().meterFilter(MeterFilter.commonTags(Tags.of("common", "tag")));
+
+            assertThat(logEvents.withLevel(Level.WARN)).isEmpty();
+            assertThat(logEvents.withLevel(Level.DEBUG)).singleElement()
+                .extracting(ILoggingEvent::getFormattedMessage, as(InstanceOfAssertFactories.STRING))
+                .contains("A MeterFilter is being configured after a Meter has been registered to this registry.")
+                // this test method (filter config call site) is in stack trace
+                .contains("meterRegistrationBeforeMeterFilterConfigWithDebugLogging")
+                .contains("\tat ") // stack trace output
+            ;
+        }
+        finally {
+            ((Logger) LoggerFactory.getLogger(SimpleMeterRegistry.class)).setLevel(priorLevel);
+        }
+    }
+
 }