Add request filter.

This commit is contained in:
Stephan Schnabel 2020-08-20 19:40:48 +02:00
parent c4b1d1d2f6
commit c3d38e2d11
Signed by: stephan.schnabel
GPG key ID: F74FE2422AA07290
12 changed files with 500 additions and 0 deletions

View file

@ -64,6 +64,44 @@ logger:
user: {} 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 ## Build & Release
### Dependency updates ### Dependency updates
@ -88,3 +126,6 @@ mvn release:prepare release:perform release:clean -B
## Open Topics ## Open Topics
* configure mdc on refresh event * configure mdc on refresh event
* add stackdriver per configuration
* add fluent per configuration
* read **serviceName** and **serviceVersion** from yaml

15
pom.xml
View file

@ -90,6 +90,21 @@
<artifactId>micronaut-test-junit5</artifactId> <artifactId>micronaut-test-junit5</artifactId>
<scope>test</scope> <scope>test</scope>
</dependency> </dependency>
<dependency>
<groupId>io.micronaut</groupId>
<artifactId>micronaut-http-client</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>io.micronaut</groupId>
<artifactId>micronaut-http-server-netty</artifactId>
<scope>test</scope>
</dependency>
<dependency>
<groupId>io.micronaut.security</groupId>
<artifactId>micronaut-security-jwt</artifactId>
<scope>test</scope>
</dependency>
<!-- logging --> <!-- logging -->
<dependency> <dependency>

View file

@ -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<Integer> 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<MutableHttpResponse<?>> doFilter(HttpRequest<?> request, ServerFilterChain chain) {
request.getHeaders().getFirst(header).ifPresent(level -> MDC.put(MDC_KEY, level));
return chain.proceed(request);
}
}

View file

@ -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;
}
}

View file

@ -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<Integer> order) {
this.key = key;
this.order = order.orElse(DEFAULT_ORDER);
}
@Override
public int getOrder() {
return order;
}
@Override
public Publisher<MutableHttpResponse<?>> doFilter(HttpRequest<?> request, ServerFilterChain chain) {
request.getUserPrincipal().ifPresent(princial -> MDC.put(key, princial.getName()));
return chain.proceed(request);
}
}

View file

@ -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");
}
}

View file

@ -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");
}
}

View file

@ -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());
}
}

View file

@ -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());
}
}

View file

@ -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;
}
}

View file

@ -0,0 +1,8 @@
logger:
mdc:
principal:
level: DEBUG
loggers:
- io.kokuwa
values:
- horst

View file

@ -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