Skip to content

Commit

Permalink
Rebind log4j2 metrics if configuration is changed (#5810)
Browse files Browse the repository at this point in the history 
This change ensures Log4j2 metrics are recorded when the configuration is updated (reconfigure'd). This also will log a warning and do nothing when binding an instance of Log4j2Metrics to the same registry multiple times.

Fixes gh-5756

---------

Signed-off-by: Patrik Ivarsson <[email protected]>
Co-authored-by: Tommy Ludwig <[email protected]>
  • Loading branch information
@pativa @shakuzen
pativa and shakuzen authored Feb 6, 2025
1 parent ab0409a commit 04f6d8c
Show file tree
Hide file tree
Showing 2 changed files with 134 additions and 19 deletions.
73 changes: 54 additions & 19 deletions ...ometer-core/src/main/java/io/micrometer/core/instrument/binder/logging/Log4j2Metrics.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@

import io.micrometer.common.lang.NonNullApi;
import io.micrometer.common.lang.NonNullFields;
import io.micrometer.common.util.internal.logging.InternalLogger;
import io.micrometer.common.util.internal.logging.InternalLoggerFactory;
import io.micrometer.core.instrument.Counter;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tag;
Expand All @@ -31,9 +33,12 @@
import org.apache.logging.log4j.core.filter.AbstractFilter;
import org.apache.logging.log4j.core.filter.CompositeFilter;

import java.util.*;
import java.beans.PropertyChangeListener;
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.CopyOnWriteArrayList;

import static java.util.Collections.emptyList;

Expand All @@ -57,12 +62,16 @@ public class Log4j2Metrics implements MeterBinder, AutoCloseable {

private static final String METER_DESCRIPTION = "Number of log events";

private static final InternalLogger logger = InternalLoggerFactory.getInstance(Log4j2Metrics.class);

private final Iterable<Tag> tags;

private final LoggerContext loggerContext;

private final ConcurrentMap<MeterRegistry, MetricsFilter> metricsFilters = new ConcurrentHashMap<>();

private final List<PropertyChangeListener> changeListeners = new CopyOnWriteArrayList<>();

public Log4j2Metrics() {
this(emptyList());
}
Expand All @@ -78,13 +87,35 @@ public Log4j2Metrics(Iterable<Tag> tags, LoggerContext loggerContext) {

@Override
public void bindTo(MeterRegistry registry) {
if (metricsFilters.containsKey(registry)) {
logger.warn("This Log4j2Metrics instance has already been bound to the registry {}", registry);
return;
}
Configuration configuration = loggerContext.getConfiguration();
registerMetricsFilter(configuration, registry);
loggerContext.updateLoggers(configuration);

PropertyChangeListener changeListener = listener -> {
if (listener.getNewValue() instanceof Configuration && listener.getOldValue() != listener.getNewValue()) {
Configuration newConfiguration = (Configuration) listener.getNewValue();
registerMetricsFilter(newConfiguration, registry);
loggerContext.updateLoggers(newConfiguration);
if (listener.getOldValue() instanceof Configuration) {
removeMetricsFilter((Configuration) listener.getOldValue());
}
}
};

changeListeners.add(changeListener);
loggerContext.addPropertyChangeListener(changeListener);
}

private void registerMetricsFilter(Configuration configuration, MeterRegistry registry) {
LoggerConfig rootLoggerConfig = configuration.getRootLogger();
MetricsFilter metricsFilter = getOrCreateMetricsFilterAndStart(registry);
rootLoggerConfig.addFilter(metricsFilter);

loggerContext.getConfiguration()
.getLoggers()
configuration.getLoggers()
.values()
.stream()
.filter(loggerConfig -> !loggerConfig.isAdditive())
Expand All @@ -105,8 +136,6 @@ public void bindTo(MeterRegistry registry) {

loggerConfig.addFilter(metricsFilter);
});

loggerContext.updateLoggers(configuration);
}

private MetricsFilter getOrCreateMetricsFilterAndStart(MeterRegistry registry) {
Expand All @@ -119,28 +148,34 @@ private MetricsFilter getOrCreateMetricsFilterAndStart(MeterRegistry registry) {

@Override
public void close() {
changeListeners.forEach(loggerContext::removePropertyChangeListener);
changeListeners.clear();

if (!metricsFilters.isEmpty()) {
Configuration configuration = loggerContext.getConfiguration();
LoggerConfig rootLoggerConfig = configuration.getRootLogger();
metricsFilters.values().forEach(rootLoggerConfig::removeFilter);

loggerContext.getConfiguration()
.getLoggers()
.values()
.stream()
.filter(loggerConfig -> !loggerConfig.isAdditive())
.forEach(loggerConfig -> {
if (loggerConfig != rootLoggerConfig) {
metricsFilters.values().forEach(loggerConfig::removeFilter);
}
});

removeMetricsFilter(configuration);
loggerContext.updateLoggers(configuration);

metricsFilters.values().forEach(MetricsFilter::stop);
metricsFilters.clear();
}
}

private void removeMetricsFilter(Configuration configuration) {
LoggerConfig rootLoggerConfig = configuration.getRootLogger();
metricsFilters.values().forEach(rootLoggerConfig::removeFilter);

configuration.getLoggers()
.values()
.stream()
.filter(loggerConfig -> !loggerConfig.isAdditive())
.forEach(loggerConfig -> {
if (loggerConfig != rootLoggerConfig) {
metricsFilters.values().forEach(loggerConfig::removeFilter);
}
});
}

@NonNullApi
@NonNullFields
static class MetricsFilter extends AbstractFilter {
Expand Down
80 changes: 80 additions & 0 deletions ...er-core/src/test/java/io/micrometer/core/instrument/binder/logging/Log4j2MetricsTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -288,4 +288,84 @@ void multipleRegistriesCanBeBoundWithNonRootLoggerContext() {
assertThat(registry2.get("log4j2.events").tags("level", "info").counter().count()).isEqualTo(2);
}

@Issue("#5756")
@Test
void rebindsMetricsWhenConfigurationIsReloaded() {
LoggerContext context = new LoggerContext("test");
Logger logger = context.getLogger("com.test");
Configuration oldConfiguration = context.getConfiguration();

try (Log4j2Metrics metrics = new Log4j2Metrics(emptyList(), context)) {
metrics.bindTo(registry);

logger.error("first");
assertThat(registry.get("log4j2.events").tags("level", "error").counter().count()).isEqualTo(1);

// Should have added filter to configuration
Filter oldFilter = oldConfiguration.getRootLogger().getFilter();
assertThat(oldFilter).isInstanceOf(Log4j2Metrics.MetricsFilter.class);

// This will reload the configuration to default
context.reconfigure();

Configuration newConfiguration = context.getConfiguration();

// For this event to be counted, the metrics must be rebound
logger.error("second");
assertThat(registry.get("log4j2.events").tags("level", "error").counter().count()).isEqualTo(2);

// Should have removed filter from old configuration, adding it to the new
assertThat(oldConfiguration.getRootLogger().getFilter()).isNull();
Filter newFilter = newConfiguration.getRootLogger().getFilter();
assertThat(newFilter).isInstanceOf(Log4j2Metrics.MetricsFilter.class);
}
}

@Test
void shouldNotRebindMetricsIfBinderIsClosed() {
LoggerContext context = new LoggerContext("test");
Logger logger = context.getLogger("com.test");

try (Log4j2Metrics metrics = new Log4j2Metrics(emptyList(), context)) {
metrics.bindTo(registry);
logger.error("first");
assertThat(registry.get("log4j2.events").tags("level", "error").counter().count()).isEqualTo(1);
}

// This will reload the configuration to default
context.reconfigure();

// This event should not be counted as the metrics binder is already closed
logger.error("second");

assertThat(registry.get("log4j2.events").tags("level", "error").counter().count()).isEqualTo(1);
}

@Test
void bindingTwiceToSameRegistry_doesNotDoubleCount() {
LoggerContext context = new LoggerContext("test");
Logger logger = context.getLogger("com.test");

try (Log4j2Metrics metrics = new Log4j2Metrics(emptyList(), context)) {
// binding twice
metrics.bindTo(registry);
metrics.bindTo(registry);

logger.error("first");

assertThat(registry.get("log4j2.events").tags("level", "error").counter().count()).isEqualTo(1);

context.reconfigure();

logger.error("second");
assertThat(registry.get("log4j2.events").tags("level", "error").counter().count()).isEqualTo(2);
}

// no additional events should be counted now
context.reconfigure();

logger.error("third");
assertThat(registry.get("log4j2.events").tags("level", "error").counter().count()).isEqualTo(2);
}

}

0 comments on commit 04f6d8c

Please sign in to comment.