From d1e60fda409e5f1056b1a6c43cb4aa1a4a73989e Mon Sep 17 00:00:00 2001 From: Tommy Ludwig <8924140+shakuzen@users.noreply.github.com> Date: Tue, 2 Apr 2024 17:15:47 +0900 Subject: [PATCH] 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. --- config/checkstyle/checkstyle-suppressions.xml | 1 + gradle/libs.versions.toml | 1 + micrometer-core/build.gradle | 1 + .../core/instrument/MeterRegistry.java | 18 +++++ .../instrument/MeterRegistryLoggingTest.java | 75 +++++++++++++++++++ .../core/instrument/MeterRegistryTest.java | 1 + 6 files changed, 97 insertions(+) create mode 100644 micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryLoggingTest.java diff --git a/config/checkstyle/checkstyle-suppressions.xml b/config/checkstyle/checkstyle-suppressions.xml index afa2ac6d9b..547d5acf91 100644 --- a/config/checkstyle/checkstyle-suppressions.xml +++ b/config/checkstyle/checkstyle-suppressions.xml @@ -19,6 +19,7 @@ + diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index 1e56079c88..2aae465d9f 100644 --- a/gradle/libs.versions.toml +++ b/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" } diff --git a/micrometer-core/build.gradle b/micrometer-core/build.gradle index fa70508afd..a1f8fa480f 100644 --- a/micrometer-core/build.gradle +++ b/micrometer-core/build.gradle @@ -156,6 +156,7 @@ dependencies { } // Needed for LogbackMetrics tests testImplementation libs.slf4jApi + testImplementation(libs.junitLoggingExtention) testImplementation 'org.mockito:mockito-core' diff --git a/micrometer-core/src/main/java/io/micrometer/core/instrument/MeterRegistry.java b/micrometer-core/src/main/java/io/micrometer/core/instrument/MeterRegistry.java index bacdd0dd56..8b710cdd1e 100644 --- a/micrometer-core/src/main/java/io/micrometer/core/instrument/MeterRegistry.java +++ b/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; diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryLoggingTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryLoggingTest.java new file mode 100644 index 0000000000..226eacec75 --- /dev/null +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryLoggingTest.java @@ -0,0 +1,75 @@ +/* + * Copyright 2024 VMware, Inc. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +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.instrument.config.MeterFilter; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; +import org.assertj.core.api.InstanceOfAssertFactories; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; + +import static org.assertj.core.api.Assertions.as; +import static org.assertj.core.api.Assertions.assertThat; + +/** + * Tests for expected logging from {@link MeterRegistry}. + */ +@Logging +class MeterRegistryLoggingTest { + + MeterRegistry registry = new SimpleMeterRegistry(); + + @Test + void meterRegistrationBeforeMeterFilterConfig(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("meterRegistrationBeforeMeterFilterConfig") + .doesNotContain("\tat "); + } + + @Test + void meterRegistrationBeforeMeterFilterConfigWithDebugLogging(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); + } + } + +} diff --git a/micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryTest.java b/micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryTest.java index 58abd569e1..041614d56a 100644 --- a/micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryTest.java +++ b/micrometer-core/src/test/java/io/micrometer/core/instrument/MeterRegistryTest.java @@ -30,6 +30,7 @@ import static org.assertj.core.api.Assertions.assertThat; import static org.assertj.core.api.Assertions.assertThatThrownBy; + /** * Tests for {@link MeterRegistry}. *