Fix native-image StatsD publishing and logback metrics

micrometer-core/src/main/java/io/micronaut/configuration/metrics/binder/logging/LogbackMeterRegistryBinderFactory.java

@@ -48,6 +48,6 @@ public class LogbackMeterRegistryBinderFactory {
     @Singleton
     @Primary
     public LogbackMetrics logbackMetrics() {
-        return new LogbackMetrics();
+        return new MicronautLogbackMetrics();
     }
 }

micrometer-core/src/main/java/io/micronaut/configuration/metrics/binder/logging/MicronautLogbackMetrics.java

@@ -0,0 +1,201 @@
+/*
+ * Copyright 2017-2019 original authors
+ *
+ * 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.micronaut.configuration.metrics.binder.logging;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.LoggerContext;
+import ch.qos.logback.classic.spi.LoggerContextListener;
+import ch.qos.logback.classic.turbo.TurboFilter;
+import ch.qos.logback.core.spi.FilterReply;
+import io.micrometer.core.instrument.FunctionCounter;
+import io.micrometer.core.instrument.MeterRegistry;
+import io.micrometer.core.instrument.Tag;
+import io.micrometer.core.instrument.binder.BaseUnits;
+import io.micrometer.core.instrument.binder.logging.LogbackMetrics;
+import org.slf4j.LoggerFactory;
+import org.slf4j.Marker;
+
+import java.util.HashMap;
+import java.util.Map;
+import java.util.concurrent.atomic.LongAdder;
+
+import static java.util.Collections.emptyList;
+
+/**
+ * Async-safe variant of {@link LogbackMetrics}.
+ */
+final class MicronautLogbackMetrics extends LogbackMetrics {
+
+    private final Iterable<Tag> tags;
+    private final LoggerContext loggerContext;
+    private final Map<MeterRegistry, MetricsTurboFilter> metricsTurboFilters = new HashMap<>();
+    private final LoggerContextListener resetListener;
+
+    MicronautLogbackMetrics() {
+        this(emptyList());
+    }
+
+    MicronautLogbackMetrics(Iterable<Tag> tags) {
+        this(tags, (LoggerContext) LoggerFactory.getILoggerFactory());
+    }
+
+    MicronautLogbackMetrics(Iterable<Tag> tags, LoggerContext loggerContext) {
+        super(tags, loggerContext);
+        this.tags = tags;
+        this.loggerContext = loggerContext;
+
+        this.resetListener = new LoggerContextListener() {
+            @Override
+            public boolean isResetResistant() {
+                return true;
+            }
+
+            @Override
+            public void onReset(LoggerContext context) {
+                synchronized (metricsTurboFilters) {
+                    for (MetricsTurboFilter metricsTurboFilter : metricsTurboFilters.values()) {
+                        loggerContext.addTurboFilter(metricsTurboFilter);
+                    }
+                }
+            }
+
+            @Override
+            public void onStart(LoggerContext context) {
+                // no-op
+            }
+
+            @Override
+            public void onStop(LoggerContext context) {
+                // no-op
+            }
+
+            @Override
+            public void onLevelChange(Logger logger, Level level) {
+                // no-op
+            }
+        };
+        loggerContext.addListener(resetListener);
+    }
+
+    @Override
+    public void bindTo(MeterRegistry registry) {
+        synchronized (metricsTurboFilters) {
+            MetricsTurboFilter existingFilter = metricsTurboFilters.get(registry);
+            if (existingFilter != null) {
+                loggerContext.getTurboFilterList().remove(existingFilter);
+                loggerContext.addTurboFilter(existingFilter);
+                return;
+            }
+            MetricsTurboFilter filter = new MetricsTurboFilter(registry, tags);
+            metricsTurboFilters.put(registry, filter);
+            loggerContext.addTurboFilter(filter);
+        }
+    }
+
+    @Override
+    public void close() {
+        synchronized (metricsTurboFilters) {
+            for (MetricsTurboFilter metricsTurboFilter : metricsTurboFilters.values()) {
+                loggerContext.getTurboFilterList().remove(metricsTurboFilter);
+            }
+            metricsTurboFilters.clear();
+        }
+        loggerContext.removeListener(resetListener);
+    }
+
+    static final class MetricsTurboFilter extends TurboFilter {
+
+        private static final String METER_NAME = "logback.events";
+        private static final String METER_DESCRIPTION = "Number of log events that were enabled by the effective log level";
+        private static final String LEVEL_TAG = "level";
+
+        private final LongAdder errorCount = new LongAdder();
+        private final LongAdder warnCount = new LongAdder();
+        private final LongAdder infoCount = new LongAdder();
+        private final LongAdder debugCount = new LongAdder();
+        private final LongAdder traceCount = new LongAdder();
+
+        MetricsTurboFilter(MeterRegistry registry, Iterable<Tag> tags) {
+            FunctionCounter.builder(METER_NAME, errorCount, LongAdder::doubleValue)
+                .tags(tags)
+                .tags(LEVEL_TAG, "error")
+                .description(METER_DESCRIPTION)
+                .baseUnit(BaseUnits.EVENTS)
+                .register(registry);
+
+            FunctionCounter.builder(METER_NAME, warnCount, LongAdder::doubleValue)
+                .tags(tags)
+                .tags(LEVEL_TAG, "warn")
+                .description(METER_DESCRIPTION)
+                .baseUnit(BaseUnits.EVENTS)
+                .register(registry);
+
+            FunctionCounter.builder(METER_NAME, infoCount, LongAdder::doubleValue)
+                .tags(tags)
+                .tags(LEVEL_TAG, "info")
+                .description(METER_DESCRIPTION)
+                .baseUnit(BaseUnits.EVENTS)
+                .register(registry);
+
+            FunctionCounter.builder(METER_NAME, debugCount, LongAdder::doubleValue)
+                .tags(tags)
+                .tags(LEVEL_TAG, "debug")
+                .description(METER_DESCRIPTION)
+                .baseUnit(BaseUnits.EVENTS)
+                .register(registry);
+
+            FunctionCounter.builder(METER_NAME, traceCount, LongAdder::doubleValue)
+                .tags(tags)
+                .tags(LEVEL_TAG, "trace")
+                .description(METER_DESCRIPTION)
+                .baseUnit(BaseUnits.EVENTS)
+                .register(registry);
+        }
+
+        @Override
+        public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
+            if (format == null || !level.isGreaterOrEqual(logger.getEffectiveLevel())) {
+                return FilterReply.NEUTRAL;
+            }
+
+            recordMetrics(level);
+            return FilterReply.NEUTRAL;
+        }
+
+        private void recordMetrics(Level level) {
+            switch (level.toInt()) {
+                case Level.ERROR_INT:
+                    errorCount.increment();
+                    break;
+                case Level.WARN_INT:
+                    warnCount.increment();
+                    break;
+                case Level.INFO_INT:
+                    infoCount.increment();
+                    break;
+                case Level.DEBUG_INT:
+                    debugCount.increment();
+                    break;
+                case Level.TRACE_INT:
+                    traceCount.increment();
+                    break;
+                default:
+                    break;
+            }
+        }
+    }
+}

micrometer-core/src/test/groovy/io/micronaut/configuration/metrics/binder/logging/LogbackMeterRegistryBinderFactorySpec.groovy

@@ -1,10 +1,20 @@
 package io.micronaut.configuration.metrics.binder.logging
 
+import io.micrometer.core.instrument.Counter
+import io.micrometer.core.instrument.Meter
 import io.micrometer.core.instrument.binder.logging.LogbackMetrics
+import io.micrometer.core.instrument.cumulative.CumulativeCounter
+import io.micrometer.core.instrument.simple.SimpleConfig
+import io.micrometer.core.instrument.simple.SimpleMeterRegistry
 import io.micronaut.context.ApplicationContext
+import org.slf4j.LoggerFactory
 import spock.lang.Specification
 import spock.lang.Unroll
 
+import java.util.concurrent.CountDownLatch
+import java.util.concurrent.TimeUnit
+import java.util.concurrent.atomic.AtomicBoolean
+
 import static io.micronaut.configuration.metrics.micrometer.MeterRegistryFactory.MICRONAUT_METRICS_BINDERS
 import static io.micronaut.configuration.metrics.micrometer.MeterRegistryFactory.MICRONAUT_METRICS_ENABLED
 
@@ -18,6 +28,25 @@ class LogbackMeterRegistryBinderFactorySpec extends Specification {
         binder.logbackMetrics()
     }
 
+    void "logback metrics do not recurse when counter emits an async log event"() {
+        given:
+        def logger = LoggerFactory.getLogger("logback-binder-recursion-test")
+        LogbackMetrics binder = new LogbackMeterRegistryBinderFactory().logbackMetrics()
+        def registry = new AsyncLoggingCounterRegistry()
+        binder.bindTo(registry)
+
+        when:
+        logger.info("primary event")
+
+        then:
+        !registry.awaitAsyncLog()
+        registry.get("logback.events").tags("level", "info").functionCounter().count() == 1d
+
+        cleanup:
+        binder.close()
+        registry.close()
+    }
+
     void "test getting the beans"() {
         when:
         ApplicationContext context = ApplicationContext.run()
@@ -49,4 +78,88 @@ class LogbackMeterRegistryBinderFactorySpec extends Specification {
         MICRONAUT_METRICS_BINDERS + ".logback.enabled" | true
         MICRONAUT_METRICS_BINDERS + ".logback.enabled" | false
     }
+
+    void "logback metrics close removes filters and reset listener"() {
+        given:
+        def loggerContext = newLoggerContext()
+        def binder = new MicronautLogbackMetrics([], loggerContext)
+        def registry = new SimpleMeterRegistry()
+
+        when:
+        binder.bindTo(registry)
+
+        then:
+        binder.@metricsTurboFilters.size() == 1
+        loggerContext.getTurboFilterList().size() == 1
+        loggerContext.getCopyOfListenerList().contains(binder.@resetListener)
+
+        when:
+        binder.close()
+        loggerContext.reset()
+
+        then:
+        binder.@metricsTurboFilters.isEmpty()
+        loggerContext.getTurboFilterList().isEmpty()
+        !loggerContext.getCopyOfListenerList().contains(binder.@resetListener)
+
+        cleanup:
+        registry.close()
+        loggerContext.stop()
+    }
+
+    void "logback metrics bind same registry once"() {
+        given:
+        def loggerContext = newLoggerContext()
+        def logger = loggerContext.getLogger("logback-binder-repeat-bind-test")
+        def binder = new MicronautLogbackMetrics([], loggerContext)
+        def registry = new SimpleMeterRegistry()
+
+        when:
+        binder.bindTo(registry)
+        binder.bindTo(registry)
+        logger.info("primary event")
+
+        then:
+        binder.@metricsTurboFilters.size() == 1
+        loggerContext.getTurboFilterList().findAll { it instanceof MicronautLogbackMetrics.MetricsTurboFilter }.size() == 1
+        registry.get("logback.events").tags("level", "info").functionCounter().count() == 1d
+
+        cleanup:
+        binder.close()
+        registry.close()
+        loggerContext.stop()
+    }
+
+    private static newLoggerContext() {
+        LoggerFactory.getILoggerFactory().class.getDeclaredConstructor().newInstance()
+    }
+
+    private static final class AsyncLoggingCounterRegistry extends SimpleMeterRegistry {
+        private final AtomicBoolean asyncLogged = new AtomicBoolean()
+        private final CountDownLatch asyncLogLatch = new CountDownLatch(1)
+
+        AsyncLoggingCounterRegistry() {
+            super(SimpleConfig.DEFAULT, io.micrometer.core.instrument.Clock.SYSTEM)
+        }
+
+        @Override
+        protected Counter newCounter(Meter.Id id) {
+            return new CumulativeCounter(id) {
+                @Override
+                void increment(double amount) {
+                    super.increment(amount)
+                    if (asyncLogged.compareAndSet(false, true)) {
+                        Thread.start {
+                            LoggerFactory.getLogger("logback-binder-recursion-test").info("counter emitted event")
+                            asyncLogLatch.countDown()
+                        }
+                    }
+                }
+            }
+        }
+
+        boolean awaitAsyncLog() {
+            asyncLogLatch.await(5, TimeUnit.SECONDS)
+        }
+    }
 }

micrometer-registry-statsd/src/main/java/io/micronaut/configuration/metrics/micrometer/statsd/NativeImageStatsdCondition.java

@@ -0,0 +1,40 @@
+/*
+ * Copyright 2017-2026 original authors
+ *
+ * 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.micronaut.configuration.metrics.micrometer.statsd;
+
+import io.micronaut.context.condition.Condition;
+import io.micronaut.context.condition.ConditionContext;
+
+/**
+ * Enables the native-image StatsD workaround only for UDP-based native executables.
+ */
+final class NativeImageStatsdCondition implements Condition {
+
+    static final String NATIVE_IMAGE_CODE_PROPERTY = "org.graalvm.nativeimage.imagecode";
+    private static final String RUNTIME = "runtime";
+    private static final String UDP = "UDP";
+
+    @Override
+    public boolean matches(ConditionContext context) {
+        String imageCode = System.getProperty(NATIVE_IMAGE_CODE_PROPERTY);
+        if (!RUNTIME.equalsIgnoreCase(imageCode)) {
+            return false;
+        }
+        String protocol = context.getProperty(StatsdMeterRegistryFactory.STATSD_CONFIG + ".protocol", String.class)
+            .orElse(UDP);
+        return UDP.equalsIgnoreCase(protocol);
+    }
+}