diff --git a/README.md b/README.md index 30645e4..378e985 100644 --- a/README.md +++ b/README.md @@ -64,6 +64,44 @@ logger: user: {} ``` +### Set log level based on HTTP request header + +Confguration: + * *enabled*: enable HTTP request filter (`true` is default) + * *order*: order for [Ordered](https://github.com/micronaut-projects/micronaut-core/blob/master/core/src/main/java/io/micronaut/core/order/Ordered.java) (highest is default) + * *pattern*: filter pattern (`/**` is default) + * *header*: name of HTTP header (`x-log-level` is default) + +Example with default configuration: +``` +logger: + request: + header: + enabled: true + order: -2147483648 + pattern: /** + header: x-log-level +``` + +### Add princial for request to MDC + +Confguration: + * *enabled*: enable HTTP principal filter (`true` is default) + * *order*: order for [Ordered](https://github.com/micronaut-projects/micronaut-core/blob/master/core/src/main/java/io/micronaut/core/order/Ordered.java) ([ServerFilterPhase.SECURITY.after()](https://github.com/micronaut-projects/micronaut-core/blob/v2.0.1/http/src/main/java/io/micronaut/http/filter/ServerFilterPhase.java#L54) is default) + * *pattern*: filter pattern (`/**` is default) + * *key*: name of MDC header (`principal` is default) + +Example with default configuration: +``` +logger: + request: + principal: + enabled: true + order: 39250 + pattern: /** + key: principal +``` + ## Build & Release ### Dependency updates @@ -88,3 +126,6 @@ mvn release:prepare release:perform release:clean -B ## Open Topics * configure mdc on refresh event + * add stackdriver per configuration + * add fluent per configuration + * read **serviceName** and **serviceVersion** from yaml diff --git a/pom.xml b/pom.xml index a053834..84db594 100644 --- a/pom.xml +++ b/pom.xml @@ -90,6 +90,21 @@ micronaut-test-junit5 test + + io.micronaut + micronaut-http-client + test + + + io.micronaut + micronaut-http-server-netty + test + + + io.micronaut.security + micronaut-security-jwt + test + diff --git a/src/main/java/io/kokuwa/micronaut/logging/request/HeaderLoggingHttpFilter.java b/src/main/java/io/kokuwa/micronaut/logging/request/HeaderLoggingHttpFilter.java new file mode 100644 index 0000000..bed5fae --- /dev/null +++ b/src/main/java/io/kokuwa/micronaut/logging/request/HeaderLoggingHttpFilter.java @@ -0,0 +1,75 @@ +package io.kokuwa.micronaut.logging.request; + +import java.util.Optional; + +import javax.annotation.PostConstruct; +import javax.annotation.PreDestroy; + +import org.reactivestreams.Publisher; +import org.slf4j.MDC; + +import ch.qos.logback.classic.turbo.TurboFilter; +import io.kokuwa.micronaut.logging.LogbackUtil; +import io.micronaut.context.annotation.Requires; +import io.micronaut.context.annotation.Value; +import io.micronaut.http.HttpRequest; +import io.micronaut.http.MutableHttpResponse; +import io.micronaut.http.annotation.Filter; +import io.micronaut.http.filter.HttpServerFilter; +import io.micronaut.http.filter.ServerFilterChain; +import io.micronaut.http.filter.ServerFilterPhase; +import io.micronaut.runtime.server.EmbeddedServer; + +/** + * Http request logging filter. + * + * @author Stephan Schnabel + */ +@Requires(beans = EmbeddedServer.class) +@Requires(property = HeaderLoggingHttpFilter.ENABLED, notEquals = "false") +@Filter("${" + HeaderLoggingHttpFilter.PREFIX + ".pattern:" + HeaderLoggingHttpFilter.DEFAULT_PATTERN + ":/**}") +public class HeaderLoggingHttpFilter implements HttpServerFilter { + + public static final String PREFIX = "logger.request.header"; + public static final String ENABLED = PREFIX + ".enabled"; + public static final String MDC_FILTER = PREFIX + ".filter"; + public static final String MDC_KEY = "level"; + + public static final String DEFAULT_HEADER = "x-log-level"; + public static final String DEFAULT_PATTERN = "/**"; + public static final int DEFAULT_ORDER = ServerFilterPhase.FIRST.before(); + + private final LogbackUtil logback; + private final String header; + private final int order; + + public HeaderLoggingHttpFilter( + LogbackUtil logback, + @Value("${" + PREFIX + ".header:" + DEFAULT_HEADER + "}") String header, + @Value("${" + PREFIX + ".order}") Optional order) { + this.logback = logback; + this.header = header; + this.order = order.orElse(DEFAULT_ORDER); + } + + @PostConstruct + void startTurbofilter() { + logback.getTurboFilter(HeaderLoggingTurboFilter.class, MDC_FILTER, HeaderLoggingTurboFilter::new).start(); + } + + @PreDestroy + void stopTurbofilter() { + logback.getTurboFilter(HeaderLoggingTurboFilter.class, MDC_FILTER).ifPresent(TurboFilter::stop); + } + + @Override + public int getOrder() { + return order; + } + + @Override + public Publisher> doFilter(HttpRequest request, ServerFilterChain chain) { + request.getHeaders().getFirst(header).ifPresent(level -> MDC.put(MDC_KEY, level)); + return chain.proceed(request); + } +} diff --git a/src/main/java/io/kokuwa/micronaut/logging/request/HeaderLoggingTurboFilter.java b/src/main/java/io/kokuwa/micronaut/logging/request/HeaderLoggingTurboFilter.java new file mode 100644 index 0000000..17e42ea --- /dev/null +++ b/src/main/java/io/kokuwa/micronaut/logging/request/HeaderLoggingTurboFilter.java @@ -0,0 +1,32 @@ +package io.kokuwa.micronaut.logging.request; + +import org.slf4j.MDC; +import org.slf4j.Marker; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.turbo.TurboFilter; +import ch.qos.logback.core.spi.FilterReply; + +/** + * Filter for log levels based on MDC. + * + * @author Stephan Schnabel + */ +public class HeaderLoggingTurboFilter extends TurboFilter { + + @Override + public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) { + + if (!isStarted()) { + return FilterReply.NEUTRAL; + } + + var value = MDC.get(HeaderLoggingHttpFilter.MDC_KEY); + if (value == null) { + return FilterReply.NEUTRAL; + } + + return level.isGreaterOrEqual(Level.valueOf(value)) ? FilterReply.ACCEPT : FilterReply.NEUTRAL; + } +} diff --git a/src/main/java/io/kokuwa/micronaut/logging/request/PrincipalHttpFilter.java b/src/main/java/io/kokuwa/micronaut/logging/request/PrincipalHttpFilter.java new file mode 100644 index 0000000..80848e2 --- /dev/null +++ b/src/main/java/io/kokuwa/micronaut/logging/request/PrincipalHttpFilter.java @@ -0,0 +1,55 @@ +package io.kokuwa.micronaut.logging.request; + +import java.util.Optional; + +import org.reactivestreams.Publisher; +import org.slf4j.MDC; + +import io.micronaut.context.annotation.Requires; +import io.micronaut.context.annotation.Value; +import io.micronaut.http.HttpRequest; +import io.micronaut.http.MutableHttpResponse; +import io.micronaut.http.annotation.Filter; +import io.micronaut.http.filter.HttpServerFilter; +import io.micronaut.http.filter.ServerFilterChain; +import io.micronaut.http.filter.ServerFilterPhase; +import io.micronaut.runtime.server.EmbeddedServer; + +/** + * Http request principal filter. + * + * @author Stephan Schnabel + */ +@Requires(beans = EmbeddedServer.class) +@Requires(property = PrincipalHttpFilter.ENABLED, notEquals = "false") +@Filter("${" + PrincipalHttpFilter.PREFIX + ".pattern:" + PrincipalHttpFilter.DEFAULT_PATTERN + ":/**}") +public class PrincipalHttpFilter implements HttpServerFilter { + + public static final String PREFIX = "logger.request.principal"; + public static final String ENABLED = PREFIX + ".enabled"; + + public static final String DEFAULT_KEY = "principal"; + public static final String DEFAULT_PATTERN = "/**"; + public static final int DEFAULT_ORDER = ServerFilterPhase.SECURITY.after(); + + private final String key; + private final int order; + + public PrincipalHttpFilter( + @Value("${" + PREFIX + ".key:" + DEFAULT_KEY + "}") String key, + @Value("${" + PREFIX + ".order}") Optional order) { + this.key = key; + this.order = order.orElse(DEFAULT_ORDER); + } + + @Override + public int getOrder() { + return order; + } + + @Override + public Publisher> doFilter(HttpRequest request, ServerFilterChain chain) { + request.getUserPrincipal().ifPresent(princial -> MDC.put(key, princial.getName())); + return chain.proceed(request); + } +} diff --git a/src/test/java/io/kokuwa/micronaut/logging/request/CompositeTest.java b/src/test/java/io/kokuwa/micronaut/logging/request/CompositeTest.java new file mode 100644 index 0000000..26e766d --- /dev/null +++ b/src/test/java/io/kokuwa/micronaut/logging/request/CompositeTest.java @@ -0,0 +1,41 @@ +package io.kokuwa.micronaut.logging.request; + +import javax.inject.Inject; + +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Test; + +import ch.qos.logback.classic.Level; +import io.kokuwa.micronaut.logging.AbstractTest; +import io.micronaut.test.annotation.MicronautTest; + +/** + * Test for MDC and request filter combined. + * + * @author Stephan Schnabel + */ +@DisplayName("request-composite") +@MicronautTest(environments = "test-composite") +public class CompositeTest extends AbstractTest { + + @Inject + TestClient client; + + @DisplayName("default level") + @Test + void defaultLogging() { + client.assertLevel(Level.INFO, client.token("somebody"), null); + } + + @DisplayName("level set by mdc") + @Test + void headerFromMdc() { + client.assertLevel(Level.DEBUG, client.token("horst"), null); + } + + @DisplayName("level set by header (overriding mdc)") + @Test + void headerFromHeader() { + client.assertLevel(Level.TRACE, client.token("horst"), "TRACE"); + } +} diff --git a/src/test/java/io/kokuwa/micronaut/logging/request/RequestHeaderTest.java b/src/test/java/io/kokuwa/micronaut/logging/request/RequestHeaderTest.java new file mode 100644 index 0000000..b939b95 --- /dev/null +++ b/src/test/java/io/kokuwa/micronaut/logging/request/RequestHeaderTest.java @@ -0,0 +1,57 @@ +package io.kokuwa.micronaut.logging.request; + +import javax.inject.Inject; + +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Test; + +import ch.qos.logback.classic.Level; +import io.kokuwa.micronaut.logging.AbstractTest; + +/** + * Test for {@link HeaderLoggingHttpFilter}. + * + * @author Stephan Schnabel + */ +@DisplayName("request-header") +public class RequestHeaderTest extends AbstractTest { + + @Inject + TestClient client; + + @DisplayName("header missing") + @Test + void headerMissing() { + client.assertLevel(Level.INFO, null, null); + } + + @DisplayName("header invalid, use DEBUG as default from logback") + @Test + void headerInvalid() { + client.assertLevel(Level.DEBUG, null, "TRCE"); + } + + @DisplayName("level trace (below default)") + @Test + void headerLevelTrace() { + client.assertLevel(Level.TRACE, null, "TRACE"); + } + + @DisplayName("level debug (below default)") + @Test + void headerLevelDebug() { + client.assertLevel(Level.DEBUG, null, "DEBUG"); + } + + @DisplayName("level info (is default)") + @Test + void headerLevelInfo() { + client.assertLevel(Level.INFO, null, "INFO"); + } + + @DisplayName("level warn (above default)") + @Test + void headerLevelWarn() { + client.assertLevel(Level.INFO, null, "WARN"); + } +} diff --git a/src/test/java/io/kokuwa/micronaut/logging/request/RequestPrincipalTest.java b/src/test/java/io/kokuwa/micronaut/logging/request/RequestPrincipalTest.java new file mode 100644 index 0000000..f8f1fcc --- /dev/null +++ b/src/test/java/io/kokuwa/micronaut/logging/request/RequestPrincipalTest.java @@ -0,0 +1,44 @@ +package io.kokuwa.micronaut.logging.request; + +import static org.junit.jupiter.api.Assertions.assertEquals; + +import javax.inject.Inject; + +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Test; + +import io.kokuwa.micronaut.logging.AbstractTest; + +/** + * Test for {@link PrincipalHttpFilter}. + * + * @author Stephan Schnabel + */ +@DisplayName("request-principal") +public class RequestPrincipalTest extends AbstractTest { + + @Inject + TestClient client; + + @DisplayName("token missing") + @Test + void tokenMissing() { + assertPrincipal(null, null); + } + + @DisplayName("token invalid") + @Test + void tokenInvalid() { + assertPrincipal(null, "meh"); + } + + @DisplayName("token valid") + @Test + void tokenValid() { + assertPrincipal("meh", client.token("meh")); + } + + private void assertPrincipal(String expectedPrincipal, String actualTokenValue) { + assertEquals(expectedPrincipal, client.get(actualTokenValue, null).getPrincipal()); + } +} diff --git a/src/test/java/io/kokuwa/micronaut/logging/request/TestClient.java b/src/test/java/io/kokuwa/micronaut/logging/request/TestClient.java new file mode 100644 index 0000000..b44495a --- /dev/null +++ b/src/test/java/io/kokuwa/micronaut/logging/request/TestClient.java @@ -0,0 +1,64 @@ +package io.kokuwa.micronaut.logging.request; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.junit.jupiter.api.Assertions.fail; + +import javax.inject.Inject; +import javax.inject.Singleton; + +import com.nimbusds.jose.JOSEException; +import com.nimbusds.jwt.JWTClaimsSet; + +import ch.qos.logback.classic.Level; +import io.kokuwa.micronaut.logging.request.TestController.TestResponse; +import io.micronaut.http.HttpRequest; +import io.micronaut.http.HttpStatus; +import io.micronaut.http.client.HttpClient; +import io.micronaut.http.client.annotation.Client; +import io.micronaut.security.token.jwt.signature.SignatureGeneratorConfiguration; + +/** + * Contoller for testing {@link HeaderLoggingHttpFilter} and {@link PrincipalHttpFilter}. + * + * @author Stephan Schnabel + */ +@Singleton +public class TestClient { + + @Inject + @Client("/") + HttpClient client; + @Inject + SignatureGeneratorConfiguration signature; + + String token(String subject) { + try { + return signature.sign(new JWTClaimsSet.Builder().subject(subject).build()).serialize(); + } catch (JOSEException e) { + fail("failed to create token"); + return null; + } + } + + TestResponse get(String token, String header) { + + var request = HttpRequest.GET("/"); + if (token != null) { + request.bearerAuth(token); + } + if (header != null) { + request.getHeaders().add(HeaderLoggingHttpFilter.DEFAULT_HEADER, header); + } + + var response = client.toBlocking().exchange(request, TestResponse.class); + assertEquals(HttpStatus.OK, response.getStatus(), "status"); + assertTrue(response.getBody().isPresent(), "body"); + + return response.body(); + } + + void assertLevel(Level expectedLevel, String actualTokenValue, String actualHeaderValue) { + assertEquals(expectedLevel.toString(), get(actualTokenValue, actualHeaderValue).getLevel()); + } +} diff --git a/src/test/java/io/kokuwa/micronaut/logging/request/TestController.java b/src/test/java/io/kokuwa/micronaut/logging/request/TestController.java new file mode 100644 index 0000000..3d3d6c9 --- /dev/null +++ b/src/test/java/io/kokuwa/micronaut/logging/request/TestController.java @@ -0,0 +1,52 @@ +package io.kokuwa.micronaut.logging.request; + +import org.slf4j.MDC; + +import ch.qos.logback.classic.Level; +import io.micronaut.http.annotation.Controller; +import io.micronaut.http.annotation.Get; +import io.micronaut.security.annotation.Secured; +import io.micronaut.security.rules.SecurityRule; +import lombok.AllArgsConstructor; +import lombok.Data; +import lombok.NoArgsConstructor; +import lombok.extern.slf4j.Slf4j; + +/** + * Controller for testing {@link HeaderLoggingHttpFilter} and {@link PrincipalHttpFilter}. + * + * @author Stephan Schnabel + */ +@Secured({ SecurityRule.IS_ANONYMOUS, SecurityRule.IS_AUTHENTICATED }) +@Controller +@Slf4j +public class TestController { + + @Get("/") + TestResponse run() { + + var principal = MDC.get(PrincipalHttpFilter.DEFAULT_KEY); + var level = Level.OFF; + if (log.isTraceEnabled()) { + level = Level.TRACE; + } else if (log.isDebugEnabled()) { + level = Level.DEBUG; + } else if (log.isInfoEnabled()) { + level = Level.INFO; + } else if (log.isWarnEnabled()) { + level = Level.WARN; + } else if (log.isErrorEnabled()) { + level = Level.ERROR; + } + + return new TestResponse(level.toString(), principal); + } + + @Data + @NoArgsConstructor + @AllArgsConstructor + public static class TestResponse { + private String level; + private String principal; + } +} diff --git a/src/test/resources/application-test-composite.yaml b/src/test/resources/application-test-composite.yaml new file mode 100644 index 0000000..7ba34db --- /dev/null +++ b/src/test/resources/application-test-composite.yaml @@ -0,0 +1,8 @@ +logger: + mdc: + principal: + level: DEBUG + loggers: + - io.kokuwa + values: + - horst diff --git a/src/test/resources/application-test.yaml b/src/test/resources/application-test.yaml new file mode 100644 index 0000000..42aa67e --- /dev/null +++ b/src/test/resources/application-test.yaml @@ -0,0 +1,16 @@ +micronaut: + security: + token: + jwt: + signatures: + secret: + generator: + secret: pleaseChangeThisSecretForANewOne + jws-algorithm: HS256 + http: + client: + logger-name: io.kokuwa.Test + +logger: + levels: + io.kokuwa.Test: TRACE