From 963e9ade1f68baa3a9f4fde6290977260bdb7b59 Mon Sep 17 00:00:00 2001 From: Valentin Laurin Date: Wed, 5 Feb 2025 15:10:17 +0000 Subject: [PATCH 1/5] Add Spring dependency management Let Spring drives versions of dependencies in accordance with BOM of version of Spring Boot currently used --- build.gradle.kts | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/build.gradle.kts b/build.gradle.kts index 6572f69..fb498b4 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -4,6 +4,7 @@ plugins { `java-library` `jacoco` id("io.freefair.lombok") version "8.12.1" + id("io.spring.dependency-management") version "1.1.7" } java { @@ -15,8 +16,18 @@ repositories { mavenCentral() } +val versions = mapOf( + "springBoot" to "3.4.2" +) + +dependencyManagement { + imports { + mavenBom("org.springframework.boot:spring-boot-dependencies:${versions["springBoot"]}") + } +} + dependencies { - api("com.fasterxml.jackson.core:jackson-databind:2.18.2") + api("com.fasterxml.jackson.core:jackson-databind") testImplementation("org.hamcrest:hamcrest:3.0") } From c39a61ca5a120ddc8104a6c0ac9f095e3070fc19 Mon Sep 17 00:00:00 2001 From: Valentin Laurin Date: Wed, 5 Feb 2025 15:48:09 +0000 Subject: [PATCH 2/5] Add dependency on spring-boot-starter-web Provides transitive dependency on `jakarta.servlet` package required to write HTTP request filters for Spring Boot --- build.gradle.kts | 1 + 1 file changed, 1 insertion(+) diff --git a/build.gradle.kts b/build.gradle.kts index fb498b4..30a2e40 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -28,6 +28,7 @@ dependencyManagement { dependencies { api("com.fasterxml.jackson.core:jackson-databind") + api("org.springframework.boot:spring-boot-starter-web") testImplementation("org.hamcrest:hamcrest:3.0") } From 82afb9abd131f22b0f8c7dc7bb9c3a7a486a16ad Mon Sep 17 00:00:00 2001 From: Valentin Laurin Date: Wed, 5 Feb 2025 16:11:39 +0000 Subject: [PATCH 3/5] Add dependency on `logback-classic` This prepares this library to replace the legacy quickcase/spring-logging project --- build.gradle.kts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/build.gradle.kts b/build.gradle.kts index 30a2e40..79dca56 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -30,6 +30,8 @@ dependencies { api("com.fasterxml.jackson.core:jackson-databind") api("org.springframework.boot:spring-boot-starter-web") + implementation("ch.qos.logback:logback-classic") + testImplementation("org.hamcrest:hamcrest:3.0") } From 908d4439bd43b1c4b132e430d5dc8ebb3dab48e7 Mon Sep 17 00:00:00 2001 From: Valentin Laurin Date: Wed, 5 Feb 2025 17:43:46 +0000 Subject: [PATCH 4/5] Add default Logback config with JSON support Re-use Spring Boot default logback configuration but extends with structured JSON format used by default. --- src/main/resources/console-json-appender.xml | 22 ++++++++++++++++++++ src/main/resources/logback.xml | 17 +++++++++++++++ 2 files changed, 39 insertions(+) create mode 100644 src/main/resources/console-json-appender.xml create mode 100644 src/main/resources/logback.xml diff --git a/src/main/resources/console-json-appender.xml b/src/main/resources/console-json-appender.xml new file mode 100644 index 0000000..e1af9bb --- /dev/null +++ b/src/main/resources/console-json-appender.xml @@ -0,0 +1,22 @@ + + + + + + + + ${CONSOLE_LOG_THRESHOLD} + + + false + false + false + false + false + true + + + \ No newline at end of file diff --git a/src/main/resources/logback.xml b/src/main/resources/logback.xml new file mode 100644 index 0000000..0fd1480 --- /dev/null +++ b/src/main/resources/logback.xml @@ -0,0 +1,17 @@ + + + + + + + + + + + + + + + + + \ No newline at end of file From 005349aeba632a79454931907051df2bb8c4d088 Mon Sep 17 00:00:00 2001 From: Valentin Laurin Date: Wed, 5 Feb 2025 17:44:53 +0000 Subject: [PATCH 5/5] Add HTTP request logging utilities Servlet filters migrated from quickcase/data-store to: - log access requests - clear MDC per request (avoid MDC leaks) - group logs per requests using request trace ID For convenience a configuration class is provided to be imported in consuming web apps. --- build.gradle.kts | 1 + .../sdk/spring/logging/AccessLogFilter.java | 85 +++++++++++++++++++ .../spring/logging/LoggingConfiguration.java | 32 +++++++ .../sdk/spring/logging/MDCBoundaryFilter.java | 29 +++++++ .../spring/logging/TraceRequestFilter.java | 36 ++++++++ .../spring/logging/AccessLogFilterTest.java | 53 ++++++++++++ 6 files changed, 236 insertions(+) create mode 100644 src/main/java/app/quickcase/sdk/spring/logging/AccessLogFilter.java create mode 100644 src/main/java/app/quickcase/sdk/spring/logging/LoggingConfiguration.java create mode 100644 src/main/java/app/quickcase/sdk/spring/logging/MDCBoundaryFilter.java create mode 100644 src/main/java/app/quickcase/sdk/spring/logging/TraceRequestFilter.java create mode 100644 src/test/java/app/quickcase/sdk/spring/logging/AccessLogFilterTest.java diff --git a/build.gradle.kts b/build.gradle.kts index 79dca56..a5e4668 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -33,6 +33,7 @@ dependencies { implementation("ch.qos.logback:logback-classic") testImplementation("org.hamcrest:hamcrest:3.0") + testImplementation("org.mockito:mockito-core") } testing { diff --git a/src/main/java/app/quickcase/sdk/spring/logging/AccessLogFilter.java b/src/main/java/app/quickcase/sdk/spring/logging/AccessLogFilter.java new file mode 100644 index 0000000..9ce3d39 --- /dev/null +++ b/src/main/java/app/quickcase/sdk/spring/logging/AccessLogFilter.java @@ -0,0 +1,85 @@ +package app.quickcase.sdk.spring.logging; + +import java.io.IOException; +import java.time.Clock; +import java.time.Duration; +import java.time.Instant; + +import jakarta.servlet.Filter; +import jakarta.servlet.FilterChain; +import jakarta.servlet.ServletException; +import jakarta.servlet.ServletRequest; +import jakarta.servlet.ServletResponse; +import jakarta.servlet.http.HttpServletRequest; +import jakarta.servlet.http.HttpServletResponse; +import lombok.extern.slf4j.Slf4j; +import org.slf4j.spi.LoggingEventBuilder; +import org.springframework.http.HttpMethod; + +@Slf4j +public class AccessLogFilter implements Filter { + private static final String KEY_METHOD = "requestMethod"; + private static final String KEY_URI = "requestUri"; + private static final String KEY_STATUS = "responseCode"; + private static final String KEY_DURATION = "duration"; + + private final Clock clock; + + public AccessLogFilter() { + this.clock = Clock.systemDefaultZone(); + } + + public AccessLogFilter(Clock clock) { + this.clock = clock; + } + + @Override + public void doFilter(ServletRequest request, + ServletResponse response, + FilterChain chain) throws IOException, ServletException { + final HttpServletRequest httpRequest = (HttpServletRequest) request; + final HttpServletResponse httpResponse = (HttpServletResponse) response; + + final String method = httpRequest.getMethod(); + final String requestURI = httpRequest.getRequestURI(); + + log.atTrace() + .addKeyValue(KEY_METHOD, method) + .addKeyValue(KEY_URI, requestURI) + .log("Request received: {} {}", method, requestURI); + + final Instant start = clock.instant(); + + try { + chain.doFilter(request, response); + + final Duration duration = Duration.between(start, clock.instant()); + final int status = httpResponse.getStatus(); + + successLogBuilder(method) + .addKeyValue(KEY_METHOD, method) + .addKeyValue(KEY_URI, requestURI) + .addKeyValue(KEY_STATUS, status) + .addKeyValue(KEY_DURATION, duration.toMillis()) + .log("Request processed ({}) in {}ms: {} {}", status, duration.toMillis(), method, requestURI); + + } catch (Exception exception) { + final Duration duration = Duration.between(start, clock.instant()); + + log.atError() + .addKeyValue(KEY_METHOD, method) + .addKeyValue(KEY_URI, requestURI) + .addKeyValue(KEY_DURATION, duration.toMillis()) + .log("Request failed in {}ms: {} {} ", duration.toMillis(), method, requestURI); + + throw exception; + } + } + + private LoggingEventBuilder successLogBuilder (String httpMethod) { + if (HttpMethod.OPTIONS.matches(httpMethod)) { + return log.atDebug(); + } + return log.atInfo(); + } +} diff --git a/src/main/java/app/quickcase/sdk/spring/logging/LoggingConfiguration.java b/src/main/java/app/quickcase/sdk/spring/logging/LoggingConfiguration.java new file mode 100644 index 0000000..2e32198 --- /dev/null +++ b/src/main/java/app/quickcase/sdk/spring/logging/LoggingConfiguration.java @@ -0,0 +1,32 @@ +package app.quickcase.sdk.spring.logging; + +import jakarta.servlet.Filter; +import org.springframework.context.annotation.Bean; +import org.springframework.context.annotation.Configuration; +import org.springframework.core.Ordered; +import org.springframework.core.annotation.Order; + +/** + * Spring configuration class to import in web app using Spring's @Import annotation in order to enable MDC support, + * access logs and request tracing. + */ +@Configuration +public class LoggingConfiguration { + @Bean + @Order(Ordered.HIGHEST_PRECEDENCE) + public Filter mdcBoundaryFilter() { + return new MDCBoundaryFilter(); + } + + @Bean + @Order(Ordered.HIGHEST_PRECEDENCE + 1) + public Filter traceRequestFilter() { + return new TraceRequestFilter(); + } + + @Bean + @Order(Ordered.HIGHEST_PRECEDENCE + 2) + public Filter accessLogFilter() { + return new AccessLogFilter(); + } +} diff --git a/src/main/java/app/quickcase/sdk/spring/logging/MDCBoundaryFilter.java b/src/main/java/app/quickcase/sdk/spring/logging/MDCBoundaryFilter.java new file mode 100644 index 0000000..ad12e3e --- /dev/null +++ b/src/main/java/app/quickcase/sdk/spring/logging/MDCBoundaryFilter.java @@ -0,0 +1,29 @@ +package app.quickcase.sdk.spring.logging; + +import java.io.IOException; + +import jakarta.servlet.Filter; +import jakarta.servlet.FilterChain; +import jakarta.servlet.ServletException; +import jakarta.servlet.ServletRequest; +import jakarta.servlet.ServletResponse; +import org.slf4j.MDC; + +/** + * Given web apps handle requests by allocating threads from a pool and then reusing threads, we must ensure that the + * MDC values for a given request are always cleared at the end of the request. + */ +public class MDCBoundaryFilter implements Filter { + @Override + public void doFilter( + ServletRequest request, + ServletResponse response, + FilterChain chain + ) throws IOException, ServletException { + try { + chain.doFilter(request, response); + } finally { + MDC.clear(); + } + } +} diff --git a/src/main/java/app/quickcase/sdk/spring/logging/TraceRequestFilter.java b/src/main/java/app/quickcase/sdk/spring/logging/TraceRequestFilter.java new file mode 100644 index 0000000..ec409d3 --- /dev/null +++ b/src/main/java/app/quickcase/sdk/spring/logging/TraceRequestFilter.java @@ -0,0 +1,36 @@ +package app.quickcase.sdk.spring.logging; + +import java.io.IOException; +import java.util.Optional; +import java.util.UUID; + +import jakarta.servlet.Filter; +import jakarta.servlet.FilterChain; +import jakarta.servlet.ServletException; +import jakarta.servlet.ServletRequest; +import jakarta.servlet.ServletResponse; +import jakarta.servlet.http.HttpServletRequest; +import org.slf4j.MDC; + +/** + * Generate a unique trace ID per request and assign it to MDC to allow grouping of logs per request. + * If the request itself bears a custom trace ID header, this is preserved as parent trace ID. + */ +public class TraceRequestFilter implements Filter { + public static final String X_TRACE_ID = "x-trace-id"; + + @Override + public void doFilter( + ServletRequest request, + ServletResponse response, + FilterChain chain + ) throws IOException, ServletException { + final HttpServletRequest httpRequest = (HttpServletRequest) request; + final Optional traceParentId = Optional.ofNullable(httpRequest.getHeader(X_TRACE_ID)); + + MDC.put("traceId", UUID.randomUUID().toString()); + traceParentId.ifPresent(id -> MDC.put("traceParentId", id)); + + chain.doFilter(request, response); + } +} diff --git a/src/test/java/app/quickcase/sdk/spring/logging/AccessLogFilterTest.java b/src/test/java/app/quickcase/sdk/spring/logging/AccessLogFilterTest.java new file mode 100644 index 0000000..18c5c9e --- /dev/null +++ b/src/test/java/app/quickcase/sdk/spring/logging/AccessLogFilterTest.java @@ -0,0 +1,53 @@ +package app.quickcase.sdk.spring.logging; + +import java.io.IOException; + +import jakarta.servlet.FilterChain; +import jakarta.servlet.ServletException; +import jakarta.servlet.http.HttpServletRequest; +import jakarta.servlet.http.HttpServletResponse; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Test; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.is; +import static org.mockito.Mockito.*; + +class AccessLogFilterTest { + + @Test + @DisplayName("should execute filter chain") + void shouldExecuteFilterChain() throws ServletException, IOException { + var filter = new AccessLogFilter(); + + var request = mock(HttpServletRequest.class); + var response = mock(HttpServletResponse.class); + var chain = mock(FilterChain.class); + + filter.doFilter(request, response, chain); + + verify(chain).doFilter(request, response); + } + + @Test + @DisplayName("should rethrow exception") + void shouldRethrowException() throws ServletException, IOException { + var filter = new AccessLogFilter(); + + var request = mock(HttpServletRequest.class); + var response = mock(HttpServletResponse.class); + var chain = mock(FilterChain.class); + + var exception = new RuntimeException("Some exception"); + + doThrow(exception).when(chain).doFilter(request, response); + + var actualException = Assertions.assertThrows( + RuntimeException.class, + () -> filter.doFilter(request, response, chain) + ); + assertThat(actualException, is(exception)); + } + +} \ No newline at end of file