Add tests, add docu, use subpackage.

This commit is contained in:
Stephan Schnabel 2020-08-13 18:32:41 +02:00
parent 333f3302ec
commit 059ff67d2b
Signed by: stephan.schnabel
GPG key ID: F74FE2422AA07290
10 changed files with 345 additions and 110 deletions

View file

@ -2,26 +2,66 @@
## Features ## Features
* Buildin appender: ### Preconfigured Appender
* console format
* stackdriver format (with support for error reporting)
* logback filter for log-levels per mdc
## Usage Buildin appender:
* console format
* stackdriver format (with support for error reporting)
MDC example: ### Set log level based on MDC values
Confguration:
* *enabled*: enable MDC filter (`true` is default)
* *key*: MDC key, is optional (will use name instead, see example `user` below)
* *level*: log level to use (`TRACE` is default)
* *loggers*: whitelist of logger names, matches all loggers if empty
* *values*: values for matching MDC key, matches all values if empty
Example for setting different values for different values/logger:
``` ```
logger: logger:
levels: levels:
io.kokuwa: INFO io.kokuwa: INFO
mdc: mdc:
gateway: gateway-debug:
key: gateway
level: DEBUG level: DEBUG
loggers: loggers:
- io.kokuwa - io.kokuwa
values: values:
- 6a1bae7f-eb6c-4c81-af9d-dc15396584e2 - 6a1bae7f-eb6c-4c81-af9d-dc15396584e2
- fb3318f1-2c73-48e9-acd4-a2be3c9f9256 - fb3318f1-2c73-48e9-acd4-a2be3c9f9256
gateway-trace:
key: gateway
level: TRACE
loggers:
- io.kokuwa
- io.micronaut
values:
- 257802b2-22fe-4dcc-bb99-c1db2a47861f
```
Example for omiting level and key:
```
logger:
levels:
io.kokuwa: INFO
mdc:
gateway:
loggers:
- io.kokuwa
values:
- 257802b2-22fe-4dcc-bb99-c1db2a47861f
- 0a44738b-0c3a-4798-8210-2495485f10b2
```
Example for minimal configuration:
```
logger:
levels:
io.kokuwa: INFO
mdc:
user: {}
``` ```
## Build & Release ## Build & Release
@ -47,6 +87,4 @@ mvn release:prepare release:perform release:clean -B
## Open Topics ## Open Topics
* tests
* configure mdc on refresh event * configure mdc on refresh event
* examples and documentation

11
pom.xml
View file

@ -85,6 +85,11 @@
<artifactId>micronaut-runtime</artifactId> <artifactId>micronaut-runtime</artifactId>
<scope>provided</scope> <scope>provided</scope>
</dependency> </dependency>
<dependency>
<groupId>io.micronaut.test</groupId>
<artifactId>micronaut-test-junit5</artifactId>
<scope>test</scope>
</dependency>
<!-- logging --> <!-- logging -->
<dependency> <dependency>
@ -103,6 +108,12 @@
</dependencies> </dependencies>
<build> <build>
<testResources>
<testResource>
<directory>src/test/resources</directory>
<filtering>true</filtering>
</testResource>
</testResources>
<plugins> <plugins>
<!-- add compiler processors --> <!-- add compiler processors -->

View file

@ -0,0 +1,50 @@
package io.kokuwa.micronaut.logging;
import java.util.Objects;
import java.util.Optional;
import java.util.function.Supplier;
import javax.inject.Singleton;
import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.turbo.TurboFilter;
import io.micronaut.context.annotation.BootstrapContextCompatible;
import io.micronaut.context.annotation.Requires;
import io.micronaut.core.annotation.Internal;
/**
* Utility class for Logback operations.
*
* @author Stephan Schnabel
*/
@Requires(classes = LoggerContext.class)
@BootstrapContextCompatible
@Singleton
@Internal
public class LogbackUtil {
private final LoggerContext context;
public LogbackUtil() {
this.context = (LoggerContext) LoggerFactory.getILoggerFactory();
}
public <T extends TurboFilter> Optional<T> getTurboFilter(Class<T> type, String name) {
return context.getTurboFilterList().stream()
.filter(filter -> Objects.equals(name, filter.getName()))
.filter(type::isInstance)
.map(type::cast).findAny();
}
public <T extends TurboFilter> T getTurboFilter(Class<T> type, String name, Supplier<T> defaultFilter) {
return getTurboFilter(type, name).orElseGet(() -> {
var filter = defaultFilter.get();
filter.setName(name);
filter.setContext(context);
context.addTurboFilter(filter);
return filter;
});
}
}

View file

@ -1,86 +0,0 @@
package io.kokuwa.micronaut.logging;
import java.util.Objects;
import java.util.Set;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.LoggerContext;
import io.micronaut.context.annotation.BootstrapContextCompatible;
import io.micronaut.context.annotation.Context;
import io.micronaut.context.annotation.Requires;
import io.micronaut.context.env.Environment;
import io.micronaut.context.event.ApplicationEventListener;
import io.micronaut.core.annotation.Internal;
import io.micronaut.core.type.Argument;
import io.micronaut.runtime.context.scope.refresh.RefreshEvent;
/**
* Configure mdc filter.
*
* @author Stephan Schnabel
*/
@BootstrapContextCompatible
@Context
@Requires(classes = LoggerContext.class)
@Requires(property = MDCTurboFilterConfigurer.LOGGER_MDCS_PROPERTY_PREFIX)
@Internal
public class MDCTurboFilterConfigurer implements ApplicationEventListener<RefreshEvent> {
public static final String LOGGER_MDCS_PROPERTY_PREFIX = "logger.mdc";
private static final Logger log = LoggerFactory.getLogger(MDCTurboFilterConfigurer.class);
private final LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
private final Environment environment;
public MDCTurboFilterConfigurer(Environment environment) {
this.environment = environment;
configure();
}
@Override
public void onApplicationEvent(RefreshEvent event) {
if (event.getSource().keySet().stream().anyMatch(key -> key.startsWith(LOGGER_MDCS_PROPERTY_PREFIX))) {
configure();
}
}
private void configure() {
for (var name : environment.getPropertyEntries(LOGGER_MDCS_PROPERTY_PREFIX)) {
var prefix = LOGGER_MDCS_PROPERTY_PREFIX + "." + name + ".";
var key = environment.getProperty(prefix + "key", String.class, name);
var loggers = environment.getProperty(prefix + "loggers", Argument.setOf(String.class)).orElseGet(Set::of);
var values = environment.getProperty(prefix + "values", Argument.setOf(String.class)).orElseGet(Set::of);
var level = Level.valueOf(environment.getProperty(prefix + "level", String.class, Level.TRACE.toString()));
getFilter(name, key).setLoggers(loggers).setValues(values).setLevel(level);
log.info("Configured MDC filter {} for key {} with level {}.", name, key, level);
}
}
private MDCTurboFilter getFilter(String name, String key) {
// get filter
var filterName = LOGGER_MDCS_PROPERTY_PREFIX + "." + key;
var filterOptional = context.getTurboFilterList().stream()
.filter(f -> Objects.equals(filterName, f.getName()))
.filter(MDCTurboFilter.class::isInstance)
.map(MDCTurboFilter.class::cast)
.findAny();
if (filterOptional.isPresent()) {
return filterOptional.get();
}
// add filter
var filter = new MDCTurboFilter(name, key, context);
filter.start();
context.addTurboFilter(filter);
return filter;
}
}

View file

@ -1,4 +1,4 @@
package io.kokuwa.micronaut.logging; package io.kokuwa.micronaut.logging.mdc;
import java.util.HashMap; import java.util.HashMap;
import java.util.HashSet; import java.util.HashSet;
@ -11,29 +11,21 @@ import org.slf4j.Marker;
import ch.qos.logback.classic.Level; import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.turbo.TurboFilter; import ch.qos.logback.classic.turbo.TurboFilter;
import ch.qos.logback.core.Context;
import ch.qos.logback.core.spi.FilterReply; import ch.qos.logback.core.spi.FilterReply;
/** /**
* Filter for log levels based on mdc. * Filter for log levels based on MDC.
* *
* @author Stephan Schnabel * @author Stephan Schnabel
*/ */
public class MDCTurboFilter extends TurboFilter { public class MDCTurboFilter extends TurboFilter {
private final String key;
private final Map<String, Boolean> cache = new HashMap<>(); private final Map<String, Boolean> cache = new HashMap<>();
private final Set<String> loggers = new HashSet<>(); private final Set<String> loggers = new HashSet<>();
private final Set<String> values = new HashSet<>(); private final Set<String> values = new HashSet<>();
private String key;
private Level level; private Level level;
public MDCTurboFilter(String name, String key, Context context) {
this.key = key;
this.level = Level.TRACE;
this.setName(name);
this.setContext(context);
}
public MDCTurboFilter setLoggers(Set<String> loggers) { public MDCTurboFilter setLoggers(Set<String> loggers) {
this.cache.clear(); this.cache.clear();
this.loggers.clear(); this.loggers.clear();
@ -47,6 +39,11 @@ public class MDCTurboFilter extends TurboFilter {
return this; return this;
} }
public MDCTurboFilter setKey(String key) {
this.key = key;
return this;
}
public MDCTurboFilter setLevel(Level level) { public MDCTurboFilter setLevel(Level level) {
this.level = level; this.level = level;
return this; return this;
@ -55,17 +52,18 @@ public class MDCTurboFilter extends TurboFilter {
@Override @Override
public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) { public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
if (logger == null || !isStarted() || values.isEmpty() || loggers.isEmpty()) { if (logger == null || !isStarted()) {
return FilterReply.NEUTRAL; return FilterReply.NEUTRAL;
} }
var value = MDC.get(key); var value = MDC.get(key);
if (value == null || !values.contains(value)) { if (value == null || !values.isEmpty() && !values.contains(value)) {
return FilterReply.NEUTRAL; return FilterReply.NEUTRAL;
} }
var isLoggerIncluded = !cache.computeIfAbsent(logger.getName(), k -> loggers.stream().anyMatch(k::startsWith)); var isLoggerIncluded = loggers.isEmpty()
if (isLoggerIncluded) { || cache.computeIfAbsent(logger.getName(), k -> loggers.stream().anyMatch(k::startsWith));
if (!isLoggerIncluded) {
return FilterReply.NEUTRAL; return FilterReply.NEUTRAL;
} }

View file

@ -0,0 +1,60 @@
package io.kokuwa.micronaut.logging.mdc;
import java.util.Set;
import ch.qos.logback.classic.Level;
import io.kokuwa.micronaut.logging.LogbackUtil;
import io.micronaut.context.annotation.BootstrapContextCompatible;
import io.micronaut.context.annotation.Context;
import io.micronaut.context.annotation.Requires;
import io.micronaut.context.env.Environment;
import io.micronaut.core.annotation.Internal;
import io.micronaut.core.type.Argument;
import lombok.extern.slf4j.Slf4j;
/**
* Configure MDC filter.
*
* @author Stephan Schnabel
*/
@Requires(beans = LogbackUtil.class)
@Requires(property = MDCTurboFilterConfigurer.PREFIX)
@Requires(property = MDCTurboFilterConfigurer.ENABLED, notEquals = "false")
@BootstrapContextCompatible
@Context
@Internal
@Slf4j
public class MDCTurboFilterConfigurer {
public static final String PREFIX = "logger.mdc";
public static final String ENABLED = PREFIX + ".enabled";
private final LogbackUtil logback;
private final Environment environment;
public MDCTurboFilterConfigurer(LogbackUtil logback, Environment environment) {
this.logback = logback;
this.environment = environment;
configure();
}
public void configure() {
for (var name : environment.getPropertyEntries(PREFIX)) {
var prefix = PREFIX + "." + name + ".";
var key = environment.getProperty(prefix + "key", String.class, name);
var loggers = environment.getProperty(prefix + "loggers", Argument.setOf(String.class)).orElseGet(Set::of);
var values = environment.getProperty(prefix + "values", Argument.setOf(String.class)).orElseGet(Set::of);
var level = Level.valueOf(environment.getProperty(prefix + "level", String.class, Level.TRACE.toString()));
logback.getTurboFilter(MDCTurboFilter.class, name, MDCTurboFilter::new)
.setKey(key)
.setLevel(level)
.setLoggers(loggers)
.setValues(values)
.start();
log.info("Configured MDC filter {} for key {} with level {}.", name, key, level);
}
}
}

View file

@ -0,0 +1,25 @@
package io.kokuwa.micronaut.logging;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.MethodOrderer.Alphanumeric;
import org.junit.jupiter.api.TestMethodOrder;
import org.slf4j.MDC;
import io.micronaut.test.annotation.MicronautTest;
/**
* Base for tests regarding logging.
*
* @author Stephan Schnabel
*/
@MicronautTest
@TestMethodOrder(Alphanumeric.class)
public abstract class AbstractTest {
@BeforeEach
@AfterEach
void setUpMdc() {
MDC.clear();
}
}

View file

@ -0,0 +1,111 @@
package io.kokuwa.micronaut.logging.mdc;
import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertTrue;
import org.junit.jupiter.api.DisplayName;
import org.junit.jupiter.api.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import io.kokuwa.micronaut.logging.AbstractTest;
import io.micronaut.test.annotation.MicronautTest;
/**
* Test for {@link MDCTurboFilterConfigurer}.
*
* @author Stephan Schnabel
*/
@DisplayName("mdc")
@MicronautTest(environments = "test-mdc")
public class MDCTurboFilterTest extends AbstractTest {
final Logger logA = LoggerFactory.getLogger("io.kiwios.a");
final Logger logB = LoggerFactory.getLogger("io.kiwios.b");
final Logger logC = LoggerFactory.getLogger("io.kiwios.c");
final Logger logOther = LoggerFactory.getLogger("org.example");
@DisplayName("no key set")
@Test
void noKeySet() {
assertFalse(logA.isDebugEnabled());
assertFalse(logA.isTraceEnabled());
assertFalse(logB.isDebugEnabled());
assertFalse(logB.isTraceEnabled());
assertFalse(logC.isDebugEnabled());
assertFalse(logC.isTraceEnabled());
assertFalse(logOther.isDebugEnabled());
assertFalse(logOther.isTraceEnabled());
}
@DisplayName("match nothing")
@Test
void matchNothing() {
MDC.put("key", "value-4");
assertFalse(logA.isDebugEnabled());
assertFalse(logA.isTraceEnabled());
assertFalse(logB.isDebugEnabled());
assertFalse(logB.isTraceEnabled());
assertFalse(logC.isDebugEnabled());
assertFalse(logC.isTraceEnabled());
assertFalse(logOther.isDebugEnabled());
assertFalse(logOther.isTraceEnabled());
}
@DisplayName("match root logger")
@Test
void matchRootLogger() {
MDC.put("key", "value-3");
assertTrue(logA.isDebugEnabled());
assertTrue(logA.isTraceEnabled());
assertTrue(logB.isDebugEnabled());
assertTrue(logB.isTraceEnabled());
assertTrue(logC.isDebugEnabled());
assertTrue(logC.isTraceEnabled());
assertFalse(logOther.isDebugEnabled());
assertFalse(logOther.isTraceEnabled());
}
@DisplayName("match single filter")
@Test
void matchSingleFilter() {
MDC.put("key", "value-1");
assertTrue(logA.isDebugEnabled());
assertFalse(logA.isTraceEnabled());
assertTrue(logB.isDebugEnabled());
assertFalse(logB.isTraceEnabled());
assertFalse(logC.isDebugEnabled());
assertFalse(logC.isTraceEnabled());
assertFalse(logOther.isDebugEnabled());
assertFalse(logOther.isTraceEnabled());
}
@DisplayName("match multiple filter")
@Test
void matchMultipleFilter() {
MDC.put("key", "value-2");
assertTrue(logA.isDebugEnabled());
assertFalse(logA.isTraceEnabled());
assertTrue(logB.isDebugEnabled());
assertTrue(logB.isTraceEnabled());
assertTrue(logC.isDebugEnabled());
assertTrue(logC.isTraceEnabled());
assertFalse(logOther.isDebugEnabled());
assertFalse(logOther.isTraceEnabled());
}
@DisplayName("match simple config")
@Test
void matchSimpleConfig() {
MDC.put("user", "foobar");
assertTrue(logA.isDebugEnabled());
assertTrue(logA.isTraceEnabled());
assertTrue(logB.isDebugEnabled());
assertTrue(logB.isTraceEnabled());
assertTrue(logC.isDebugEnabled());
assertTrue(logC.isTraceEnabled());
assertTrue(logOther.isDebugEnabled());
assertTrue(logOther.isTraceEnabled());
}
}

View file

@ -0,0 +1,2 @@
serviceName: ${project.artifactId}
serviceVersion: ${project.version}

View file

@ -0,0 +1,26 @@
logger:
mdc:
key1:
key: key
level: DEBUG
loggers:
- io.kiwios.a
- io.kiwios.b
values:
- value-1
- value-2
key2:
key: key
level: TRACE
loggers:
- io.kiwios.b
- io.kiwios.c
values:
- value-2
key:
level: TRACE
loggers:
- io.kiwios
values:
- value-3
user: {}