From 9322d9845ee8a4a0326c9d47c10363869be4ec49 Mon Sep 17 00:00:00 2001 From: ennoeller Date: Fri, 30 Aug 2024 16:33:50 +0300 Subject: [PATCH 01/14] feature/enable-custom-http-logger-interceptor --- build.gradle | 2 +- .../retrofit/builder/RetrofitApiBuilder.java | 28 +++++++++++++++---- .../builder/SpringAwareRetrofitBuilder.java | 13 +++++++-- 3 files changed, 34 insertions(+), 9 deletions(-) diff --git a/build.gradle b/build.gradle index d0e8837..7efe82c 100644 --- a/build.gradle +++ b/build.gradle @@ -19,7 +19,7 @@ plugins { } group 'ee.bitweb' -version '3.3.0' +version '3.4.0' java { sourceCompatibility = '17' } diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java index b26e041..0a1c8f7 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java @@ -33,12 +33,12 @@ public class RetrofitApiBuilder { private final String url; private final Class definition; - private final HttpLoggingInterceptor loggingInterceptor; + private final Interceptor loggingInterceptor; private Converter.Factory converterFactory; private OkHttpClient.Builder clientBuilder; - public static RetrofitApiBuilder create(String baseUrl, Class definition) { + public static RetrofitApiBuilder create(String baseUrl, Class definition) { return new RetrofitApiBuilder<>( baseUrl, definition, @@ -47,7 +47,15 @@ public static RetrofitApiBuilder create(String baseUrl, Class definit ); } - private RetrofitApiBuilder(String url, Class definition, HttpLoggingInterceptor loggingInterceptor) { + public static RetrofitApiBuilder create(String baseUrl, Class definition, Interceptor loggingInterceptor) { + return new RetrofitApiBuilder<>( + baseUrl, + definition, + loggingInterceptor + ); + } + + private RetrofitApiBuilder(String url, Class definition, Interceptor loggingInterceptor) { this.url = url; this.definition = definition; this.loggingInterceptor = loggingInterceptor; @@ -97,13 +105,21 @@ public RetrofitApiBuilder replaceAllOfType(Interceptor interceptor) { } public RetrofitApiBuilder loggingLevel(LoggingLevel level) { - loggingInterceptor.setLevel(level.getLevel()); + if (loggingInterceptor instanceof HttpLoggingInterceptor httpLoggingInterceptor) { + httpLoggingInterceptor.setLevel(level.getLevel()); + } else { + log.error("Unknown logging interceptor used, unable to set logging level."); + } return this; } public RetrofitApiBuilder suppressedHeaders(List headers) { - headers.forEach(loggingInterceptor::redactHeader); + if (loggingInterceptor instanceof HttpLoggingInterceptor httpLoggingInterceptor) { + headers.forEach(httpLoggingInterceptor::redactHeader); + } else { + log.error("Unknown logging interceptor used, unable to set logging level."); + } return this; } @@ -166,7 +182,7 @@ public T build() { .build().create(definition); } - private OkHttpClient.Builder createDefaultBuilder(HttpLoggingInterceptor loggingInterceptor) { + private OkHttpClient.Builder createDefaultBuilder(Interceptor loggingInterceptor) { var httpClientBuilder = new OkHttpClient.Builder(); httpClientBuilder.interceptors().add(loggingInterceptor); diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java index 53674ea..cb8446e 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java @@ -3,6 +3,8 @@ import ee.bitweb.core.retrofit.RetrofitProperties; import ee.bitweb.core.retrofit.interceptor.InterceptorBean; import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; +import okhttp3.Interceptor; import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; import org.springframework.stereotype.Component; import retrofit2.Converter; @@ -10,6 +12,7 @@ import java.util.ArrayList; import java.util.List; +@Slf4j @Component @RequiredArgsConstructor @ConditionalOnProperty(value = "ee.bitweb.core.retrofit.auto-configuration", havingValue = "true") @@ -20,9 +23,15 @@ public class SpringAwareRetrofitBuilder { private final RetrofitProperties properties; public RetrofitApiBuilder create(String baseUrl, Class definition) { + return configure(RetrofitApiBuilder.create(baseUrl, definition)); + } + + public RetrofitApiBuilder create(String baseUrl, Class definition, Interceptor loggingInterceptor) { + return configure(RetrofitApiBuilder.create(baseUrl, definition, loggingInterceptor)); + } - return RetrofitApiBuilder.create(baseUrl, definition) - .addAll(new ArrayList<>(defaultInterceptors)) + private RetrofitApiBuilder configure(RetrofitApiBuilder api) { + return api.addAll(new ArrayList<>(defaultInterceptors)) .loggingLevel(properties.getLogging().getLevel()) .suppressedHeaders(properties.getLogging().getSuppressedHeaders()) .callTimeout(properties.getTimeout().getCall()) From 32d25fe0293029c80a4491ae913942a6194e9dc0 Mon Sep 17 00:00:00 2001 From: ennoeller Date: Mon, 2 Sep 2024 09:06:44 +0300 Subject: [PATCH 02/14] feature/enable-custom-http-logger-interceptor --- .../SpringAwareRetrofitBuilderTests.java | 28 +++++++++++++++++++ 1 file changed, 28 insertions(+) diff --git a/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java b/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java index 924ea82..306b2ba 100644 --- a/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java +++ b/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java @@ -152,6 +152,34 @@ void addedCustomInterceptorIsAppliedToApi() throws Exception { ); } + @Test + void addedCustomInterceptorAsLoggingInterceptorIsAppliedToApi() throws Exception { + context.set("some-trace-id-value"); + mockServerGet( + List.of( + new Header(config.getHeaderName(), "some-trace-id-value") + ), + "message", + 1 + ); + RequestCountInterceptor customInterceptor = new RequestCountInterceptor(); + + ExternalServiceApi api = builder.create( + BASE_URL + server.getPort(), + ExternalServiceApi.class, + customInterceptor + ).build(); + + ExternalServiceApi.Payload response = api.get().execute().body(); + Assertions.assertAll( + () -> Assertions.assertEquals("message", response.getMessage()), + () -> Assertions.assertEquals(1, response.getValue()), + () -> Assertions.assertEquals(1, interceptor1.getCount()), + () -> Assertions.assertEquals(1, interceptor2.getCount()), + () -> Assertions.assertEquals(1, customInterceptor.getCount()) + ); + } + private static void mockServerGet(List
headers, String message, Integer value) { server.mock( server.requestBuilder() From d0f28bfec8c7f54d92fecc01f674a3bb992d6767 Mon Sep 17 00:00:00 2001 From: ennoeller Date: Tue, 1 Oct 2024 16:10:12 +0300 Subject: [PATCH 03/14] feature/enable-custom-http-logger-interceptor --- build.gradle | 2 +- .../core/retrofit/RetrofitProperties.java | 10 +- .../core/retrofit/builder/LoggingLevel.java | 18 - .../retrofit/builder/RetrofitApiBuilder.java | 26 +- .../builder/SpringAwareRetrofitBuilder.java | 4 +- .../retrofit/logging/LoggingInterceptor.java | 9 + .../core/retrofit/logging/LoggingLevel.java | 17 + .../logging/RetrofitLoggingInterceptor.java | 350 ++++++++++++++++++ .../SpringAwareRetrofitBuilderTests.java | 30 -- .../retrofit/helpers/ExternalServiceApi.java | 7 + .../RetrofitLoggingInterceptorTest.java | 263 +++++++++++++ 11 files changed, 664 insertions(+), 72 deletions(-) delete mode 100644 src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java create mode 100644 src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java diff --git a/build.gradle b/build.gradle index c8137b1..27003f9 100644 --- a/build.gradle +++ b/build.gradle @@ -19,7 +19,7 @@ plugins { } group 'ee.bitweb' -version '3.4.0' +version '3.5.0' java { sourceCompatibility = '17' } diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java index cb78661..61483e3 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java @@ -1,6 +1,10 @@ package ee.bitweb.core.retrofit; -import ee.bitweb.core.retrofit.builder.LoggingLevel; +import ee.bitweb.core.retrofit.logging.LoggingLevel; +import jakarta.validation.Valid; +import jakarta.validation.constraints.AssertTrue; +import jakarta.validation.constraints.NotBlank; +import jakarta.validation.constraints.NotNull; import lombok.Getter; import lombok.Setter; import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; @@ -10,10 +14,6 @@ import org.springframework.util.StringUtils; import org.springframework.validation.annotation.Validated; -import jakarta.validation.Valid; -import jakarta.validation.constraints.AssertTrue; -import jakarta.validation.constraints.NotBlank; -import jakarta.validation.constraints.NotNull; import java.util.ArrayList; import java.util.List; diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java b/src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java deleted file mode 100644 index c4fd0ee..0000000 --- a/src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java +++ /dev/null @@ -1,18 +0,0 @@ -package ee.bitweb.core.retrofit.builder; - -import lombok.AccessLevel; -import lombok.AllArgsConstructor; -import lombok.Getter; -import okhttp3.logging.HttpLoggingInterceptor; - -@AllArgsConstructor(access = AccessLevel.PRIVATE) -public enum LoggingLevel { - - NONE(HttpLoggingInterceptor.Level.NONE), - BASIC(HttpLoggingInterceptor.Level.BASIC), - HEADERS(HttpLoggingInterceptor.Level.HEADERS), - BODY(HttpLoggingInterceptor.Level.BODY); - - @Getter(AccessLevel.PACKAGE) - private HttpLoggingInterceptor.Level level; -} diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java index 0a1c8f7..68479c0 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java @@ -3,10 +3,12 @@ import com.fasterxml.jackson.databind.DeserializationFeature; import com.fasterxml.jackson.databind.ObjectMapper; import com.fasterxml.jackson.datatype.jsr310.JavaTimeModule; +import ee.bitweb.core.retrofit.logging.LoggingInterceptor; +import ee.bitweb.core.retrofit.logging.LoggingLevel; +import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptor; import lombok.extern.slf4j.Slf4j; import okhttp3.Interceptor; import okhttp3.OkHttpClient; -import okhttp3.logging.HttpLoggingInterceptor; import retrofit2.Converter; import retrofit2.Retrofit; import retrofit2.converter.jackson.JacksonConverterFactory; @@ -33,7 +35,7 @@ public class RetrofitApiBuilder { private final String url; private final Class definition; - private final Interceptor loggingInterceptor; + private final LoggingInterceptor loggingInterceptor; private Converter.Factory converterFactory; private OkHttpClient.Builder clientBuilder; @@ -42,12 +44,12 @@ public static RetrofitApiBuilder create(String baseUrl, Class definiti return new RetrofitApiBuilder<>( baseUrl, definition, - new HttpLoggingInterceptor() - .setLevel(DEFAULT_LOGGING_LEVEL.getLevel()) + new RetrofitLoggingInterceptor() + .setLevel(DEFAULT_LOGGING_LEVEL) ); } - public static RetrofitApiBuilder create(String baseUrl, Class definition, Interceptor loggingInterceptor) { + public static RetrofitApiBuilder create(String baseUrl, Class definition, LoggingInterceptor loggingInterceptor) { return new RetrofitApiBuilder<>( baseUrl, definition, @@ -55,7 +57,7 @@ public static RetrofitApiBuilder create(String baseUrl, Class definiti ); } - private RetrofitApiBuilder(String url, Class definition, Interceptor loggingInterceptor) { + private RetrofitApiBuilder(String url, Class definition, LoggingInterceptor loggingInterceptor) { this.url = url; this.definition = definition; this.loggingInterceptor = loggingInterceptor; @@ -105,21 +107,13 @@ public RetrofitApiBuilder replaceAllOfType(Interceptor interceptor) { } public RetrofitApiBuilder loggingLevel(LoggingLevel level) { - if (loggingInterceptor instanceof HttpLoggingInterceptor httpLoggingInterceptor) { - httpLoggingInterceptor.setLevel(level.getLevel()); - } else { - log.error("Unknown logging interceptor used, unable to set logging level."); - } + loggingInterceptor.setLevel(level); return this; } public RetrofitApiBuilder suppressedHeaders(List headers) { - if (loggingInterceptor instanceof HttpLoggingInterceptor httpLoggingInterceptor) { - headers.forEach(httpLoggingInterceptor::redactHeader); - } else { - log.error("Unknown logging interceptor used, unable to set logging level."); - } + headers.forEach(loggingInterceptor::redactHeader); return this; } diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java index cb8446e..193f4ea 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java @@ -2,9 +2,9 @@ import ee.bitweb.core.retrofit.RetrofitProperties; import ee.bitweb.core.retrofit.interceptor.InterceptorBean; +import ee.bitweb.core.retrofit.logging.LoggingInterceptor; import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; -import okhttp3.Interceptor; import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; import org.springframework.stereotype.Component; import retrofit2.Converter; @@ -26,7 +26,7 @@ public RetrofitApiBuilder create(String baseUrl, Class definition) { return configure(RetrofitApiBuilder.create(baseUrl, definition)); } - public RetrofitApiBuilder create(String baseUrl, Class definition, Interceptor loggingInterceptor) { + public RetrofitApiBuilder create(String baseUrl, Class definition, LoggingInterceptor loggingInterceptor) { return configure(RetrofitApiBuilder.create(baseUrl, definition, loggingInterceptor)); } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java new file mode 100644 index 0000000..28061a7 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java @@ -0,0 +1,9 @@ +package ee.bitweb.core.retrofit.logging; + +import okhttp3.Interceptor; + +public interface LoggingInterceptor extends Interceptor { + + LoggingInterceptor setLevel(LoggingLevel level); + void redactHeader(String name); +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java new file mode 100644 index 0000000..c302912 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java @@ -0,0 +1,17 @@ +package ee.bitweb.core.retrofit.logging; + +import lombok.AccessLevel; +import lombok.AllArgsConstructor; +import lombok.Getter; + +@AllArgsConstructor(access = AccessLevel.PRIVATE) +public enum LoggingLevel { + + NONE(0), + BASIC(1), + HEADERS(2), + BODY(3); + + @Getter(AccessLevel.PACKAGE) + private int level; +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java new file mode 100644 index 0000000..0132898 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java @@ -0,0 +1,350 @@ +package ee.bitweb.core.retrofit.logging; + +import lombok.extern.slf4j.Slf4j; +import okhttp3.*; +import okio.Buffer; +import okio.GzipSource; +import org.jetbrains.annotations.NotNull; + +import java.io.EOFException; +import java.io.IOException; +import java.nio.charset.Charset; +import java.util.*; + +import static java.nio.charset.StandardCharsets.UTF_8; +import static java.util.concurrent.TimeUnit.NANOSECONDS; +import static okhttp3.internal.http.HttpHeaders.promisesBody; + +@Slf4j +public class RetrofitLoggingInterceptor implements LoggingInterceptor { + + private static final String CONTENT_TYPE = "Content-Type"; + private static final String CONTENT_LENGTH = "Content-Length"; + + private LoggingLevel loggingLevel = LoggingLevel.BASIC; + private final Set redactHeaders = new HashSet<>(); + + @Override + public LoggingInterceptor setLevel(LoggingLevel level) { + this.loggingLevel = level; + + return this; + } + + @Override + public void redactHeader(String name) { + this.redactHeaders.add(name.toLowerCase()); + } + + @NotNull + @Override + public Response intercept(@NotNull Chain chain) throws IOException { + if (loggingLevel.getLevel() == 0) { + return chain.proceed(chain.request()); + } + + var request = chain.request(); + var connection = chain.connection(); + + try { + StringBuilder sb = new StringBuilder(); + + sb.append(getRequestDescription(request, connection)); + + if (loggingLevel.getLevel() >= 2) { + sb.append("\n").append(getRequestHeaders(request)); + } + + if (loggingLevel.getLevel() >= 3) { + sb.append("\n").append(getRequestBody(request)); + } + + log.info("{}", sb); + } catch (Exception e) { + log.error("Unable to log request.", e); + } + + var startNs = System.nanoTime(); + + Response response; + try { + response = chain.proceed(request); + } catch (Exception e) { + log.warn("<-- HTTP FAILED", e); + throw e; + } + + var durationMs = NANOSECONDS.toMillis(System.nanoTime() - startNs); + + try { + StringBuilder sb = new StringBuilder(); + + sb.append(getResponseDescription(response, durationMs)); + + if (loggingLevel.getLevel() >= 2) { + sb.append("\n").append(getResponseHeaders(response)); + } + + if (loggingLevel.getLevel() >= 3) { + sb.append("\n").append(getResponseBody(response)); + } + + log.info("{}", sb); + } catch (Exception e) { + log.error("Unable to log response", e); + } + + return response; + } + + protected String getRequestDescription(Request request, Connection connection) { + return "--> %s %s%s".formatted(request.method(), request.url(), connection != null ? connection.protocol() : ""); + } + + protected String getResponseDescription(Response response, long durationMs) { + String bodySize; + + if (response.body() != null && response.body().contentLength() != -1L) { + bodySize = "%s-byte".formatted(response.body().contentLength()); + } else { + bodySize = "unknown length"; + } + + return "<-- %s%s %s %sms, body size %s".formatted( + response.code(), + response.message().isEmpty() ? "" : " " + response.message(), + response.request().url(), + durationMs, + bodySize + ); + } + + protected String getRequestHeaders(Request request) throws IOException { + List headerRows = new ArrayList<>(); + + var requestHeaders = request.headers(); + var requestBody = request.body(); + + String contentType = getRequestContentTypeValue(requestHeaders, requestBody); + String contentLength = getRequestContentLengthValue(requestHeaders, requestBody); + + if (contentType != null) { + addHeaderToRows(headerRows, CONTENT_TYPE, contentType); + } + + if (contentLength != null) { + addHeaderToRows(headerRows, CONTENT_LENGTH, contentLength); + } + + for (int i = 0; i < requestHeaders.size(); i++) { + var name = requestHeaders.name(i); + if (List.of("content-type", "content-length").contains(name.toLowerCase())) { + continue; + } + addHeaderToRows(headerRows, name, requestHeaders.value(i)); + } + + return headerRowsToString(headerRows); + } + + protected String getResponseHeaders(Response response) { + List headerRows = new ArrayList<>(); + + var responseHeaders = response.headers(); + var responseBody = response.body(); + + String contentType = getResponseContentTypeValue(responseHeaders, responseBody); + String contentLength = getResponseContentLengthValue(responseHeaders, responseBody); + + if (contentType != null) { + addHeaderToRows(headerRows, CONTENT_TYPE, contentType); + } + + if (contentLength != null) { + addHeaderToRows(headerRows, CONTENT_LENGTH, contentLength); + } + + for (int i = 0; i < responseHeaders.size(); i++) { + var name = responseHeaders.name(i); + if (List.of("content-type", "content-length").contains(name.toLowerCase())) { + continue; + } + addHeaderToRows(headerRows, name, responseHeaders.value(i)); + } + + return headerRowsToString(headerRows); + } + + protected String getRequestContentTypeValue(Headers headers, RequestBody body) { + var headerValue = headers.get(CONTENT_TYPE); + + if (headerValue != null) { + return headerValue; + } + + if (body != null && body.contentType() != null) { + return Objects.requireNonNullElse(body.contentType(), "").toString(); + } + + return null; + } + + protected String getRequestContentLengthValue(Headers headers, RequestBody body) throws IOException { + var headerValue = headers.get(CONTENT_LENGTH); + + if (headerValue != null) { + return headerValue; + } + + if (body != null && body.contentLength() != -1) { + return String.valueOf(body.contentLength()); + } + + return null; + } + + protected String getResponseContentTypeValue(Headers headers, ResponseBody body) { + var headerValue = headers.get(CONTENT_TYPE); + + if (headerValue != null) { + return headerValue; + } + + if (body != null && body.contentType() != null) { + return Objects.requireNonNullElse(body.contentType(), "").toString(); + } + + return null; + } + + protected String getResponseContentLengthValue(Headers headers, ResponseBody body) { + var headerValue = headers.get(CONTENT_LENGTH); + + if (headerValue != null) { + return headerValue; + } + + if (body != null && body.contentLength() != -1) { + return String.valueOf(body.contentLength()); + } + + return null; + } + + protected void addHeaderToRows(List headerRows, String name, String value) { + headerRows.add("\t%s: %s".formatted( + name, + redactHeaders.contains(name.toLowerCase()) ? " " : value + )); + } + + protected String headerRowsToString(List headerRows) { + StringBuilder sb = new StringBuilder() + .append("Headers:"); + + headerRows.forEach(row -> sb.append("\n").append(row)); + + return sb.toString(); + } + + protected String getRequestBody(Request request) throws IOException { + var body = request.body(); + + if (body == null) { + return "null"; + } else if (bodyHasUnknownEncoding(request.headers())) { + return "(encoded body omitted)"; + } else if (body.isDuplex()) { + return "(duplex request body omitted)"; + } else if (body.isOneShot()) { + return "(one-shot body omitted)"; + } else { + var buffer = new Buffer(); + body.writeTo(buffer); + + var contentType = body.contentType(); + Charset charSet = contentType != null ? contentType.charset(UTF_8) : UTF_8; + + if (isProbablyUtf8(buffer)) { + assert charSet != null; + return buffer.readString(charSet); + } else { + return ("binary body omitted"); + } + } + } + + protected String getResponseBody(Response response) throws IOException { + if (!promisesBody(response)) { + return ""; + } else if (bodyHasUnknownEncoding(response.headers())) { + return "(encoded body omitted)"; + } else if (response.body() == null) { + return "(body missing)"; + } else { + var responseBody = response.body(); + var contentType = responseBody.contentType(); + var contentLength = responseBody.contentLength(); + var charset = contentType != null ? contentType.charset(UTF_8) : UTF_8; + + var source = responseBody.source(); + source.request(Long.MAX_VALUE); + var buffer = source.getBuffer(); + + Long gzippedLength = null; + if ("gzip".equalsIgnoreCase(response.header("Content-Encoding"))) { + gzippedLength = buffer.size(); + var gzipSource = new GzipSource(buffer.clone()); + buffer = new Buffer(); + gzipSource.read(buffer, gzippedLength); + } + + if (!isProbablyUtf8(buffer)) { + return "(binary %s-byte body omitted)".formatted(buffer.size()); + } + + if (contentLength != 0L) { + return buffer.clone().readString(charset); + } else { + return ""; + } + } + } + + protected boolean bodyHasUnknownEncoding(Headers headers) { + var contentEncoding = headers.get("Content-Encoding"); + + if (contentEncoding == null) { + return false; + } + + return !contentEncoding.equalsIgnoreCase("identity") && + !contentEncoding.equalsIgnoreCase("gzip"); + } + + protected boolean isProbablyUtf8(Buffer buffer) { + try { + var prefix = new Buffer(); + var byteCount = buffer.size() > 64 ? 64 : buffer.size(); + + buffer.copyTo(prefix, 0, byteCount); + + for (int i = 0; i < 16; i++) { + if (prefix.exhausted()) { + break; + } + + var codePoint = prefix.readUtf8CodePoint(); + + if (Character.isISOControl(codePoint) && !Character.isWhitespace(codePoint)) { + return false; + } + } + + return true; + } catch (EOFException e) { + log.trace("", e); + return false; + } + } +} diff --git a/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java b/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java index 306b2ba..27d2f41 100644 --- a/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java +++ b/src/test/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilderTests.java @@ -34,8 +34,6 @@ class SpringAwareRetrofitBuilderTests { @RegisterExtension private static final MockServer server = new MockServer(HttpMethod.GET, "/request"); - - @Autowired private SpringAwareRetrofitBuilder builder; @@ -152,34 +150,6 @@ void addedCustomInterceptorIsAppliedToApi() throws Exception { ); } - @Test - void addedCustomInterceptorAsLoggingInterceptorIsAppliedToApi() throws Exception { - context.set("some-trace-id-value"); - mockServerGet( - List.of( - new Header(config.getHeaderName(), "some-trace-id-value") - ), - "message", - 1 - ); - RequestCountInterceptor customInterceptor = new RequestCountInterceptor(); - - ExternalServiceApi api = builder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class, - customInterceptor - ).build(); - - ExternalServiceApi.Payload response = api.get().execute().body(); - Assertions.assertAll( - () -> Assertions.assertEquals("message", response.getMessage()), - () -> Assertions.assertEquals(1, response.getValue()), - () -> Assertions.assertEquals(1, interceptor1.getCount()), - () -> Assertions.assertEquals(1, interceptor2.getCount()), - () -> Assertions.assertEquals(1, customInterceptor.getCount()) - ); - } - private static void mockServerGet(List
headers, String message, Integer value) { server.mock( server.requestBuilder() diff --git a/src/test/java/ee/bitweb/core/retrofit/helpers/ExternalServiceApi.java b/src/test/java/ee/bitweb/core/retrofit/helpers/ExternalServiceApi.java index bae4423..da4ae99 100644 --- a/src/test/java/ee/bitweb/core/retrofit/helpers/ExternalServiceApi.java +++ b/src/test/java/ee/bitweb/core/retrofit/helpers/ExternalServiceApi.java @@ -1,11 +1,14 @@ package ee.bitweb.core.retrofit.helpers; import ee.bitweb.core.retrofit.Response; +import lombok.AllArgsConstructor; import lombok.Getter; import lombok.NoArgsConstructor; import lombok.Setter; import retrofit2.Call; +import retrofit2.http.Body; import retrofit2.http.GET; +import retrofit2.http.POST; public interface ExternalServiceApi { @@ -15,9 +18,13 @@ public interface ExternalServiceApi { @GET("/data-request") Call> getWrappedInResponse(); + @POST("/data-post") + Call postData(@Body Payload payload); + @Setter @Getter @NoArgsConstructor + @AllArgsConstructor class Payload { private String message; private Integer value; diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java new file mode 100644 index 0000000..7f14ab4 --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java @@ -0,0 +1,263 @@ +package ee.bitweb.core.retrofit.logging; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.LoggerContext; +import ee.bitweb.core.TestSpringApplication; +import ee.bitweb.core.retrofit.RetrofitProperties; +import ee.bitweb.core.retrofit.builder.SpringAwareRetrofitBuilder; +import ee.bitweb.core.retrofit.helpers.ExternalServiceApi; +import ee.bitweb.core.trace.context.TraceIdContext; +import ee.bitweb.core.utils.MemoryAppender; +import ee.bitweb.http.server.mock.MockServer; +import io.netty.handler.codec.http.HttpMethod; +import org.json.JSONObject; +import org.junit.jupiter.api.*; +import org.junit.jupiter.api.extension.RegisterExtension; +import org.slf4j.LoggerFactory; +import org.springframework.beans.factory.annotation.Autowired; +import org.springframework.boot.test.context.SpringBootTest; +import org.springframework.test.context.ActiveProfiles; + +import java.io.IOException; +import java.util.ArrayList; +import java.util.List; +import java.util.regex.Pattern; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertTrue; + +@Tag("integration") +@SpringBootTest( + classes = TestSpringApplication.class, + properties = { + "ee.bitweb.core.trace.auto-configuration=true", + "ee.bitweb.core.retrofit.auto-configuration=true" + } +) +@ActiveProfiles("retrofit") +class RetrofitLoggingInterceptorTest { + + private static final String BASE_URL = "http://localhost:"; + + @RegisterExtension + private static final MockServer server = new MockServer(HttpMethod.POST, "/data-post"); + + @Autowired + private SpringAwareRetrofitBuilder builder; + + @Autowired + private TraceIdContext context; + + @Autowired + private RetrofitProperties retrofitProperties; + + Logger logger; + MemoryAppender memoryAppender; + + @BeforeEach + void beforeEach() { + context.set("TEST"); + + logger = (Logger) LoggerFactory.getLogger(RetrofitLoggingInterceptor.class); + memoryAppender = new MemoryAppender(); + memoryAppender.setContext((LoggerContext) LoggerFactory.getILoggerFactory()); + logger.setLevel(Level.DEBUG); + logger.addAppender(memoryAppender); + memoryAppender.start(); + } + + @AfterEach + void afterEach() { + context.clear(); + + memoryAppender.stop(); + + retrofitProperties.getLogging().setLevel(LoggingLevel.BASIC); + retrofitProperties.getLogging().setSuppressedHeaders(new ArrayList<>()); + } + + @Test + @DisplayName("Logging level NONE") + void loggingLevelNone() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.NONE); + + executeRetrofitRequest(); + + assertEquals(0, memoryAppender.getSize()); + } + + @Test + @DisplayName("Logging level BASIC") + void loggingLevelBasic() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.BASIC); + + executeRetrofitRequest(); + + assertEquals(2, memoryAppender.getSize()); + + assertRequestLevel(); + assertRequestDescription(); + assertRequestHeaderExists(false); + assertRequestBodyExists(false); + + assertResponseLevel(); + assertResponseDescription(); + assertResponseHeaderExists(false); + assertResponseBodyExists(false); + } + + @Test + @DisplayName("Logging level HEADERS") + void loggingLevelHeaders() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.HEADERS); + + executeRetrofitRequest(); + + assertEquals(2, memoryAppender.getSize()); + + assertRequestLevel(); + assertRequestDescription(); + assertRequestHeaderExists(true); + assertRequestBodyExists(false); + + assertResponseLevel(); + assertResponseDescription(); + assertResponseHeaderExists(true); + assertResponseBodyExists(false); + } + + @Test + @DisplayName("Logging level BODY") + void loggingLevelBody() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.BODY); + + executeRetrofitRequest(); + + assertEquals(2, memoryAppender.getSize()); + + assertRequestLevel(); + assertRequestDescription(); + assertRequestHeaderExists(true); + assertRequestBodyExists(true); + + assertResponseLevel(); + assertResponseDescription(); + assertResponseHeaderExists(true); + assertResponseBodyExists(true); + } + + @Test + @DisplayName("Redact header") + void redactHeader() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.HEADERS); + retrofitProperties.getLogging().setSuppressedHeaders(List.of("content-type")); + + executeRetrofitRequest(); + + assertEquals(2, memoryAppender.getSize()); + + logger.info("Request: {}", memoryAppender.getLoggedEvents().get(0).getFormattedMessage()); + logger.info("Response: {}", memoryAppender.getLoggedEvents().get(1).getFormattedMessage()); + + assertRequestLevel(); + assertRequestDescription(); + assertRequestHeaderExists(false); + assertRequestBodyExists(false); + assertRequestHeaderRedacted(); + + assertResponseLevel(); + assertResponseDescription(); + assertResponseHeaderExists(false); + assertResponseBodyExists(false); + assertResponseHeaderRedacted(); + } + + private void assertRequestLevel() { + assertEquals(Level.INFO, memoryAppender.getLoggedEvents().get(0).getLevel()); + } + + private void assertResponseLevel() { + assertEquals(Level.INFO, memoryAppender.getLoggedEvents().get(1).getLevel()); + } + + private void assertRequestDescription() { + assertTrue(Pattern.compile("--> POST http://localhost:[0-9]*/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find()); + } + + private void assertResponseDescription() { + assertTrue(Pattern.compile("<-- 200 OK http://localhost:[0-9]*/data-post [0-9]*ms, body size 32-byte") + .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find()); + } + + private void assertRequestHeaderExists(boolean exists) { + assertEquals( + exists, + Pattern.compile("Content-Type: application\\/json; charset=UTF-8") + .matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find() + ); + } + + private void assertResponseHeaderExists(boolean exists) { + assertEquals( + exists, + Pattern.compile("Content-Type: application\\/json; charset=utf-8") + .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + ); + } + + private void assertRequestHeaderRedacted() { + assertTrue( + Pattern.compile("Content-Type: \n") + .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + ); + } + + private void assertResponseHeaderRedacted() { + assertTrue( + Pattern.compile("Content-Type: \n") + .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + ); + } + + private void assertRequestBodyExists(boolean exists) { + assertEquals( + exists, + Pattern.compile("\\{\"message\":\"message1\",\"value\":1}") + .matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find() + ); + } + + private void assertResponseBodyExists(boolean exists) { + assertEquals( + exists, + Pattern.compile("\\{\"message\":\"message2\",\"value\":2}") + .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + ); + } + + private void executeRetrofitRequest() throws IOException { + ExternalServiceApi api = builder.create(BASE_URL + server.getPort(), ExternalServiceApi.class).build(); + + mockServerRequest(); + + api.postData(new ExternalServiceApi.Payload("message1", 1)).execute(); + } + + private static void mockServerRequest() { + server.mock( + server.requestBuilder(), + server.responseBuilder(200, createPayload()) + ); + } + + private static JSONObject createPayload() { + JSONObject payload = new JSONObject(); + + payload.put("message", "message2"); + payload.put("value", 2); + + return payload; + } +} \ No newline at end of file From f18294cce74d3d5d81fe813de7138b7e215386a7 Mon Sep 17 00:00:00 2001 From: ennoeller Date: Tue, 1 Oct 2024 16:13:59 +0300 Subject: [PATCH 04/14] feature/enable-custom-http-logger-interceptor --- .../core/retrofit/logging/RetrofitLoggingInterceptorTest.java | 1 + 1 file changed, 1 insertion(+) diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java index 7f14ab4..9fcf39d 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java @@ -57,6 +57,7 @@ class RetrofitLoggingInterceptorTest { @BeforeEach void beforeEach() { + context.clear(); context.set("TEST"); logger = (Logger) LoggerFactory.getLogger(RetrofitLoggingInterceptor.class); From d3f7dd8b872887e9279fe65b7774a8da2f824983 Mon Sep 17 00:00:00 2001 From: ennoeller Date: Fri, 11 Oct 2024 12:20:21 +0300 Subject: [PATCH 05/14] feature/enable-custom-http-logger-interceptor --- .../core/retrofit/RetrofitProperties.java | 8 + .../retrofit/builder/RetrofitApiBuilder.java | 27 +- .../builder/SpringAwareRetrofitBuilder.java | 3 + .../retrofit/logging/LoggingInterceptor.java | 9 +- .../logging/RetrofitLoggingInterceptor.java | 262 ++++++++++----- .../RetrofitLoggingInterceptorTest.java | 318 +++++++++++++----- 6 files changed, 461 insertions(+), 166 deletions(-) diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java index 61483e3..b95ddfd 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java @@ -47,7 +47,15 @@ public static class Logging { @NotNull private LoggingLevel level = LoggingLevel.BASIC; + + @NotNull + private Long maxLoggableRequestBodySize = 1024 * 10L; + + @NotNull + private Long maxLoggableResponseBodySize = 1024 * 10L; + private List<@NotBlank String> suppressedHeaders = new ArrayList<>(); + private List<@NotBlank String> redactedBodyUrls = new ArrayList<>(); } @Getter diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java index 68479c0..ee37e95 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java @@ -6,6 +6,7 @@ import ee.bitweb.core.retrofit.logging.LoggingInterceptor; import ee.bitweb.core.retrofit.logging.LoggingLevel; import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptor; +import lombok.Getter; import lombok.extern.slf4j.Slf4j; import okhttp3.Interceptor; import okhttp3.OkHttpClient; @@ -35,6 +36,8 @@ public class RetrofitApiBuilder { private final String url; private final Class definition; + + @Getter private final LoggingInterceptor loggingInterceptor; private Converter.Factory converterFactory; @@ -45,7 +48,7 @@ public static RetrofitApiBuilder create(String baseUrl, Class definiti baseUrl, definition, new RetrofitLoggingInterceptor() - .setLevel(DEFAULT_LOGGING_LEVEL) + .setLoggingLevel(DEFAULT_LOGGING_LEVEL) ); } @@ -107,7 +110,19 @@ public RetrofitApiBuilder replaceAllOfType(Interceptor interceptor) { } public RetrofitApiBuilder loggingLevel(LoggingLevel level) { - loggingInterceptor.setLevel(level); + loggingInterceptor.setLoggingLevel(level); + + return this; + } + + public RetrofitApiBuilder setMaxLoggableRequestBodySize(int size) { + loggingInterceptor.setMaxLoggableRequestSize(size); + + return this; + } + + public RetrofitApiBuilder setMaxLoggableResponseBodySize(int size) { + loggingInterceptor.setMaxLoggableResponseSize(size); return this; } @@ -118,6 +133,12 @@ public RetrofitApiBuilder suppressedHeaders(List headers) { return this; } + public RetrofitApiBuilder bodyRedactedUrls(List urls) { + urls.forEach(loggingInterceptor::addRedactBodyURL); + + return this; + } + public RetrofitApiBuilder addAll(Collection interceptors) { clientBuilder.interceptors().addAll(interceptors); @@ -176,7 +197,7 @@ public T build() { .build().create(definition); } - private OkHttpClient.Builder createDefaultBuilder(Interceptor loggingInterceptor) { + private OkHttpClient.Builder createDefaultBuilder(LoggingInterceptor loggingInterceptor) { var httpClientBuilder = new OkHttpClient.Builder(); httpClientBuilder.interceptors().add(loggingInterceptor); diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java index 193f4ea..1c64bb5 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java @@ -33,6 +33,9 @@ public RetrofitApiBuilder create(String baseUrl, Class definition, Log private RetrofitApiBuilder configure(RetrofitApiBuilder api) { return api.addAll(new ArrayList<>(defaultInterceptors)) .loggingLevel(properties.getLogging().getLevel()) + .setMaxLoggableRequestBodySize(properties.getLogging().getMaxLoggableRequestBodySize().intValue()) + .setMaxLoggableResponseBodySize(properties.getLogging().getMaxLoggableResponseBodySize().intValue()) + .bodyRedactedUrls(properties.getLogging().getRedactedBodyUrls()) .suppressedHeaders(properties.getLogging().getSuppressedHeaders()) .callTimeout(properties.getTimeout().getCall()) .connectTimeout(properties.getTimeout().getConnect()) diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java index 28061a7..3ee9d2b 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java @@ -4,6 +4,13 @@ public interface LoggingInterceptor extends Interceptor { - LoggingInterceptor setLevel(LoggingLevel level); + LoggingInterceptor setLoggingLevel(LoggingLevel level); + + LoggingInterceptor setMaxLoggableRequestSize(int size); + + LoggingInterceptor setMaxLoggableResponseSize(int size); + + LoggingInterceptor addRedactBodyURL(String url); + void redactHeader(String name); } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java index 0132898..2876d1d 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java @@ -5,11 +5,13 @@ import okio.Buffer; import okio.GzipSource; import org.jetbrains.annotations.NotNull; +import org.slf4j.MDC; import java.io.EOFException; import java.io.IOException; import java.nio.charset.Charset; import java.util.*; +import java.util.stream.Collectors; import static java.nio.charset.StandardCharsets.UTF_8; import static java.util.concurrent.TimeUnit.NANOSECONDS; @@ -21,12 +23,56 @@ public class RetrofitLoggingInterceptor implements LoggingInterceptor { private static final String CONTENT_TYPE = "Content-Type"; private static final String CONTENT_LENGTH = "Content-Length"; - private LoggingLevel loggingLevel = LoggingLevel.BASIC; + private static final String REQUEST_METHOD_KEY = "RequestMethod"; + private static final String REQUEST_URL_KEY = "RequestUrl"; + private static final String REQUEST_PROTOCOL_KEY = "RequestProtocol"; + private static final String REQUEST_DURATION_KEY = "RequestDuration"; + private static final String REQUEST_BODY_SIZE_KEY = "RequestBodySize"; + private static final String REQUEST_HEADERS_KEY = "RequestHeaders"; + private static final String REQUEST_BODY_KEY = "RequestBody"; + private static final String RESPONSE_CODE_KEY = "ResponseCode"; + private static final String RESPONSE_MESSAGE_KEY = "ResponseMessage"; + private static final String RESPONSE_BODY_SIZE_KEY = "ResponseBodySize"; + private static final String RESPONSE_HEADERS_KEY = "ResponseHeaders"; + private static final String RESPONSE_BODY_KEY = "ResponseBody"; + + private final List loggingLevel = new ArrayList<>(); private final Set redactHeaders = new HashSet<>(); + private final Set redactBodyUrls = new HashSet<>(); + + private int maxLoggableRequestSize = Integer.MAX_VALUE; + private int maxLoggableResponseSize = Integer.MAX_VALUE; @Override - public LoggingInterceptor setLevel(LoggingLevel level) { - this.loggingLevel = level; + public LoggingInterceptor setLoggingLevel(LoggingLevel level) { + this.loggingLevel.clear(); + + List.of(LoggingLevel.BASIC, LoggingLevel.HEADERS, LoggingLevel.BODY).forEach(option -> { + if (level.getLevel() >= option.getLevel()) { + this.loggingLevel.add(option); + } + }); + + return this; + } + + @Override + public LoggingInterceptor setMaxLoggableRequestSize(int size) { + this.maxLoggableRequestSize = size; + + return this; + } + + @Override + public LoggingInterceptor setMaxLoggableResponseSize(int size) { + this.maxLoggableResponseSize = size; + + return this; + } + + @Override + public LoggingInterceptor addRedactBodyURL(String url) { + this.redactBodyUrls.add(url.toLowerCase()); return this; } @@ -39,88 +85,78 @@ public void redactHeader(String name) { @NotNull @Override public Response intercept(@NotNull Chain chain) throws IOException { - if (loggingLevel.getLevel() == 0) { + if (loggingLevel.isEmpty()) { return chain.proceed(chain.request()); } - var request = chain.request(); - var connection = chain.connection(); + Map container = new HashMap<>(); - try { - StringBuilder sb = new StringBuilder(); - - sb.append(getRequestDescription(request, connection)); - - if (loggingLevel.getLevel() >= 2) { - sb.append("\n").append(getRequestHeaders(request)); - } - - if (loggingLevel.getLevel() >= 3) { - sb.append("\n").append(getRequestBody(request)); - } - - log.info("{}", sb); - } catch (Exception e) { - log.error("Unable to log request.", e); - } + addRequestLogEntries(container, chain); var startNs = System.nanoTime(); Response response; try { - response = chain.proceed(request); + response = chain.proceed(chain.request()); } catch (Exception e) { - log.warn("<-- HTTP FAILED", e); + writeFailedLogMessage(container, e); throw e; } - var durationMs = NANOSECONDS.toMillis(System.nanoTime() - startNs); + container.put(REQUEST_DURATION_KEY, String.valueOf(NANOSECONDS.toMillis(System.nanoTime() - startNs))); - try { - StringBuilder sb = new StringBuilder(); + addResponseLogEntries(container, response); - sb.append(getResponseDescription(response, durationMs)); + writeLogMessage(container); - if (loggingLevel.getLevel() >= 2) { - sb.append("\n").append(getResponseHeaders(response)); - } + return response; + } + + protected void addRequestLogEntries(Map container, Chain chain) { + var request = chain.request(); + var connection = chain.connection(); + + try { + container.put(REQUEST_METHOD_KEY, request.method()); + container.put(REQUEST_PROTOCOL_KEY, connection != null ? connection.protocol().toString() : "-"); + container.put(REQUEST_URL_KEY, request.url().toString()); + container.put(REQUEST_BODY_SIZE_KEY, request.body() != null ? String.valueOf(request.body().contentLength()) : "-"); - if (loggingLevel.getLevel() >= 3) { - sb.append("\n").append(getResponseBody(response)); + if (loggingLevel.contains(LoggingLevel.HEADERS)) { + container.put(REQUEST_HEADERS_KEY, getRequestHeadersString(request)); } - log.info("{}", sb); + if (loggingLevel.contains(LoggingLevel.BODY)) { + container.put(REQUEST_BODY_KEY, getRequestBody(request)); + } } catch (Exception e) { - log.error("Unable to log response", e); + log.error("Unable to log request.", e); } - - return response; } - protected String getRequestDescription(Request request, Connection connection) { - return "--> %s %s%s".formatted(request.method(), request.url(), connection != null ? connection.protocol() : ""); - } + protected void addResponseLogEntries(Map container, Response response) { + try { + container.put(RESPONSE_CODE_KEY, String.valueOf(response.code())); + container.put(RESPONSE_BODY_SIZE_KEY, response.body() != null ? String.valueOf(response.body().contentLength()) : "-"); - protected String getResponseDescription(Response response, long durationMs) { - String bodySize; + if (!response.message().isEmpty()) { + container.put(RESPONSE_MESSAGE_KEY, response.message()); + } - if (response.body() != null && response.body().contentLength() != -1L) { - bodySize = "%s-byte".formatted(response.body().contentLength()); - } else { - bodySize = "unknown length"; - } + if (loggingLevel.contains(LoggingLevel.HEADERS)) { + container.put(RESPONSE_HEADERS_KEY, addResponseHeaders(response)); + } - return "<-- %s%s %s %sms, body size %s".formatted( - response.code(), - response.message().isEmpty() ? "" : " " + response.message(), - response.request().url(), - durationMs, - bodySize - ); + if (loggingLevel.contains(LoggingLevel.BODY)) { + container.put(RESPONSE_BODY_KEY, getResponseBody(response)); + } + } catch (Exception e) { + log.error("Unable to log response", e); + } } - protected String getRequestHeaders(Request request) throws IOException { - List headerRows = new ArrayList<>(); + protected String getRequestHeadersString(Request request) throws IOException { + Map result = new HashMap<>(); var requestHeaders = request.headers(); var requestBody = request.body(); @@ -129,26 +165,26 @@ protected String getRequestHeaders(Request request) throws IOException { String contentLength = getRequestContentLengthValue(requestHeaders, requestBody); if (contentType != null) { - addHeaderToRows(headerRows, CONTENT_TYPE, contentType); + addHeaderToResult(result, CONTENT_TYPE, contentType); } if (contentLength != null) { - addHeaderToRows(headerRows, CONTENT_LENGTH, contentLength); + addHeaderToResult(result, CONTENT_LENGTH, contentLength); } for (int i = 0; i < requestHeaders.size(); i++) { var name = requestHeaders.name(i); - if (List.of("content-type", "content-length").contains(name.toLowerCase())) { + if (CONTENT_TYPE.equalsIgnoreCase(name) || CONTENT_LENGTH.equalsIgnoreCase(name)) { continue; } - addHeaderToRows(headerRows, name, requestHeaders.value(i)); + addHeaderToResult(result, name, requestHeaders.value(i)); } - return headerRowsToString(headerRows); + return writeHeadersMapAsString(result); } - protected String getResponseHeaders(Response response) { - List headerRows = new ArrayList<>(); + protected String addResponseHeaders(Response response) { + Map result = new HashMap<>(); var responseHeaders = response.headers(); var responseBody = response.body(); @@ -157,22 +193,22 @@ protected String getResponseHeaders(Response response) { String contentLength = getResponseContentLengthValue(responseHeaders, responseBody); if (contentType != null) { - addHeaderToRows(headerRows, CONTENT_TYPE, contentType); + addHeaderToResult(result, CONTENT_TYPE, contentType); } if (contentLength != null) { - addHeaderToRows(headerRows, CONTENT_LENGTH, contentLength); + addHeaderToResult(result, CONTENT_LENGTH, contentLength); } for (int i = 0; i < responseHeaders.size(); i++) { var name = responseHeaders.name(i); - if (List.of("content-type", "content-length").contains(name.toLowerCase())) { + if (CONTENT_TYPE.equalsIgnoreCase(name) || CONTENT_LENGTH.equalsIgnoreCase(name)) { continue; } - addHeaderToRows(headerRows, name, responseHeaders.value(i)); + addHeaderToResult(result, name, responseHeaders.value(i)); } - return headerRowsToString(headerRows); + return writeHeadersMapAsString(result); } protected String getRequestContentTypeValue(Headers headers, RequestBody body) { @@ -231,11 +267,8 @@ protected String getResponseContentLengthValue(Headers headers, ResponseBody bod return null; } - protected void addHeaderToRows(List headerRows, String name, String value) { - headerRows.add("\t%s: %s".formatted( - name, - redactHeaders.contains(name.toLowerCase()) ? " " : value - )); + protected void addHeaderToResult(Map result, String name, String value) { + result.put(name, redactHeaders.contains(name.toLowerCase()) ? " " : value); } protected String headerRowsToString(List headerRows) { @@ -252,6 +285,8 @@ protected String getRequestBody(Request request) throws IOException { if (body == null) { return "null"; + } else if (isRedactBodyUrl(request.url().toString())) { + return "(body redacted)"; } else if (bodyHasUnknownEncoding(request.headers())) { return "(encoded body omitted)"; } else if (body.isDuplex()) { @@ -267,7 +302,16 @@ protected String getRequestBody(Request request) throws IOException { if (isProbablyUtf8(buffer)) { assert charSet != null; - return buffer.readString(charSet); + var bodyString = buffer.readString(charSet); + + if (request.body().contentLength() > maxLoggableRequestSize) { + return "%s ... Content size: %s characters".formatted( + bodyString.substring(0, maxLoggableRequestSize), + request.body().contentLength() + ); + } + + return bodyString; } else { return ("binary body omitted"); } @@ -275,7 +319,9 @@ protected String getRequestBody(Request request) throws IOException { } protected String getResponseBody(Response response) throws IOException { - if (!promisesBody(response)) { + if (isRedactBodyUrl(response.request().url().toString())) { + return "(body redacted)"; + } else if (!promisesBody(response)) { return ""; } else if (bodyHasUnknownEncoding(response.headers())) { return "(encoded body omitted)"; @@ -304,13 +350,25 @@ protected String getResponseBody(Response response) throws IOException { } if (contentLength != 0L) { - return buffer.clone().readString(charset); + var bodyString = buffer.clone().readString(charset); + if (contentLength > maxLoggableResponseSize) { + return "%s ... Content size: %s characters".formatted( + bodyString.substring(0, maxLoggableResponseSize), + contentLength + ); + } + + return bodyString; } else { return ""; } } } + protected boolean isRedactBodyUrl(String url) { + return redactBodyUrls.contains(url); + } + protected boolean bodyHasUnknownEncoding(Headers headers) { var contentEncoding = headers.get("Content-Encoding"); @@ -347,4 +405,54 @@ protected boolean isProbablyUtf8(Buffer buffer) { return false; } } + + protected void writeFailedLogMessage(Map container, Exception e) { + Map currentContext = MDC.getCopyOfContextMap(); + + container.forEach(MDC::put); + + log.warn( + "Failed to process request. Method({}), URL({})", + get(container, REQUEST_METHOD_KEY), + get(container, REQUEST_URL_KEY), + e + ); + + if (currentContext != null) { + MDC.setContextMap(currentContext); + } + } + + protected void writeLogMessage(Map container) { + Map currentContext = MDC.getCopyOfContextMap(); + + container.forEach(MDC::put); + + log.info( + "Method({}), URL({}) Status({}) ResponseSize({}) Duration({} ms)", + get(container, REQUEST_METHOD_KEY), + get(container, REQUEST_URL_KEY), + get(container, RESPONSE_CODE_KEY), + get(container, RESPONSE_BODY_SIZE_KEY), + get(container, REQUEST_DURATION_KEY) + ); + + if (currentContext != null) { + MDC.setContextMap(currentContext); + } + } + + protected String get(Map container, String key) { + if (container.containsKey(key)) { + return container.get(key); + } + + return "-"; + } + + protected String writeHeadersMapAsString(Map headersMap) { + return headersMap.entrySet().stream() + .map(entry -> "%s: %s".formatted(entry.getKey(), entry.getValue())) + .collect(Collectors.joining("; ")); + } } diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java index 9fcf39d..2cf5c70 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java @@ -76,6 +76,9 @@ void afterEach() { retrofitProperties.getLogging().setLevel(LoggingLevel.BASIC); retrofitProperties.getLogging().setSuppressedHeaders(new ArrayList<>()); + retrofitProperties.getLogging().getRedactedBodyUrls().clear(); + retrofitProperties.getLogging().setMaxLoggableRequestBodySize(1024 * 10L); + retrofitProperties.getLogging().setMaxLoggableResponseBodySize(1024 * 10L); } @Test @@ -95,17 +98,33 @@ void loggingLevelBasic() throws Exception { executeRetrofitRequest(); - assertEquals(2, memoryAppender.getSize()); + assertEquals(1, memoryAppender.getSize()); - assertRequestLevel(); - assertRequestDescription(); - assertRequestHeaderExists(false); - assertRequestBodyExists(false); + assertLogLevel(); + assertLogMessage(); - assertResponseLevel(); - assertResponseDescription(); - assertResponseHeaderExists(false); - assertResponseBodyExists(false); + assertEquals(9, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); + assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); + assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); + assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); + assertTrue( + Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() + ); + assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() + ); + assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() + ); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() + ); } @Test @@ -115,17 +134,41 @@ void loggingLevelHeaders() throws Exception { executeRetrofitRequest(); - assertEquals(2, memoryAppender.getSize()); + assertEquals(1, memoryAppender.getSize()); - assertRequestLevel(); - assertRequestDescription(); - assertRequestHeaderExists(true); - assertRequestBodyExists(false); + assertLogLevel(); + assertLogMessage(); - assertResponseLevel(); - assertResponseDescription(); - assertResponseHeaderExists(true); - assertResponseBodyExists(false); + assertEquals(11, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); + assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); + assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); + assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); + assertTrue( + Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() + ); + assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() + ); + assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() + ); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() + ); + assertEquals( + "Content-Length: 32; Content-Type: application/json; charset=UTF-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") + ); + assertEquals( + "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") + ); } @Test @@ -135,17 +178,49 @@ void loggingLevelBody() throws Exception { executeRetrofitRequest(); - assertEquals(2, memoryAppender.getSize()); + assertEquals(1, memoryAppender.getSize()); - assertRequestLevel(); - assertRequestDescription(); - assertRequestHeaderExists(true); - assertRequestBodyExists(true); + assertLogLevel(); + assertLogMessage(); - assertResponseLevel(); - assertResponseDescription(); - assertResponseHeaderExists(true); - assertResponseBodyExists(true); + assertEquals(13, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); + assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); + assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); + assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); + assertTrue( + Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() + ); + assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() + ); + assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() + ); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() + ); + assertEquals( + "Content-Length: 32; Content-Type: application/json; charset=UTF-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") + ); + assertEquals( + "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") + ); + assertEquals( + "{\"message\":\"message1\",\"value\":1}", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") + ); + assertEquals( + "{\"message\":\"message2\",\"value\":2}", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") + ); } @Test @@ -156,88 +231,161 @@ void redactHeader() throws Exception { executeRetrofitRequest(); - assertEquals(2, memoryAppender.getSize()); - - logger.info("Request: {}", memoryAppender.getLoggedEvents().get(0).getFormattedMessage()); - logger.info("Response: {}", memoryAppender.getLoggedEvents().get(1).getFormattedMessage()); + assertEquals(1, memoryAppender.getSize()); - assertRequestLevel(); - assertRequestDescription(); - assertRequestHeaderExists(false); - assertRequestBodyExists(false); - assertRequestHeaderRedacted(); + assertLogLevel(); + assertLogMessage(); - assertResponseLevel(); - assertResponseDescription(); - assertResponseHeaderExists(false); - assertResponseBodyExists(false); - assertResponseHeaderRedacted(); + assertEquals(11, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); + assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); + assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); + assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); + assertTrue( + Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() + ); + assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() + ); + assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() + ); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() + ); + assertEquals( + "Content-Length: 32; Content-Type: ", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") + ); + assertEquals( + "connection: keep-alive; Content-Length: 32; Content-Type: ", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") + ); } - private void assertRequestLevel() { - assertEquals(Level.INFO, memoryAppender.getLoggedEvents().get(0).getLevel()); - } + @Test + @DisplayName("Redact body url") + void redactBodyUrl() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.BODY); + retrofitProperties.getLogging().getRedactedBodyUrls().add(BASE_URL + server.getPort() + "/data-post"); - private void assertResponseLevel() { - assertEquals(Level.INFO, memoryAppender.getLoggedEvents().get(1).getLevel()); - } + executeRetrofitRequest(); - private void assertRequestDescription() { - assertTrue(Pattern.compile("--> POST http://localhost:[0-9]*/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find()); - } + assertEquals(1, memoryAppender.getSize()); - private void assertResponseDescription() { - assertTrue(Pattern.compile("<-- 200 OK http://localhost:[0-9]*/data-post [0-9]*ms, body size 32-byte") - .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find()); - } + assertLogLevel(); + assertLogMessage(); - private void assertRequestHeaderExists(boolean exists) { + assertEquals(13, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); + assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); + assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); + assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); + assertTrue( + Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() + ); + assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() + ); + assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() + ); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() + ); assertEquals( - exists, - Pattern.compile("Content-Type: application\\/json; charset=UTF-8") - .matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find() + "Content-Length: 32; Content-Type: application/json; charset=UTF-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") ); - } - - private void assertResponseHeaderExists(boolean exists) { assertEquals( - exists, - Pattern.compile("Content-Type: application\\/json; charset=utf-8") - .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") + ); + assertEquals( + "(body redacted)", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") + ); + assertEquals( + "(body redacted)", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") ); } - private void assertRequestHeaderRedacted() { + @Test + @DisplayName("Limit logged body size") + void limitLoggedBodySize() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.BODY); + retrofitProperties.getLogging().setMaxLoggableRequestBodySize(5L); + retrofitProperties.getLogging().setMaxLoggableResponseBodySize(10L); + + executeRetrofitRequest(); + + assertEquals(1, memoryAppender.getSize()); + + assertLogLevel(); + assertLogMessage(); + + assertEquals(13, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); + assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); + assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); + assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); assertTrue( - Pattern.compile("Content-Type: \n") - .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() ); - } - - private void assertResponseHeaderRedacted() { + assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); assertTrue( - Pattern.compile("Content-Type: \n") - .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() + ); + assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() + ); + assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() ); - } - - private void assertRequestBodyExists(boolean exists) { assertEquals( - exists, - Pattern.compile("\\{\"message\":\"message1\",\"value\":1}") - .matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find() + "Content-Length: 32; Content-Type: application/json; charset=UTF-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") + ); + assertEquals( + "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") + ); + assertEquals( + "{\"mes ... Content size: 32 characters", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") ); - } - - private void assertResponseBodyExists(boolean exists) { assertEquals( - exists, - Pattern.compile("\\{\"message\":\"message2\",\"value\":2}") - .matcher(memoryAppender.getLoggedEvents().get(1).getFormattedMessage()).find() + "{\"message\" ... Content size: 32 characters", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") ); } + private void assertLogLevel() { + assertEquals(Level.INFO, memoryAppender.getLoggedEvents().get(0).getLevel()); + } + + private void assertLogMessage() { + logger.info(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()); + assertTrue(Pattern.compile( + "Method\\(POST\\), URL\\(http:\\/\\/localhost:[0-9]*\\/data-post\\) Status\\(200\\) ResponseSize\\([0-9]*\\) Duration\\([0-9]* ms\\)" + ).matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find()); + } + private void executeRetrofitRequest() throws IOException { ExternalServiceApi api = builder.create(BASE_URL + server.getPort(), ExternalServiceApi.class).build(); From dba785726f38557ee699f904cd01d0fda7ce41a9 Mon Sep 17 00:00:00 2001 From: ennoeller Date: Fri, 18 Oct 2024 15:44:02 +0300 Subject: [PATCH 06/14] feature/enable-custom-http-logger-interceptor --- .../ConditionalOnEnabledRetrofitMapper.java | 49 ++ .../retrofit/RetrofitAutoConfiguration.java | 105 ++++ .../core/retrofit/RetrofitProperties.java | 25 +- .../retrofit/builder/RetrofitApiBuilder.java | 73 +-- .../builder/SpringAwareRetrofitBuilder.java | 12 +- .../retrofit/logging/LoggingInterceptor.java | 16 - .../core/retrofit/logging/LoggingLevel.java | 17 - .../logging/RetrofitLoggingInterceptor.java | 456 +----------------- ...rofitLoggingInterceptorImplementation.java | 45 ++ .../mappers/RetrofitBodyMapperHelper.java | 49 ++ .../mappers/RetrofitHeadersMapperHelper.java | 55 +++ .../mappers/RetrofitLoggingMapper.java | 23 + .../mappers/RetrofitRequestBodyMapper.java | 77 +++ .../RetrofitRequestBodySizeMapper.java | 31 ++ .../mappers/RetrofitRequestHeadersMapper.java | 72 +++ .../mappers/RetrofitRequestMethodMapper.java | 22 + .../RetrofitRequestProtocolMapper.java | 22 + .../mappers/RetrofitRequestUrlMapper.java | 22 + .../mappers/RetrofitResponseBodyMapper.java | 91 ++++ .../RetrofitResponseBodySizeMapper.java | 22 + .../RetrofitResponseHeadersMapper.java | 65 +++ .../RetrofitResponseMessageMapper.java | 22 + .../RetrofitResponseStatusCodeMapper.java | 22 + .../RetrofitLogLoggerWriterAdapter.java | 51 ++ .../writers/RetrofitLogWriteAdapter.java | 8 + .../RetrofitAutoConfigurationTests.java | 2 + .../core/retrofit/RetrofitExecutorTests.java | 10 +- .../builder/RetrofitApiBuilderTests.java | 47 +- .../helpers/RetrofitConfiguration.java | 4 +- .../helpers/RetrofitLogTestWriter.java | 25 + .../interceptor/TraceIdInterceptorTests.java | 9 +- .../auth/AuthTokenInjectInterceptorTests.java | 7 +- .../RetrofitLoggingInterceptorTest.java | 252 +--------- 33 files changed, 978 insertions(+), 830 deletions(-) create mode 100644 src/main/java/ee/bitweb/core/retrofit/ConditionalOnEnabledRetrofitMapper.java delete mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java delete mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitBodyMapperHelper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitHeadersMapperHelper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogWriteAdapter.java create mode 100644 src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitLogTestWriter.java diff --git a/src/main/java/ee/bitweb/core/retrofit/ConditionalOnEnabledRetrofitMapper.java b/src/main/java/ee/bitweb/core/retrofit/ConditionalOnEnabledRetrofitMapper.java new file mode 100644 index 0000000..a4b2a9e --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/ConditionalOnEnabledRetrofitMapper.java @@ -0,0 +1,49 @@ +package ee.bitweb.core.retrofit; + +import ee.bitweb.core.exception.CoreException; +import org.springframework.boot.context.properties.bind.Binder; +import org.springframework.context.annotation.Condition; +import org.springframework.context.annotation.ConditionContext; +import org.springframework.context.annotation.Conditional; +import org.springframework.core.type.AnnotatedTypeMetadata; + +import java.lang.annotation.ElementType; +import java.lang.annotation.Retention; +import java.lang.annotation.RetentionPolicy; +import java.lang.annotation.Target; +import java.util.Map; + +@Target({ElementType.METHOD, ElementType.TYPE}) +@Retention(RetentionPolicy.RUNTIME) +@Conditional(value = ConditionalOnEnabledRetrofitMapper.MapperEnabled.class) +public @interface ConditionalOnEnabledRetrofitMapper { + + String mapper(); + + class MapperEnabled implements Condition { + + @Override + public boolean matches(ConditionContext context, AnnotatedTypeMetadata metadata) { + Map attributes = metadata.getAnnotationAttributes( + ConditionalOnEnabledRetrofitMapper.class.getName() + ); + if (attributes == null) return false; + + Object mapperKeyOb = attributes.get("mapper"); + + if (mapperKeyOb == null) return false; + + String mapperKey = (String) mapperKeyOb; + + RetrofitProperties config = Binder.get( + context.getEnvironment() + ).bind( + RetrofitProperties.PREFIX, RetrofitProperties.class + ).orElseThrow( + () -> new CoreException("Error occurred while trying to bind environment to RetrofitProperties") + ); + + return config.getLogging().getMappers().contains(mapperKey); + } + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java index 9c3f3b7..ea18615 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java @@ -5,16 +5,23 @@ import ee.bitweb.core.retrofit.interceptor.auth.TokenProvider; import ee.bitweb.core.retrofit.interceptor.auth.criteria.AuthTokenCriteria; import ee.bitweb.core.retrofit.interceptor.auth.criteria.WhitelistCriteria; +import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptor; +import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptorImplementation; +import ee.bitweb.core.retrofit.logging.mappers.*; +import ee.bitweb.core.retrofit.logging.writers.RetrofitLogLoggerWriterAdapter; import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; import org.springframework.boot.autoconfigure.condition.ConditionalOnMissingBean; import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; +import org.springframework.boot.context.properties.EnableConfigurationProperties; import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.Configuration; +import org.springframework.context.annotation.Primary; import retrofit2.Converter; import retrofit2.converter.jackson.JacksonConverterFactory; import java.util.ArrayList; +import java.util.HashSet; import java.util.List; import java.util.regex.Pattern; @@ -22,6 +29,7 @@ @Configuration @RequiredArgsConstructor @ConditionalOnProperty(value = RetrofitProperties.PREFIX + ".auto-configuration", havingValue = "true") +@EnableConfigurationProperties({RetrofitProperties.class}) public class RetrofitAutoConfiguration { @Bean @@ -64,4 +72,101 @@ public AuthTokenCriteria defaultCriteria(RetrofitProperties properties) { return criteria; } + + @Bean("defaultRetrofitLoggingInterceptor") + @Primary + public RetrofitLoggingInterceptor defaultRetrofitLoggingInterceptor( + List mappers + ) { + log.info( + "Create Default Retrofit Logging Interceptor with writer {}", + RetrofitLogLoggerWriterAdapter.class.getSimpleName() + ); + + for (RetrofitLoggingMapper mapper : mappers) { + log.info("Applying Retrofit Log Data Mapper: {}", mapper.getClass()); + } + + return new RetrofitLoggingInterceptorImplementation(mappers, new RetrofitLogLoggerWriterAdapter()); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestMethodMapper.KEY) + public RetrofitRequestMethodMapper retrofitRequestMethodMapper() { + return new RetrofitRequestMethodMapper(); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestProtocolMapper.KEY) + public RetrofitRequestProtocolMapper retrofitRequestProtocolMapper() { + return new RetrofitRequestProtocolMapper(); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestUrlMapper.KEY) + public RetrofitRequestUrlMapper retrofitRequestUrlMapper() { + return new RetrofitRequestUrlMapper(); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestHeadersMapper.KEY) + public RetrofitRequestHeadersMapper retrofitRequestHeadersMapper( + RetrofitProperties retrofitProperties + ) { + return new RetrofitRequestHeadersMapper(new HashSet<>(retrofitProperties.getLogging().getSuppressedHeaders())); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestBodySizeMapper.KEY) + public RetrofitRequestBodySizeMapper retrofitRequestBodySizeMapper() { + return new RetrofitRequestBodySizeMapper(); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestBodyMapper.KEY) + public RetrofitRequestBodyMapper retrofitRequestBodyMapper( + RetrofitProperties retrofitProperties + ) { + return new RetrofitRequestBodyMapper( + retrofitProperties.getLogging().getMaxLoggableRequestBodySize().intValue(), + new HashSet<>(retrofitProperties.getLogging().getRedactedBodyUrls()) + ); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseStatusCodeMapper.KEY) + public RetrofitResponseStatusCodeMapper retrofitResponseStatusCodeMapper() { + return new RetrofitResponseStatusCodeMapper(); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseMessageMapper.KEY) + public RetrofitResponseMessageMapper retrofitResponseMessageMapper() { + return new RetrofitResponseMessageMapper(); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseHeadersMapper.KEY) + public RetrofitResponseHeadersMapper retrofitResponseHeadersMapper( + RetrofitProperties retrofitProperties + ) { + return new RetrofitResponseHeadersMapper(new HashSet<>(retrofitProperties.getLogging().getSuppressedHeaders())); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseBodySizeMapper.KEY) + public RetrofitResponseBodySizeMapper retrofitResponseBodySizeMapper() { + return new RetrofitResponseBodySizeMapper(); + } + + @Bean + @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseBodyMapper.KEY) + public RetrofitResponseBodyMapper responseBodyMapper( + RetrofitProperties retrofitProperties + ) { + return new RetrofitResponseBodyMapper( + new HashSet<>(retrofitProperties.getLogging().getRedactedBodyUrls()), + retrofitProperties.getLogging().getMaxLoggableResponseBodySize().intValue() + ); + } } diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java index b95ddfd..5702fd1 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java @@ -1,6 +1,6 @@ package ee.bitweb.core.retrofit; -import ee.bitweb.core.retrofit.logging.LoggingLevel; +import ee.bitweb.core.retrofit.logging.mappers.*; import jakarta.validation.Valid; import jakarta.validation.constraints.AssertTrue; import jakarta.validation.constraints.NotBlank; @@ -10,16 +10,15 @@ import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; import org.springframework.boot.context.properties.ConfigurationProperties; import org.springframework.http.HttpHeaders; -import org.springframework.stereotype.Component; import org.springframework.util.StringUtils; import org.springframework.validation.annotation.Validated; import java.util.ArrayList; +import java.util.Arrays; import java.util.List; import static ee.bitweb.core.retrofit.RetrofitProperties.PREFIX; -@Component @Setter @Getter @Validated @@ -45,9 +44,6 @@ public class RetrofitProperties { @Validated public static class Logging { - @NotNull - private LoggingLevel level = LoggingLevel.BASIC; - @NotNull private Long maxLoggableRequestBodySize = 1024 * 10L; @@ -56,6 +52,23 @@ public static class Logging { private List<@NotBlank String> suppressedHeaders = new ArrayList<>(); private List<@NotBlank String> redactedBodyUrls = new ArrayList<>(); + + @NotNull + private List<@NotBlank String> mappers = new ArrayList<>( + Arrays.asList( + RetrofitRequestMethodMapper.KEY, + RetrofitRequestProtocolMapper.KEY, + RetrofitRequestUrlMapper.KEY, + RetrofitRequestHeadersMapper.KEY, + RetrofitRequestBodySizeMapper.KEY, + RetrofitRequestBodyMapper.KEY, + RetrofitResponseStatusCodeMapper.KEY, + RetrofitResponseMessageMapper.KEY, + RetrofitResponseHeadersMapper.KEY, + RetrofitResponseBodySizeMapper.KEY, + RetrofitResponseBodyMapper.KEY + ) + ); } @Getter diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java index ee37e95..5f2b6b2 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java @@ -3,10 +3,8 @@ import com.fasterxml.jackson.databind.DeserializationFeature; import com.fasterxml.jackson.databind.ObjectMapper; import com.fasterxml.jackson.datatype.jsr310.JavaTimeModule; -import ee.bitweb.core.retrofit.logging.LoggingInterceptor; -import ee.bitweb.core.retrofit.logging.LoggingLevel; +import ee.bitweb.core.exception.CoreException; import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptor; -import lombok.Getter; import lombok.extern.slf4j.Slf4j; import okhttp3.Interceptor; import okhttp3.OkHttpClient; @@ -23,7 +21,6 @@ public class RetrofitApiBuilder { public static final ObjectMapper DEFAULT_OBJECT_MAPPER = new ObjectMapper(); - public static final LoggingLevel DEFAULT_LOGGING_LEVEL = LoggingLevel.BASIC; static { DEFAULT_OBJECT_MAPPER.registerModule(new JavaTimeModule()) @@ -37,22 +34,10 @@ public class RetrofitApiBuilder { private final String url; private final Class definition; - @Getter - private final LoggingInterceptor loggingInterceptor; - private Converter.Factory converterFactory; private OkHttpClient.Builder clientBuilder; - public static RetrofitApiBuilder create(String baseUrl, Class definition) { - return new RetrofitApiBuilder<>( - baseUrl, - definition, - new RetrofitLoggingInterceptor() - .setLoggingLevel(DEFAULT_LOGGING_LEVEL) - ); - } - - public static RetrofitApiBuilder create(String baseUrl, Class definition, LoggingInterceptor loggingInterceptor) { + public static RetrofitApiBuilder create(String baseUrl, Class definition, RetrofitLoggingInterceptor loggingInterceptor) { return new RetrofitApiBuilder<>( baseUrl, definition, @@ -60,10 +45,9 @@ public static RetrofitApiBuilder create(String baseUrl, Class definiti ); } - private RetrofitApiBuilder(String url, Class definition, LoggingInterceptor loggingInterceptor) { + private RetrofitApiBuilder(String url, Class definition, RetrofitLoggingInterceptor loggingInterceptor) { this.url = url; this.definition = definition; - this.loggingInterceptor = loggingInterceptor; clientBuilder = createDefaultBuilder(loggingInterceptor); } @@ -109,36 +93,6 @@ public RetrofitApiBuilder replaceAllOfType(Interceptor interceptor) { return this; } - public RetrofitApiBuilder loggingLevel(LoggingLevel level) { - loggingInterceptor.setLoggingLevel(level); - - return this; - } - - public RetrofitApiBuilder setMaxLoggableRequestBodySize(int size) { - loggingInterceptor.setMaxLoggableRequestSize(size); - - return this; - } - - public RetrofitApiBuilder setMaxLoggableResponseBodySize(int size) { - loggingInterceptor.setMaxLoggableResponseSize(size); - - return this; - } - - public RetrofitApiBuilder suppressedHeaders(List headers) { - headers.forEach(loggingInterceptor::redactHeader); - - return this; - } - - public RetrofitApiBuilder bodyRedactedUrls(List urls) { - urls.forEach(loggingInterceptor::addRedactBodyURL); - - return this; - } - public RetrofitApiBuilder addAll(Collection interceptors) { clientBuilder.interceptors().addAll(interceptors); @@ -189,6 +143,20 @@ public T build() { url, definition.getName(), clientBuilder.interceptors(), factory ); + if (clientBuilder.interceptors().stream().filter(RetrofitLoggingInterceptor.class::isInstance).toList().size() > 1) { + throw new CoreException("Multiple logging interceptors detected at build."); + } + + clientBuilder.interceptors().sort((i1, i2) -> { + if (i1 instanceof RetrofitLoggingInterceptor) { + return -1; + } else if (i2 instanceof RetrofitLoggingInterceptor) { + return 1; + } else { + return 0; + } + }); + return new Retrofit .Builder() .baseUrl(url) @@ -197,9 +165,12 @@ public T build() { .build().create(definition); } - private OkHttpClient.Builder createDefaultBuilder(LoggingInterceptor loggingInterceptor) { + private OkHttpClient.Builder createDefaultBuilder(RetrofitLoggingInterceptor loggingInterceptor) { var httpClientBuilder = new OkHttpClient.Builder(); - httpClientBuilder.interceptors().add(loggingInterceptor); + + if (loggingInterceptor != null) { + httpClientBuilder.interceptors().add(loggingInterceptor); + } return httpClientBuilder; } diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java index 1c64bb5..ff199e8 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/SpringAwareRetrofitBuilder.java @@ -2,7 +2,7 @@ import ee.bitweb.core.retrofit.RetrofitProperties; import ee.bitweb.core.retrofit.interceptor.InterceptorBean; -import ee.bitweb.core.retrofit.logging.LoggingInterceptor; +import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptor; import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; @@ -21,22 +21,18 @@ public class SpringAwareRetrofitBuilder { private final List defaultInterceptors; private final Converter.Factory defaultConverterFactory; private final RetrofitProperties properties; + private final RetrofitLoggingInterceptor defaultLoggingInterceptor; public RetrofitApiBuilder create(String baseUrl, Class definition) { - return configure(RetrofitApiBuilder.create(baseUrl, definition)); + return configure(RetrofitApiBuilder.create(baseUrl, definition, defaultLoggingInterceptor)); } - public RetrofitApiBuilder create(String baseUrl, Class definition, LoggingInterceptor loggingInterceptor) { + public RetrofitApiBuilder create(String baseUrl, Class definition, RetrofitLoggingInterceptor loggingInterceptor) { return configure(RetrofitApiBuilder.create(baseUrl, definition, loggingInterceptor)); } private RetrofitApiBuilder configure(RetrofitApiBuilder api) { return api.addAll(new ArrayList<>(defaultInterceptors)) - .loggingLevel(properties.getLogging().getLevel()) - .setMaxLoggableRequestBodySize(properties.getLogging().getMaxLoggableRequestBodySize().intValue()) - .setMaxLoggableResponseBodySize(properties.getLogging().getMaxLoggableResponseBodySize().intValue()) - .bodyRedactedUrls(properties.getLogging().getRedactedBodyUrls()) - .suppressedHeaders(properties.getLogging().getSuppressedHeaders()) .callTimeout(properties.getTimeout().getCall()) .connectTimeout(properties.getTimeout().getConnect()) .readTimeout(properties.getTimeout().getRead()) diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java deleted file mode 100644 index 3ee9d2b..0000000 --- a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingInterceptor.java +++ /dev/null @@ -1,16 +0,0 @@ -package ee.bitweb.core.retrofit.logging; - -import okhttp3.Interceptor; - -public interface LoggingInterceptor extends Interceptor { - - LoggingInterceptor setLoggingLevel(LoggingLevel level); - - LoggingInterceptor setMaxLoggableRequestSize(int size); - - LoggingInterceptor setMaxLoggableResponseSize(int size); - - LoggingInterceptor addRedactBodyURL(String url); - - void redactHeader(String name); -} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java b/src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java deleted file mode 100644 index c302912..0000000 --- a/src/main/java/ee/bitweb/core/retrofit/logging/LoggingLevel.java +++ /dev/null @@ -1,17 +0,0 @@ -package ee.bitweb.core.retrofit.logging; - -import lombok.AccessLevel; -import lombok.AllArgsConstructor; -import lombok.Getter; - -@AllArgsConstructor(access = AccessLevel.PRIVATE) -public enum LoggingLevel { - - NONE(0), - BASIC(1), - HEADERS(2), - BODY(3); - - @Getter(AccessLevel.PACKAGE) - private int level; -} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java index 2876d1d..716e2e0 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptor.java @@ -1,458 +1,6 @@ package ee.bitweb.core.retrofit.logging; -import lombok.extern.slf4j.Slf4j; -import okhttp3.*; -import okio.Buffer; -import okio.GzipSource; -import org.jetbrains.annotations.NotNull; -import org.slf4j.MDC; +import okhttp3.Interceptor; -import java.io.EOFException; -import java.io.IOException; -import java.nio.charset.Charset; -import java.util.*; -import java.util.stream.Collectors; - -import static java.nio.charset.StandardCharsets.UTF_8; -import static java.util.concurrent.TimeUnit.NANOSECONDS; -import static okhttp3.internal.http.HttpHeaders.promisesBody; - -@Slf4j -public class RetrofitLoggingInterceptor implements LoggingInterceptor { - - private static final String CONTENT_TYPE = "Content-Type"; - private static final String CONTENT_LENGTH = "Content-Length"; - - private static final String REQUEST_METHOD_KEY = "RequestMethod"; - private static final String REQUEST_URL_KEY = "RequestUrl"; - private static final String REQUEST_PROTOCOL_KEY = "RequestProtocol"; - private static final String REQUEST_DURATION_KEY = "RequestDuration"; - private static final String REQUEST_BODY_SIZE_KEY = "RequestBodySize"; - private static final String REQUEST_HEADERS_KEY = "RequestHeaders"; - private static final String REQUEST_BODY_KEY = "RequestBody"; - private static final String RESPONSE_CODE_KEY = "ResponseCode"; - private static final String RESPONSE_MESSAGE_KEY = "ResponseMessage"; - private static final String RESPONSE_BODY_SIZE_KEY = "ResponseBodySize"; - private static final String RESPONSE_HEADERS_KEY = "ResponseHeaders"; - private static final String RESPONSE_BODY_KEY = "ResponseBody"; - - private final List loggingLevel = new ArrayList<>(); - private final Set redactHeaders = new HashSet<>(); - private final Set redactBodyUrls = new HashSet<>(); - - private int maxLoggableRequestSize = Integer.MAX_VALUE; - private int maxLoggableResponseSize = Integer.MAX_VALUE; - - @Override - public LoggingInterceptor setLoggingLevel(LoggingLevel level) { - this.loggingLevel.clear(); - - List.of(LoggingLevel.BASIC, LoggingLevel.HEADERS, LoggingLevel.BODY).forEach(option -> { - if (level.getLevel() >= option.getLevel()) { - this.loggingLevel.add(option); - } - }); - - return this; - } - - @Override - public LoggingInterceptor setMaxLoggableRequestSize(int size) { - this.maxLoggableRequestSize = size; - - return this; - } - - @Override - public LoggingInterceptor setMaxLoggableResponseSize(int size) { - this.maxLoggableResponseSize = size; - - return this; - } - - @Override - public LoggingInterceptor addRedactBodyURL(String url) { - this.redactBodyUrls.add(url.toLowerCase()); - - return this; - } - - @Override - public void redactHeader(String name) { - this.redactHeaders.add(name.toLowerCase()); - } - - @NotNull - @Override - public Response intercept(@NotNull Chain chain) throws IOException { - if (loggingLevel.isEmpty()) { - return chain.proceed(chain.request()); - } - - Map container = new HashMap<>(); - - addRequestLogEntries(container, chain); - - var startNs = System.nanoTime(); - - Response response; - try { - response = chain.proceed(chain.request()); - } catch (Exception e) { - writeFailedLogMessage(container, e); - throw e; - } - - container.put(REQUEST_DURATION_KEY, String.valueOf(NANOSECONDS.toMillis(System.nanoTime() - startNs))); - - addResponseLogEntries(container, response); - - writeLogMessage(container); - - return response; - } - - protected void addRequestLogEntries(Map container, Chain chain) { - var request = chain.request(); - var connection = chain.connection(); - - try { - container.put(REQUEST_METHOD_KEY, request.method()); - container.put(REQUEST_PROTOCOL_KEY, connection != null ? connection.protocol().toString() : "-"); - container.put(REQUEST_URL_KEY, request.url().toString()); - container.put(REQUEST_BODY_SIZE_KEY, request.body() != null ? String.valueOf(request.body().contentLength()) : "-"); - - if (loggingLevel.contains(LoggingLevel.HEADERS)) { - container.put(REQUEST_HEADERS_KEY, getRequestHeadersString(request)); - } - - if (loggingLevel.contains(LoggingLevel.BODY)) { - container.put(REQUEST_BODY_KEY, getRequestBody(request)); - } - } catch (Exception e) { - log.error("Unable to log request.", e); - } - } - - protected void addResponseLogEntries(Map container, Response response) { - try { - container.put(RESPONSE_CODE_KEY, String.valueOf(response.code())); - container.put(RESPONSE_BODY_SIZE_KEY, response.body() != null ? String.valueOf(response.body().contentLength()) : "-"); - - if (!response.message().isEmpty()) { - container.put(RESPONSE_MESSAGE_KEY, response.message()); - } - - if (loggingLevel.contains(LoggingLevel.HEADERS)) { - container.put(RESPONSE_HEADERS_KEY, addResponseHeaders(response)); - } - - if (loggingLevel.contains(LoggingLevel.BODY)) { - container.put(RESPONSE_BODY_KEY, getResponseBody(response)); - } - } catch (Exception e) { - log.error("Unable to log response", e); - } - } - - protected String getRequestHeadersString(Request request) throws IOException { - Map result = new HashMap<>(); - - var requestHeaders = request.headers(); - var requestBody = request.body(); - - String contentType = getRequestContentTypeValue(requestHeaders, requestBody); - String contentLength = getRequestContentLengthValue(requestHeaders, requestBody); - - if (contentType != null) { - addHeaderToResult(result, CONTENT_TYPE, contentType); - } - - if (contentLength != null) { - addHeaderToResult(result, CONTENT_LENGTH, contentLength); - } - - for (int i = 0; i < requestHeaders.size(); i++) { - var name = requestHeaders.name(i); - if (CONTENT_TYPE.equalsIgnoreCase(name) || CONTENT_LENGTH.equalsIgnoreCase(name)) { - continue; - } - addHeaderToResult(result, name, requestHeaders.value(i)); - } - - return writeHeadersMapAsString(result); - } - - protected String addResponseHeaders(Response response) { - Map result = new HashMap<>(); - - var responseHeaders = response.headers(); - var responseBody = response.body(); - - String contentType = getResponseContentTypeValue(responseHeaders, responseBody); - String contentLength = getResponseContentLengthValue(responseHeaders, responseBody); - - if (contentType != null) { - addHeaderToResult(result, CONTENT_TYPE, contentType); - } - - if (contentLength != null) { - addHeaderToResult(result, CONTENT_LENGTH, contentLength); - } - - for (int i = 0; i < responseHeaders.size(); i++) { - var name = responseHeaders.name(i); - if (CONTENT_TYPE.equalsIgnoreCase(name) || CONTENT_LENGTH.equalsIgnoreCase(name)) { - continue; - } - addHeaderToResult(result, name, responseHeaders.value(i)); - } - - return writeHeadersMapAsString(result); - } - - protected String getRequestContentTypeValue(Headers headers, RequestBody body) { - var headerValue = headers.get(CONTENT_TYPE); - - if (headerValue != null) { - return headerValue; - } - - if (body != null && body.contentType() != null) { - return Objects.requireNonNullElse(body.contentType(), "").toString(); - } - - return null; - } - - protected String getRequestContentLengthValue(Headers headers, RequestBody body) throws IOException { - var headerValue = headers.get(CONTENT_LENGTH); - - if (headerValue != null) { - return headerValue; - } - - if (body != null && body.contentLength() != -1) { - return String.valueOf(body.contentLength()); - } - - return null; - } - - protected String getResponseContentTypeValue(Headers headers, ResponseBody body) { - var headerValue = headers.get(CONTENT_TYPE); - - if (headerValue != null) { - return headerValue; - } - - if (body != null && body.contentType() != null) { - return Objects.requireNonNullElse(body.contentType(), "").toString(); - } - - return null; - } - - protected String getResponseContentLengthValue(Headers headers, ResponseBody body) { - var headerValue = headers.get(CONTENT_LENGTH); - - if (headerValue != null) { - return headerValue; - } - - if (body != null && body.contentLength() != -1) { - return String.valueOf(body.contentLength()); - } - - return null; - } - - protected void addHeaderToResult(Map result, String name, String value) { - result.put(name, redactHeaders.contains(name.toLowerCase()) ? " " : value); - } - - protected String headerRowsToString(List headerRows) { - StringBuilder sb = new StringBuilder() - .append("Headers:"); - - headerRows.forEach(row -> sb.append("\n").append(row)); - - return sb.toString(); - } - - protected String getRequestBody(Request request) throws IOException { - var body = request.body(); - - if (body == null) { - return "null"; - } else if (isRedactBodyUrl(request.url().toString())) { - return "(body redacted)"; - } else if (bodyHasUnknownEncoding(request.headers())) { - return "(encoded body omitted)"; - } else if (body.isDuplex()) { - return "(duplex request body omitted)"; - } else if (body.isOneShot()) { - return "(one-shot body omitted)"; - } else { - var buffer = new Buffer(); - body.writeTo(buffer); - - var contentType = body.contentType(); - Charset charSet = contentType != null ? contentType.charset(UTF_8) : UTF_8; - - if (isProbablyUtf8(buffer)) { - assert charSet != null; - var bodyString = buffer.readString(charSet); - - if (request.body().contentLength() > maxLoggableRequestSize) { - return "%s ... Content size: %s characters".formatted( - bodyString.substring(0, maxLoggableRequestSize), - request.body().contentLength() - ); - } - - return bodyString; - } else { - return ("binary body omitted"); - } - } - } - - protected String getResponseBody(Response response) throws IOException { - if (isRedactBodyUrl(response.request().url().toString())) { - return "(body redacted)"; - } else if (!promisesBody(response)) { - return ""; - } else if (bodyHasUnknownEncoding(response.headers())) { - return "(encoded body omitted)"; - } else if (response.body() == null) { - return "(body missing)"; - } else { - var responseBody = response.body(); - var contentType = responseBody.contentType(); - var contentLength = responseBody.contentLength(); - var charset = contentType != null ? contentType.charset(UTF_8) : UTF_8; - - var source = responseBody.source(); - source.request(Long.MAX_VALUE); - var buffer = source.getBuffer(); - - Long gzippedLength = null; - if ("gzip".equalsIgnoreCase(response.header("Content-Encoding"))) { - gzippedLength = buffer.size(); - var gzipSource = new GzipSource(buffer.clone()); - buffer = new Buffer(); - gzipSource.read(buffer, gzippedLength); - } - - if (!isProbablyUtf8(buffer)) { - return "(binary %s-byte body omitted)".formatted(buffer.size()); - } - - if (contentLength != 0L) { - var bodyString = buffer.clone().readString(charset); - if (contentLength > maxLoggableResponseSize) { - return "%s ... Content size: %s characters".formatted( - bodyString.substring(0, maxLoggableResponseSize), - contentLength - ); - } - - return bodyString; - } else { - return ""; - } - } - } - - protected boolean isRedactBodyUrl(String url) { - return redactBodyUrls.contains(url); - } - - protected boolean bodyHasUnknownEncoding(Headers headers) { - var contentEncoding = headers.get("Content-Encoding"); - - if (contentEncoding == null) { - return false; - } - - return !contentEncoding.equalsIgnoreCase("identity") && - !contentEncoding.equalsIgnoreCase("gzip"); - } - - protected boolean isProbablyUtf8(Buffer buffer) { - try { - var prefix = new Buffer(); - var byteCount = buffer.size() > 64 ? 64 : buffer.size(); - - buffer.copyTo(prefix, 0, byteCount); - - for (int i = 0; i < 16; i++) { - if (prefix.exhausted()) { - break; - } - - var codePoint = prefix.readUtf8CodePoint(); - - if (Character.isISOControl(codePoint) && !Character.isWhitespace(codePoint)) { - return false; - } - } - - return true; - } catch (EOFException e) { - log.trace("", e); - return false; - } - } - - protected void writeFailedLogMessage(Map container, Exception e) { - Map currentContext = MDC.getCopyOfContextMap(); - - container.forEach(MDC::put); - - log.warn( - "Failed to process request. Method({}), URL({})", - get(container, REQUEST_METHOD_KEY), - get(container, REQUEST_URL_KEY), - e - ); - - if (currentContext != null) { - MDC.setContextMap(currentContext); - } - } - - protected void writeLogMessage(Map container) { - Map currentContext = MDC.getCopyOfContextMap(); - - container.forEach(MDC::put); - - log.info( - "Method({}), URL({}) Status({}) ResponseSize({}) Duration({} ms)", - get(container, REQUEST_METHOD_KEY), - get(container, REQUEST_URL_KEY), - get(container, RESPONSE_CODE_KEY), - get(container, RESPONSE_BODY_SIZE_KEY), - get(container, REQUEST_DURATION_KEY) - ); - - if (currentContext != null) { - MDC.setContextMap(currentContext); - } - } - - protected String get(Map container, String key) { - if (container.containsKey(key)) { - return container.get(key); - } - - return "-"; - } - - protected String writeHeadersMapAsString(Map headersMap) { - return headersMap.entrySet().stream() - .map(entry -> "%s: %s".formatted(entry.getKey(), entry.getValue())) - .collect(Collectors.joining("; ")); - } +public interface RetrofitLoggingInterceptor extends Interceptor { } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java new file mode 100644 index 0000000..4122923 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java @@ -0,0 +1,45 @@ +package ee.bitweb.core.retrofit.logging; + +import ee.bitweb.core.retrofit.logging.mappers.RetrofitLoggingMapper; +import ee.bitweb.core.retrofit.logging.writers.RetrofitLogWriteAdapter; +import lombok.RequiredArgsConstructor; +import okhttp3.Request; +import okhttp3.Response; +import org.jetbrains.annotations.NotNull; + +import java.io.IOException; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +@RequiredArgsConstructor +public class RetrofitLoggingInterceptorImplementation implements RetrofitLoggingInterceptor { + + public static final String DURATION_KEY = "Duration"; + + private final List mappers; + private final RetrofitLogWriteAdapter writer; + + @NotNull + @Override + public Response intercept(@NotNull Chain chain) throws IOException { + Map container = new HashMap<>(); + + var start = System.currentTimeMillis(); + + Response response = null; + try { + response = chain.proceed(chain.request()); + container.put(DURATION_KEY, String.valueOf(System.currentTimeMillis() - start)); + } finally { + Response finalResponse = response; + + Request request = finalResponse != null ? finalResponse.request() : chain.request(); + mappers.forEach(mapper -> mapper.map(chain.connection(), request, finalResponse, container)); + + writer.write(container); + } + + return response; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitBodyMapperHelper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitBodyMapperHelper.java new file mode 100644 index 0000000..eba1e8b --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitBodyMapperHelper.java @@ -0,0 +1,49 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.AccessLevel; +import lombok.NoArgsConstructor; +import okhttp3.Headers; +import okio.Buffer; + +import java.io.IOException; +import java.util.Set; + +@NoArgsConstructor(access = AccessLevel.PRIVATE) +public final class RetrofitBodyMapperHelper { + + public static boolean isProbablyUtf8(Buffer buffer) throws IOException { + var prefix = new Buffer(); + var byteCount = buffer.size() > 64 ? 64 : buffer.size(); + + buffer.copyTo(prefix, 0, byteCount); + + for (int i = 0; i < 16; i++) { + if (prefix.exhausted()) { + break; + } + + var codePoint = prefix.readUtf8CodePoint(); + + if (Character.isISOControl(codePoint) && !Character.isWhitespace(codePoint)) { + return false; + } + } + + return true; + } + + public static boolean bodyHasUnknownEncoding(Headers headers) { + var contentEncoding = headers.get("Content-Encoding"); + + if (contentEncoding == null) { + return false; + } + + return !contentEncoding.equalsIgnoreCase("identity") && + !contentEncoding.equalsIgnoreCase("gzip"); + } + + public static boolean isRedactBodyUrl(Set redactBodyUrls, String url) { + return redactBodyUrls.contains(url); + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitHeadersMapperHelper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitHeadersMapperHelper.java new file mode 100644 index 0000000..b0c0bc5 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitHeadersMapperHelper.java @@ -0,0 +1,55 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.AccessLevel; +import lombok.NoArgsConstructor; +import okhttp3.Headers; +import okhttp3.MediaType; + +import java.util.Map; +import java.util.Set; +import java.util.stream.Collectors; + +@NoArgsConstructor(access = AccessLevel.PRIVATE) +public final class RetrofitHeadersMapperHelper { + + public static final String CONTENT_TYPE = "Content-Type"; + public static final String CONTENT_LENGTH = "Content-Length"; + + public static String writeHeadersMapAsString(Map headersMap) { + return headersMap.entrySet().stream() + .map(entry -> "%s: %s".formatted(entry.getKey(), entry.getValue())) + .collect(Collectors.joining("; ")); + } + + public static void addHeaderToResult(Set redactHeaders, Map result, String name, String value) { + result.put(name, redactHeaders.contains(name.toLowerCase()) ? " " : value); + } + + public static String getContentTypeValue(Headers headers, MediaType mediaType) { + var headerValue = headers.get(CONTENT_TYPE); + + if (headerValue != null) { + return headerValue; + } + + if (mediaType == null) { + return null; + } + + return mediaType.type(); + } + + public static String getContentLengthValue(Headers headers, Long contentLength) { + var headerValue = headers.get(CONTENT_LENGTH); + + if (headerValue != null) { + return headerValue; + } + + if (contentLength != null && contentLength != -1) { + return String.valueOf(contentLength); + } + + return null; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java new file mode 100644 index 0000000..4841b4b --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java @@ -0,0 +1,23 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import ee.bitweb.core.exception.CoreException; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +import java.util.Map; + +public interface RetrofitLoggingMapper { + + String getValue(Connection connection, Request request, Response response); + + String getKey(); + + default void map(Connection connection, Request request, Response response, Map container) { + if (container.containsKey(getKey())) { + throw new CoreException(String.format("Retrofit log container already contains value for key %s", getKey())); + } + + container.put(getKey(), getValue(connection, request, response)); + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java new file mode 100644 index 0000000..4842bc6 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java @@ -0,0 +1,77 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; +import okio.Buffer; + +import java.io.IOException; +import java.nio.charset.Charset; +import java.util.Set; + +import static java.nio.charset.StandardCharsets.UTF_8; + +@Slf4j +@RequiredArgsConstructor +public class RetrofitRequestBodyMapper implements RetrofitLoggingMapper { + + public static final String KEY = "RequestBody"; + + private final int maxLoggableRequestSize; + private final Set redactBodyUrls; + + @Override + public String getValue(Connection connection, Request request, Response response) { + try { + return getRequestBody(request); + } catch (IOException e) { + log.error("Failed to parse request body.", e); + return "Parse error"; + } + } + + @Override + public String getKey() { + return KEY; + } + + private String getRequestBody(Request request) throws IOException { + var body = request.body(); + + if (body == null) { + return "null"; + } else if (RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, request.url().toString())) { + return "(body redacted)"; + } else if (RetrofitBodyMapperHelper.bodyHasUnknownEncoding(request.headers())) { + return "(encoded body omitted)"; + } else if (body.isDuplex()) { + return "(duplex request body omitted)"; + } else if (body.isOneShot()) { + return "(one-shot body omitted)"; + } else { + var buffer = new Buffer(); + body.writeTo(buffer); + + var contentType = body.contentType(); + Charset charSet = contentType != null ? contentType.charset(UTF_8) : UTF_8; + + if (RetrofitBodyMapperHelper.isProbablyUtf8(buffer)) { + assert charSet != null; + var bodyString = buffer.readString(charSet); + + if (request.body().contentLength() > maxLoggableRequestSize) { + return "%s ... Content size: %s characters".formatted( + bodyString.substring(0, maxLoggableRequestSize), + request.body().contentLength() + ); + } + + return bodyString; + } else { + return ("binary body omitted"); + } + } + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java new file mode 100644 index 0000000..c0f6186 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java @@ -0,0 +1,31 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +import java.io.IOException; + +@Slf4j +@RequiredArgsConstructor +public class RetrofitRequestBodySizeMapper implements RetrofitLoggingMapper { + + public static final String KEY = "RequestBodySize"; + + @Override + public String getValue(Connection connection, Request request, Response response) { + try { + return request.body() != null ? String.valueOf(request.body().contentLength()) : "-"; + } catch (IOException e) { + log.error("Failed to parse request content length.", e); + return "Parse error."; + } + } + + @Override + public String getKey() { + return KEY; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java new file mode 100644 index 0000000..b299109 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java @@ -0,0 +1,72 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; +import okhttp3.*; + +import java.io.IOException; +import java.util.HashMap; +import java.util.Map; +import java.util.Set; + +import static ee.bitweb.core.retrofit.logging.mappers.RetrofitHeadersMapperHelper.*; + +@Slf4j +@RequiredArgsConstructor +public class RetrofitRequestHeadersMapper implements RetrofitLoggingMapper { + + public static final String KEY = "RequestHeaders"; + + private final Set redactHeaders; + + @Override + public String getValue(Connection connection, Request request, Response response) { + try { + return getRequestHeadersString(request); + } catch (IOException e) { + log.error("Failed to parse request headers.", e); + return "Parse error"; + } + } + + @Override + public String getKey() { + return KEY; + } + + protected String getRequestHeadersString(Request request) throws IOException { + Map result = new HashMap<>(); + + var requestHeaders = request.headers(); + var requestBody = request.body(); + + String contentType = getRequestContentTypeValue(requestHeaders, requestBody); + String contentLength = getRequestContentLengthValue(requestHeaders, requestBody); + + if (contentType != null) { + RetrofitHeadersMapperHelper.addHeaderToResult(redactHeaders, result, CONTENT_TYPE, contentType); + } + + if (contentLength != null) { + RetrofitHeadersMapperHelper.addHeaderToResult(redactHeaders, result, CONTENT_LENGTH, contentLength); + } + + for (int i = 0; i < requestHeaders.size(); i++) { + var name = requestHeaders.name(i); + if (CONTENT_TYPE.equalsIgnoreCase(name) || CONTENT_LENGTH.equalsIgnoreCase(name)) { + continue; + } + addHeaderToResult(redactHeaders, result, name, requestHeaders.value(i)); + } + + return writeHeadersMapAsString(result); + } + + protected String getRequestContentTypeValue(Headers headers, RequestBody body) { + return RetrofitHeadersMapperHelper.getContentTypeValue(headers, body != null ? body.contentType() : null); + } + + protected String getRequestContentLengthValue(Headers headers, RequestBody body) throws IOException { + return RetrofitHeadersMapperHelper.getContentLengthValue(headers, body != null ? body.contentLength() : null); + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java new file mode 100644 index 0000000..05e7b50 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java @@ -0,0 +1,22 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +@RequiredArgsConstructor +public class RetrofitRequestMethodMapper implements RetrofitLoggingMapper { + + public static final String KEY = "RequestMethod"; + + @Override + public String getKey() { + return KEY; + } + + @Override + public String getValue(Connection connection, Request request, Response response) { + return request.method(); + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java new file mode 100644 index 0000000..6975030 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java @@ -0,0 +1,22 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +@RequiredArgsConstructor +public class RetrofitRequestProtocolMapper implements RetrofitLoggingMapper { + + public static final String KEY = "RequestProtocol"; + + @Override + public String getValue(Connection connection, Request request, Response response) { + return connection != null ? connection.protocol().toString() : "-"; + } + + @Override + public String getKey() { + return KEY; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java new file mode 100644 index 0000000..383b567 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java @@ -0,0 +1,22 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +@RequiredArgsConstructor +public class RetrofitRequestUrlMapper implements RetrofitLoggingMapper { + + public static final String KEY = "RequestUrl"; + + @Override + public String getValue(Connection connection, Request request, Response response) { + return request.url().toString(); + } + + @Override + public String getKey() { + return KEY; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java new file mode 100644 index 0000000..c4003a9 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java @@ -0,0 +1,91 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import lombok.extern.slf4j.Slf4j; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; +import okio.Buffer; +import okio.GzipSource; + +import java.io.IOException; +import java.util.Set; + +import static java.nio.charset.StandardCharsets.UTF_8; +import static okhttp3.internal.http.HttpHeaders.promisesBody; + +@Slf4j +@RequiredArgsConstructor +public class RetrofitResponseBodyMapper implements RetrofitLoggingMapper { + + public static final String KEY = "ResponseBody"; + + private final Set redactBodyUrls; + private final int maxLoggableResponseSize; + + @Override + public String getValue(Connection connection, Request request, Response response) { + try { + return getResponseBody(response); + } catch (IOException e) { + log.error("Failed to parse response body.", e); + return "Parse error"; + } + } + + @Override + public String getKey() { + return KEY; + } + + protected String getResponseBody(Response response) throws IOException { + if (RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, response.request().url().toString())) { + return "(body redacted)"; + } else if (!promisesBody(response)) { + return ""; + } else if (RetrofitBodyMapperHelper.bodyHasUnknownEncoding(response.headers())) { + return "(encoded body omitted)"; + } else if (response.body() == null) { + return "(body missing)"; + } else { + return parseBody(response); + } + } + + private String parseBody(Response response) throws IOException { + var responseBody = response.body(); + var contentType = responseBody.contentType(); + var contentLength = responseBody.contentLength(); + var charset = contentType != null ? contentType.charset(UTF_8) : UTF_8; + + var source = responseBody.source(); + source.request(Long.MAX_VALUE); + var buffer = source.getBuffer(); + + Long gzippedLength = null; + if ("gzip".equalsIgnoreCase(response.header("Content-Encoding"))) { + gzippedLength = buffer.size(); + var gzipSource = new GzipSource(buffer.clone()); + buffer = new Buffer(); + gzipSource.read(buffer, gzippedLength); + } + + if (!RetrofitBodyMapperHelper.isProbablyUtf8(buffer)) { + return "(binary %s-byte body omitted)".formatted(buffer.size()); + } + + if (contentLength != 0L) { + var bodyString = buffer.clone().readString(charset); + if (contentLength > maxLoggableResponseSize) { + return "%s ... Content size: %s characters".formatted( + bodyString.substring(0, maxLoggableResponseSize), + contentLength + ); + } + + return bodyString; + } else { + return ""; + } + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java new file mode 100644 index 0000000..33c0dd9 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java @@ -0,0 +1,22 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +@RequiredArgsConstructor +public class RetrofitResponseBodySizeMapper implements RetrofitLoggingMapper { + + public static final String KEY = "ResponseBodySize"; + + @Override + public String getValue(Connection connection, Request request, Response response) { + return response.body() != null ? String.valueOf(response.body().contentLength()) : "-"; + } + + @Override + public String getKey() { + return KEY; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java new file mode 100644 index 0000000..aebb6a8 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java @@ -0,0 +1,65 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import okhttp3.*; + +import java.util.HashMap; +import java.util.Map; +import java.util.Set; + +import static ee.bitweb.core.retrofit.logging.mappers.RetrofitHeadersMapperHelper.CONTENT_LENGTH; +import static ee.bitweb.core.retrofit.logging.mappers.RetrofitHeadersMapperHelper.CONTENT_TYPE; + +@RequiredArgsConstructor +public class RetrofitResponseHeadersMapper implements RetrofitLoggingMapper { + + public static final String KEY = "ResponseHeaders"; + + private final Set redactHeaders; + + @Override + public String getValue(Connection connection, Request request, Response response) { + return getResponseHeadersString(response); + } + + @Override + public String getKey() { + return KEY; + } + + protected String getResponseHeadersString(Response response) { + Map result = new HashMap<>(); + + var responseHeaders = response.headers(); + var responseBody = response.body(); + + String contentType = getResponseContentTypeValue(responseHeaders, responseBody); + String contentLength = getResponseContentLengthValue(responseHeaders, responseBody); + + if (contentType != null) { + RetrofitHeadersMapperHelper.addHeaderToResult(redactHeaders, result, CONTENT_TYPE, contentType); + } + + if (contentLength != null) { + RetrofitHeadersMapperHelper.addHeaderToResult(redactHeaders, result, CONTENT_LENGTH, contentLength); + } + + for (int i = 0; i < responseHeaders.size(); i++) { + var name = responseHeaders.name(i); + if (CONTENT_TYPE.equalsIgnoreCase(name) || CONTENT_LENGTH.equalsIgnoreCase(name)) { + continue; + } + RetrofitHeadersMapperHelper.addHeaderToResult(redactHeaders, result, name, responseHeaders.value(i)); + } + + return RetrofitHeadersMapperHelper.writeHeadersMapAsString(result); + } + + protected String getResponseContentTypeValue(Headers headers, ResponseBody body) { + return RetrofitHeadersMapperHelper.getContentTypeValue(headers, body != null ? body.contentType() : null); + } + + protected String getResponseContentLengthValue(Headers headers, ResponseBody body) { + return RetrofitHeadersMapperHelper.getContentLengthValue(headers, body != null ? body.contentLength() : null); + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java new file mode 100644 index 0000000..6287424 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java @@ -0,0 +1,22 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +@RequiredArgsConstructor +public class RetrofitResponseMessageMapper implements RetrofitLoggingMapper { + + public static final String KEY = "ResponseMessage"; + + @Override + public String getValue(Connection connection, Request request, Response response) { + return response.message(); + } + + @Override + public String getKey() { + return KEY; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java new file mode 100644 index 0000000..58d690a --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java @@ -0,0 +1,22 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import lombok.RequiredArgsConstructor; +import okhttp3.Connection; +import okhttp3.Request; +import okhttp3.Response; + +@RequiredArgsConstructor +public class RetrofitResponseStatusCodeMapper implements RetrofitLoggingMapper { + + public static final String KEY = "ResponseCode"; + + @Override + public String getValue(Connection connection, Request request, Response response) { + return String.valueOf(response.code()); + } + + @Override + public String getKey() { + return KEY; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java new file mode 100644 index 0000000..09c7f1b --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java @@ -0,0 +1,51 @@ +package ee.bitweb.core.retrofit.logging.writers; + +import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptorImplementation; +import ee.bitweb.core.retrofit.logging.mappers.RetrofitRequestMethodMapper; +import ee.bitweb.core.retrofit.logging.mappers.RetrofitRequestUrlMapper; +import ee.bitweb.core.retrofit.logging.mappers.RetrofitResponseBodySizeMapper; +import ee.bitweb.core.retrofit.logging.mappers.RetrofitResponseStatusCodeMapper; +import lombok.RequiredArgsConstructor; +import org.slf4j.MDC; + +import java.util.Map; + +@RequiredArgsConstructor +public class RetrofitLogLoggerWriterAdapter implements RetrofitLogWriteAdapter { + + public static final String LOGGER_NAME = "RetrofitLogger"; + + private static final org.slf4j.Logger log = org.slf4j.LoggerFactory.getLogger(LOGGER_NAME); + + @Override + public void write(Map container) { + Map currentContext = MDC.getCopyOfContextMap(); + + log(container); + + if (currentContext != null) { + MDC.setContextMap(currentContext); + } + } + + private void log(Map container) { + container.forEach(MDC::put); + + log.info( + "Method({}), URL({}) Status({}) ResponseSize({}) Duration({} ms)", + get(container, RetrofitRequestMethodMapper.KEY), + get(container, RetrofitRequestUrlMapper.KEY), + get(container, RetrofitResponseStatusCodeMapper.KEY), + get(container, RetrofitResponseBodySizeMapper.KEY), + get(container, RetrofitLoggingInterceptorImplementation.DURATION_KEY) + ); + } + + private String get(Map container, String key) { + if (container.containsKey(key)) { + return container.get(key); + } + + return "-"; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogWriteAdapter.java b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogWriteAdapter.java new file mode 100644 index 0000000..ec5b99a --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogWriteAdapter.java @@ -0,0 +1,8 @@ +package ee.bitweb.core.retrofit.logging.writers; + +import java.util.Map; + +public interface RetrofitLogWriteAdapter { + + void write(Map container); +} diff --git a/src/test/java/ee/bitweb/core/retrofit/RetrofitAutoConfigurationTests.java b/src/test/java/ee/bitweb/core/retrofit/RetrofitAutoConfigurationTests.java index d9f5f8c..cfe4a35 100644 --- a/src/test/java/ee/bitweb/core/retrofit/RetrofitAutoConfigurationTests.java +++ b/src/test/java/ee/bitweb/core/retrofit/RetrofitAutoConfigurationTests.java @@ -9,6 +9,7 @@ import org.junit.jupiter.api.Test; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.boot.test.context.SpringBootTest; +import org.springframework.test.context.ActiveProfiles; import retrofit2.Converter; import retrofit2.converter.jackson.JacksonConverterFactory; @@ -27,6 +28,7 @@ "ee.bitweb.core.retrofit.auth-token-injector.whitelist-urls[0]=^http?:\\\\/\\\\/localhost:\\\\d{3,5}\\\\/.*" } ) +@ActiveProfiles("retrofit") class RetrofitAutoConfigurationTests { @Autowired diff --git a/src/test/java/ee/bitweb/core/retrofit/RetrofitExecutorTests.java b/src/test/java/ee/bitweb/core/retrofit/RetrofitExecutorTests.java index dab4b5d..2ac63d0 100644 --- a/src/test/java/ee/bitweb/core/retrofit/RetrofitExecutorTests.java +++ b/src/test/java/ee/bitweb/core/retrofit/RetrofitExecutorTests.java @@ -5,7 +5,10 @@ import ee.bitweb.http.server.mock.MockServer; import io.netty.handler.codec.http.HttpMethod; import org.json.JSONObject; -import org.junit.jupiter.api.*; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.BeforeAll; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.junit.jupiter.api.extension.RegisterExtension; import org.mockito.junit.jupiter.MockitoExtension; @@ -24,7 +27,7 @@ class RetrofitExecutorTests { @BeforeAll public static void beforeAll() { - api = RetrofitApiBuilder.create(BASE_URL + server.getPort(), ExternalServiceApi.class).build(); + api = RetrofitApiBuilder.create(BASE_URL + server.getPort(), ExternalServiceApi.class, null).build(); } @Test @@ -135,7 +138,8 @@ void onServiceErrorWithRawRequestShouldThrowRetrofitException() { void onConnectionExceptionShouldThrowRetrofitException() { ExternalServiceApi api = RetrofitApiBuilder.create( "http://some-random-url", - ExternalServiceApi.class + ExternalServiceApi.class, + null ).build(); RetrofitException exception = Assertions.assertThrows( diff --git a/src/test/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilderTests.java b/src/test/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilderTests.java index a2441ec..06b0270 100644 --- a/src/test/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilderTests.java +++ b/src/test/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilderTests.java @@ -8,7 +8,9 @@ import io.netty.handler.codec.http.HttpMethod; import okhttp3.OkHttpClient; import org.json.JSONObject; -import org.junit.jupiter.api.*; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.junit.jupiter.api.extension.RegisterExtension; import org.mockito.Mockito; @@ -32,8 +34,9 @@ class RetrofitApiBuilderTests { void defaultBuilderWorksAsExpected() throws Exception { mockServerGet("message", "1"); ExternalServiceApi api = RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).build(); ExternalServiceApi.Payload response = api.get().execute().body(); @@ -49,8 +52,9 @@ void addedInterceptorShouldBeUsedOnRequest() throws Exception { RequestCountInterceptor customInterceptor = new RequestCountInterceptor(); ExternalServiceApi api = RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).add( customInterceptor ).build(); @@ -70,8 +74,9 @@ void addedMultipleInterceptorsShouldAllBeUsedOnRequest() throws Exception { RequestCountInterceptor customInterceptor2 = new RequestCountInterceptor(); ExternalServiceApi api = RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).addAll( List.of( customInterceptor1, @@ -96,8 +101,9 @@ void onAddedCustomClientIsApplied() throws Exception { OkHttpClient.Builder clientBuilder = new OkHttpClient.Builder().addInterceptor(interceptor); ExternalServiceApi api = RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).clientBuilder( clientBuilder ).build(); @@ -118,8 +124,9 @@ void clearInterceptorsRemovesInterceptors() throws Exception { OkHttpClient.Builder clientBuilder = new OkHttpClient.Builder().addInterceptor(interceptor); ExternalServiceApi api = RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).clientBuilder( clientBuilder ).emptyInterceptors().build(); @@ -140,8 +147,9 @@ void removeInterceptorRemovesProvidedInterceptorOnly() throws Exception { RequestCountInterceptor customInterceptor2 = new RequestCountInterceptor(); ExternalServiceApi api = RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).addAll( List.of( customInterceptor1, @@ -170,7 +178,7 @@ void callTimeoutIsApplied() { }).when(clientBuilder).build(); ExternalServiceApi api = RetrofitApiBuilder - .create(BASE_URL + server.getPort(), ExternalServiceApi.class) + .create(BASE_URL + server.getPort(), ExternalServiceApi.class, null) .clientBuilder(clientBuilder) .callTimeout(999) .build(); @@ -190,7 +198,7 @@ void connectTimeoutIsApplied() { }).when(clientBuilder).build(); ExternalServiceApi api = RetrofitApiBuilder - .create(BASE_URL + server.getPort(), ExternalServiceApi.class) + .create(BASE_URL + server.getPort(), ExternalServiceApi.class, null) .clientBuilder(clientBuilder) .connectTimeout(999) .build(); @@ -210,7 +218,7 @@ void readTimeoutIsApplied() { }).when(clientBuilder).build(); ExternalServiceApi api = RetrofitApiBuilder - .create(BASE_URL + server.getPort(), ExternalServiceApi.class) + .create(BASE_URL + server.getPort(), ExternalServiceApi.class, null) .clientBuilder(clientBuilder) .readTimeout(999) .build(); @@ -230,7 +238,7 @@ void writeTimeoutIsApplied() { }).when(clientBuilder).build(); ExternalServiceApi api = RetrofitApiBuilder - .create(BASE_URL + server.getPort(), ExternalServiceApi.class) + .create(BASE_URL + server.getPort(), ExternalServiceApi.class, null) .clientBuilder(clientBuilder) .writeTimeout(999) .build(); @@ -247,8 +255,9 @@ void addedCustomConverterIsApplied() throws Exception { Converter.Factory converter = JacksonConverterFactory.create(mapper); ExternalServiceApi api = RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).converter( converter ).build(); diff --git a/src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitConfiguration.java b/src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitConfiguration.java index 31bd614..be1584d 100644 --- a/src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitConfiguration.java +++ b/src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitConfiguration.java @@ -3,10 +3,10 @@ import ee.bitweb.core.retrofit.interceptor.auth.TokenProvider; import org.springframework.context.annotation.Bean; import org.springframework.context.annotation.Configuration; -import org.springframework.test.context.ActiveProfiles; +import org.springframework.context.annotation.Profile; @Configuration -@ActiveProfiles("retrofit") +@Profile("retrofit") public class RetrofitConfiguration { @Bean("interceptor1") diff --git a/src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitLogTestWriter.java b/src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitLogTestWriter.java new file mode 100644 index 0000000..61af209 --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/helpers/RetrofitLogTestWriter.java @@ -0,0 +1,25 @@ +package ee.bitweb.core.retrofit.helpers; + +import ee.bitweb.core.retrofit.logging.writers.RetrofitLogWriteAdapter; +import lombok.Getter; +import org.springframework.context.annotation.Profile; +import org.springframework.stereotype.Service; + +import java.util.Map; + +@Service +@Profile("retrofit-log-test-writer") +public class RetrofitLogTestWriter implements RetrofitLogWriteAdapter { + + @Getter + private Map container = null; + + @Override + public void write(Map container) { + this.container = container; + } + + public void clear() { + container = null; + } +} diff --git a/src/test/java/ee/bitweb/core/retrofit/interceptor/TraceIdInterceptorTests.java b/src/test/java/ee/bitweb/core/retrofit/interceptor/TraceIdInterceptorTests.java index 7d08566..4cebb48 100644 --- a/src/test/java/ee/bitweb/core/retrofit/interceptor/TraceIdInterceptorTests.java +++ b/src/test/java/ee/bitweb/core/retrofit/interceptor/TraceIdInterceptorTests.java @@ -7,7 +7,9 @@ import ee.bitweb.http.server.mock.MockServer; import io.netty.handler.codec.http.HttpMethod; import org.json.JSONObject; -import org.junit.jupiter.api.*; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.junit.jupiter.api.extension.RegisterExtension; import org.mockito.Mock; @@ -60,8 +62,9 @@ void onMissingTraceIdInContextShouldThrowException() { private ExternalServiceApi createApi() { return RetrofitApiBuilder.create( - BASE_URL + server.getPort(), - ExternalServiceApi.class + BASE_URL + server.getPort(), + ExternalServiceApi.class, + null ).add( new TraceIdInterceptor(config, context) ).build(); diff --git a/src/test/java/ee/bitweb/core/retrofit/interceptor/auth/AuthTokenInjectInterceptorTests.java b/src/test/java/ee/bitweb/core/retrofit/interceptor/auth/AuthTokenInjectInterceptorTests.java index 4757339..727b8d8 100644 --- a/src/test/java/ee/bitweb/core/retrofit/interceptor/auth/AuthTokenInjectInterceptorTests.java +++ b/src/test/java/ee/bitweb/core/retrofit/interceptor/auth/AuthTokenInjectInterceptorTests.java @@ -7,7 +7,9 @@ import ee.bitweb.http.server.mock.MockServer; import io.netty.handler.codec.http.HttpMethod; import org.json.JSONObject; -import org.junit.jupiter.api.*; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.junit.jupiter.api.extension.RegisterExtension; import org.mockito.Mock; @@ -167,7 +169,8 @@ void onMatchingBlacklistCriteriaShouldNotAddHeader() { private RetrofitApiBuilder createBuilder() { return RetrofitApiBuilder.create( BASE_URL + server.getPort(), - ExternalServiceApi.class + ExternalServiceApi.class, + null ); } diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java index 2cf5c70..9ab17ed 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java @@ -21,7 +21,6 @@ import java.io.IOException; import java.util.ArrayList; -import java.util.List; import java.util.regex.Pattern; import static org.junit.jupiter.api.Assertions.assertEquals; @@ -60,7 +59,7 @@ void beforeEach() { context.clear(); context.set("TEST"); - logger = (Logger) LoggerFactory.getLogger(RetrofitLoggingInterceptor.class); + logger = (Logger) LoggerFactory.getLogger("RetrofitLogger"); memoryAppender = new MemoryAppender(); memoryAppender.setContext((LoggerContext) LoggerFactory.getILoggerFactory()); logger.setLevel(Level.DEBUG); @@ -74,7 +73,6 @@ void afterEach() { memoryAppender.stop(); - retrofitProperties.getLogging().setLevel(LoggingLevel.BASIC); retrofitProperties.getLogging().setSuppressedHeaders(new ArrayList<>()); retrofitProperties.getLogging().getRedactedBodyUrls().clear(); retrofitProperties.getLogging().setMaxLoggableRequestBodySize(1024 * 10L); @@ -84,98 +82,6 @@ void afterEach() { @Test @DisplayName("Logging level NONE") void loggingLevelNone() throws Exception { - retrofitProperties.getLogging().setLevel(LoggingLevel.NONE); - - executeRetrofitRequest(); - - assertEquals(0, memoryAppender.getSize()); - } - - @Test - @DisplayName("Logging level BASIC") - void loggingLevelBasic() throws Exception { - retrofitProperties.getLogging().setLevel(LoggingLevel.BASIC); - - executeRetrofitRequest(); - - assertEquals(1, memoryAppender.getSize()); - - assertLogLevel(); - assertLogMessage(); - - assertEquals(9, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); - assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); - assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); - assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); - assertTrue( - Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() - ); - assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() - ); - assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() - ); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() - ); - } - - @Test - @DisplayName("Logging level HEADERS") - void loggingLevelHeaders() throws Exception { - retrofitProperties.getLogging().setLevel(LoggingLevel.HEADERS); - - executeRetrofitRequest(); - - assertEquals(1, memoryAppender.getSize()); - - assertLogLevel(); - assertLogMessage(); - - assertEquals(11, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); - assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); - assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); - assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); - assertTrue( - Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() - ); - assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() - ); - assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() - ); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() - ); - assertEquals( - "Content-Length: 32; Content-Type: application/json; charset=UTF-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") - ); - assertEquals( - "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") - ); - } - - @Test - @DisplayName("Logging level BODY") - void loggingLevelBody() throws Exception { - retrofitProperties.getLogging().setLevel(LoggingLevel.BODY); - executeRetrofitRequest(); assertEquals(1, memoryAppender.getSize()); @@ -194,7 +100,7 @@ void loggingLevelBody() throws Exception { assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); assertTrue( Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("Duration")).find() ); assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); assertTrue( @@ -206,7 +112,7 @@ void loggingLevelBody() throws Exception { .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() ); assertEquals( - "Content-Length: 32; Content-Type: application/json; charset=UTF-8", + "Content-Length: 32; Content-Type: application; X-Trace-ID: TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") ); assertEquals( @@ -223,158 +129,6 @@ void loggingLevelBody() throws Exception { ); } - @Test - @DisplayName("Redact header") - void redactHeader() throws Exception { - retrofitProperties.getLogging().setLevel(LoggingLevel.HEADERS); - retrofitProperties.getLogging().setSuppressedHeaders(List.of("content-type")); - - executeRetrofitRequest(); - - assertEquals(1, memoryAppender.getSize()); - - assertLogLevel(); - assertLogMessage(); - - assertEquals(11, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); - assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); - assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); - assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); - assertTrue( - Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() - ); - assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() - ); - assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() - ); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() - ); - assertEquals( - "Content-Length: 32; Content-Type: ", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") - ); - assertEquals( - "connection: keep-alive; Content-Length: 32; Content-Type: ", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") - ); - } - - @Test - @DisplayName("Redact body url") - void redactBodyUrl() throws Exception { - retrofitProperties.getLogging().setLevel(LoggingLevel.BODY); - retrofitProperties.getLogging().getRedactedBodyUrls().add(BASE_URL + server.getPort() + "/data-post"); - - executeRetrofitRequest(); - - assertEquals(1, memoryAppender.getSize()); - - assertLogLevel(); - assertLogMessage(); - - assertEquals(13, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); - assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); - assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); - assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); - assertTrue( - Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() - ); - assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() - ); - assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() - ); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() - ); - assertEquals( - "Content-Length: 32; Content-Type: application/json; charset=UTF-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") - ); - assertEquals( - "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") - ); - assertEquals( - "(body redacted)", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") - ); - assertEquals( - "(body redacted)", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") - ); - } - - @Test - @DisplayName("Limit logged body size") - void limitLoggedBodySize() throws Exception { - retrofitProperties.getLogging().setLevel(LoggingLevel.BODY); - retrofitProperties.getLogging().setMaxLoggableRequestBodySize(5L); - retrofitProperties.getLogging().setMaxLoggableResponseBodySize(10L); - - executeRetrofitRequest(); - - assertEquals(1, memoryAppender.getSize()); - - assertLogLevel(); - assertLogMessage(); - - assertEquals(13, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); - assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); - assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); - assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); - assertTrue( - Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() - ); - assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestDuration")).find() - ); - assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() - ); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() - ); - assertEquals( - "Content-Length: 32; Content-Type: application/json; charset=UTF-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") - ); - assertEquals( - "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") - ); - assertEquals( - "{\"mes ... Content size: 32 characters", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") - ); - assertEquals( - "{\"message\" ... Content size: 32 characters", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") - ); - } - private void assertLogLevel() { assertEquals(Level.INFO, memoryAppender.getLoggedEvents().get(0).getLevel()); } From 87e35112eb58e304d5178ffa30664f582befd1b3 Mon Sep 17 00:00:00 2001 From: ennoeller Date: Fri, 18 Oct 2024 16:49:24 +0300 Subject: [PATCH 07/14] feature/enable-custom-http-logger-interceptor --- .../RetrofitRequestBodyMapperTest.java | 78 ++++++++++ .../RetrofitResponseBodyMapperTest.java | 134 ++++++++++++++++++ 2 files changed, 212 insertions(+) create mode 100644 src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java create mode 100644 src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java new file mode 100644 index 0000000..9dfeb8e --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java @@ -0,0 +1,78 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import okhttp3.*; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; + +import java.util.HashMap; +import java.util.HashSet; +import java.util.Set; + +@Tag("unit") +class RetrofitRequestBodyMapperTest { + + @Test + @DisplayName("Is redact url") + void isRedactUrl() { + var mapper = new RetrofitRequestBodyMapper(0, Set.of("https://www.google.com/")); + + var request = new Request( + new HttpUrl.Builder() + .scheme("https") + .host("www.google.com") + .build(), + "GET", + new Headers.Builder().build(), + RequestBody.create("123".getBytes(), MediaType.get("application/text")), + new HashMap<>() + ); + + var value = mapper.getValue(null, request, null); + + Assertions.assertEquals("(body redacted)", value); + } + + @Test + @DisplayName("Body has unknown encoding") + void bodyHasUnknownEncoding() { + var mapper = new RetrofitRequestBodyMapper(0, new HashSet<>()); + + var request = new Request( + new HttpUrl.Builder() + .scheme("https") + .host("www.google.com") + .build(), + "GET", + new Headers.Builder().add("Content-Encoding", "unknownEncoding").build(), + RequestBody.create("123".getBytes(), MediaType.get("application/text")), + new HashMap<>() + ); + + var value = mapper.getValue(null, request, null); + + Assertions.assertEquals("(encoded body omitted)", value); + } + + @Test + @DisplayName("Max loggable request size") + void maxLoggableRequestSize() { + var mapper = new RetrofitRequestBodyMapper(2, new HashSet<>()); + + var request = new Request( + new HttpUrl.Builder() + .scheme("https") + .host("www.google.com") + .build(), + "GET", + new Headers.Builder().build(), + RequestBody.create("123".getBytes(), MediaType.get("application/text")), + new HashMap<>() + ); + + var value = mapper.getValue(null, request, null); + + Assertions.assertEquals("12 ... Content size: 3 characters", value); + } +} \ No newline at end of file diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java new file mode 100644 index 0000000..07a46a2 --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java @@ -0,0 +1,134 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import okhttp3.*; +import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; + +import java.util.HashMap; +import java.util.HashSet; +import java.util.Set; + +import static org.junit.jupiter.api.Assertions.*; + +@Tag("unit") +class RetrofitResponseBodyMapperTest { + + @Test + @DisplayName("Is redact url") + void isRedactUrl() { + var mapper = new RetrofitResponseBodyMapper(Set.of("https://www.google.com/"), 0); + + var response = new Response( + request("GET"), + Protocol.HTTP_1_0, + "message", + 200, + null, + new Headers.Builder().build(), + ResponseBody.create("123".getBytes(), MediaType.get("application/text")), + null, + null, + null, + 1, + 2, + null + ); + + var value = mapper.getValue(null, null, response); + + Assertions.assertEquals("(body redacted)", value); + } + + @Test + @DisplayName("Promises body") + void promisesBody() { + var mapper = new RetrofitResponseBodyMapper(new HashSet<>(), 0); + + var response = new Response( + request("HEAD"), + Protocol.HTTP_1_0, + "message", + 201, + null, + new Headers.Builder().build(), + ResponseBody.create("123".getBytes(), MediaType.get("application/text")), + null, + null, + null, + 1, + 2, + null + ); + + var value = mapper.getValue(null, null, response); + + Assertions.assertEquals("", value); + } + + @Test + @DisplayName("Body has unknown encoding") + void bodyHasUnknownEncoding() { + var mapper = new RetrofitResponseBodyMapper(new HashSet<>(), 0); + + var response = new Response( + request("GET"), + Protocol.HTTP_1_0, + "message", + 201, + null, + new Headers.Builder().add("Content-Encoding", "unknownEncoding").build(), + ResponseBody.create("123".getBytes(), MediaType.get("application/text")), + null, + null, + null, + 1, + 2, + null + ); + + var value = mapper.getValue(null, null, response); + + Assertions.assertEquals("(encoded body omitted)", value); + } + + @Test + @DisplayName("Body missing") + void bodyMissing() { + var mapper = new RetrofitResponseBodyMapper(new HashSet<>(), 0); + + var response = new Response( + request("GET"), + Protocol.HTTP_1_0, + "message", + 201, + null, + new Headers.Builder().build(), + null, + null, + null, + null, + 1, + 2, + null + ); + + var value = mapper.getValue(null, null, response); + + Assertions.assertEquals("(body missing)", value); + } + + private Request request(String method) { + return new Request( + new HttpUrl.Builder() + .scheme("https") + .host("www.google.com") + .build(), + method, + new Headers.Builder().build(), + RequestBody.create("123".getBytes(), MediaType.get("application/text")), + new HashMap<>() + ); + } +} \ No newline at end of file From 5c38189cf4e444e8c7a23380d75ee180f64f31ba Mon Sep 17 00:00:00 2001 From: ennoeller Date: Thu, 31 Oct 2024 11:08:35 +0200 Subject: [PATCH 08/14] feature/enable-custom-http-logger-interceptor --- build.gradle | 2 +- .../writers/RetrofitLogLoggerWriterAdapter.java | 10 ++++++---- 2 files changed, 7 insertions(+), 5 deletions(-) diff --git a/build.gradle b/build.gradle index 1852966..15c3a2e 100644 --- a/build.gradle +++ b/build.gradle @@ -19,7 +19,7 @@ plugins { } group 'ee.bitweb' -version '3.5.0' +version '4.0.0' java { sourceCompatibility = '17' } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java index 09c7f1b..84945fc 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java @@ -21,10 +21,12 @@ public class RetrofitLogLoggerWriterAdapter implements RetrofitLogWriteAdapter { public void write(Map container) { Map currentContext = MDC.getCopyOfContextMap(); - log(container); - - if (currentContext != null) { - MDC.setContextMap(currentContext); + try { + log(container); + } finally { + if (currentContext != null) { + MDC.setContextMap(currentContext); + } } } From f4420b76f5eaf1e2a34300ab503ef8461758b0d4 Mon Sep 17 00:00:00 2001 From: Rain Ramm Date: Fri, 1 Nov 2024 15:35:32 +0200 Subject: [PATCH 09/14] Bring back logging level for easier use, default remains same as in 3.x Remove some non-standard mappers Add no-op interceptor for when logging has been turned off All mappers are extendable and mapper beans can be overridden --- README.md | 2 +- .../retrofit/RetrofitAutoConfiguration.java | 33 ++++--- .../core/retrofit/RetrofitProperties.java | 37 ++++---- .../retrofit/RetrofitRequestExecutor.java | 2 +- .../core/retrofit/builder/LoggingLevel.java | 52 +++++++++++ .../retrofit/builder/RetrofitApiBuilder.java | 18 ++-- .../NoopRetrofitLoggingInterceptor.java | 15 ++++ ...rofitLoggingInterceptorImplementation.java | 10 ++- .../mappers/RetrofitLoggingMapper.java | 7 +- .../mappers/RetrofitRequestBodyMapper.java | 17 +++- .../RetrofitRequestBodySizeMapper.java | 3 +- .../mappers/RetrofitRequestHeadersMapper.java | 2 +- .../mappers/RetrofitRequestMethodMapper.java | 3 +- .../RetrofitRequestProtocolMapper.java | 22 ----- .../mappers/RetrofitRequestUrlMapper.java | 3 +- .../mappers/RetrofitResponseBodyMapper.java | 15 +++- .../RetrofitResponseBodySizeMapper.java | 3 +- .../RetrofitResponseHeadersMapper.java | 2 +- .../RetrofitResponseMessageMapper.java | 22 ----- .../RetrofitResponseStatusCodeMapper.java | 3 +- .../RetrofitLogLoggerWriterAdapter.java | 39 +++++--- .../RetrofitLoggingInterceptorTest.java | 88 +++++++++---------- .../RetrofitRequestBodyMapperTest.java | 8 +- .../RetrofitResponseBodyMapperTest.java | 10 +-- 24 files changed, 238 insertions(+), 178 deletions(-) create mode 100644 src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java create mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptor.java delete mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java delete mode 100644 src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java diff --git a/README.md b/README.md index 75cb050..ecd54d6 100644 --- a/README.md +++ b/README.md @@ -10,7 +10,7 @@ Library providing basic generic functionality required by any HTTP web service. ``` // https://mvnrepository.com/artifact/ee.bitweb/spring-core -implementation group: 'ee.bitweb', name: 'spring-core', version: '3.2.0' +implementation group: 'ee.bitweb', name: 'spring-core', version: '4.0.0' ``` Review available versions in [Maven Central](https://mvnrepository.com/artifact/ee.bitweb/spring-core). diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java index ea18615..80f87f1 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java @@ -1,10 +1,12 @@ package ee.bitweb.core.retrofit; import com.fasterxml.jackson.databind.ObjectMapper; +import ee.bitweb.core.retrofit.builder.LoggingLevel; import ee.bitweb.core.retrofit.interceptor.auth.AuthTokenInjectInterceptor; import ee.bitweb.core.retrofit.interceptor.auth.TokenProvider; import ee.bitweb.core.retrofit.interceptor.auth.criteria.AuthTokenCriteria; import ee.bitweb.core.retrofit.interceptor.auth.criteria.WhitelistCriteria; +import ee.bitweb.core.retrofit.logging.NoopRetrofitLoggingInterceptor; import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptor; import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptorImplementation; import ee.bitweb.core.retrofit.logging.mappers.*; @@ -76,8 +78,15 @@ public AuthTokenCriteria defaultCriteria(RetrofitProperties properties) { @Bean("defaultRetrofitLoggingInterceptor") @Primary public RetrofitLoggingInterceptor defaultRetrofitLoggingInterceptor( - List mappers + List mappers, + RetrofitProperties properties ) { + if (properties.getLogging().getLevel() == LoggingLevel.NONE) { + log.info("Create Default Retrofit Logging Interceptor for logging level NONE"); + + return new NoopRetrofitLoggingInterceptor(); + } + log.info( "Create Default Retrofit Logging Interceptor with writer {}", RetrofitLogLoggerWriterAdapter.class.getSimpleName() @@ -90,25 +99,23 @@ public RetrofitLoggingInterceptor defaultRetrofitLoggingInterceptor( return new RetrofitLoggingInterceptorImplementation(mappers, new RetrofitLogLoggerWriterAdapter()); } + // testida üle, kui on vajadus mapper üle kirjutada @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestMethodMapper.KEY) public RetrofitRequestMethodMapper retrofitRequestMethodMapper() { return new RetrofitRequestMethodMapper(); } @Bean - @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestProtocolMapper.KEY) - public RetrofitRequestProtocolMapper retrofitRequestProtocolMapper() { - return new RetrofitRequestProtocolMapper(); - } - - @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestUrlMapper.KEY) public RetrofitRequestUrlMapper retrofitRequestUrlMapper() { return new RetrofitRequestUrlMapper(); } @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestHeadersMapper.KEY) public RetrofitRequestHeadersMapper retrofitRequestHeadersMapper( RetrofitProperties retrofitProperties @@ -117,12 +124,14 @@ public RetrofitRequestHeadersMapper retrofitRequestHeadersMapper( } @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestBodySizeMapper.KEY) public RetrofitRequestBodySizeMapper retrofitRequestBodySizeMapper() { return new RetrofitRequestBodySizeMapper(); } @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestBodyMapper.KEY) public RetrofitRequestBodyMapper retrofitRequestBodyMapper( RetrofitProperties retrofitProperties @@ -134,18 +143,14 @@ public RetrofitRequestBodyMapper retrofitRequestBodyMapper( } @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseStatusCodeMapper.KEY) public RetrofitResponseStatusCodeMapper retrofitResponseStatusCodeMapper() { return new RetrofitResponseStatusCodeMapper(); } @Bean - @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseMessageMapper.KEY) - public RetrofitResponseMessageMapper retrofitResponseMessageMapper() { - return new RetrofitResponseMessageMapper(); - } - - @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseHeadersMapper.KEY) public RetrofitResponseHeadersMapper retrofitResponseHeadersMapper( RetrofitProperties retrofitProperties @@ -154,12 +159,14 @@ public RetrofitResponseHeadersMapper retrofitResponseHeadersMapper( } @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseBodySizeMapper.KEY) public RetrofitResponseBodySizeMapper retrofitResponseBodySizeMapper() { return new RetrofitResponseBodySizeMapper(); } @Bean + @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitResponseBodyMapper.KEY) public RetrofitResponseBodyMapper responseBodyMapper( RetrofitProperties retrofitProperties diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java index 5702fd1..92addd5 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitProperties.java @@ -1,6 +1,6 @@ package ee.bitweb.core.retrofit; -import ee.bitweb.core.retrofit.logging.mappers.*; +import ee.bitweb.core.retrofit.builder.LoggingLevel; import jakarta.validation.Valid; import jakarta.validation.constraints.AssertTrue; import jakarta.validation.constraints.NotBlank; @@ -13,9 +13,7 @@ import org.springframework.util.StringUtils; import org.springframework.validation.annotation.Validated; -import java.util.ArrayList; -import java.util.Arrays; -import java.util.List; +import java.util.*; import static ee.bitweb.core.retrofit.RetrofitProperties.PREFIX; @@ -44,6 +42,9 @@ public class RetrofitProperties { @Validated public static class Logging { + @NotNull + private LoggingLevel level = LoggingLevel.BASIC; + @NotNull private Long maxLoggableRequestBodySize = 1024 * 10L; @@ -53,22 +54,18 @@ public static class Logging { private List<@NotBlank String> suppressedHeaders = new ArrayList<>(); private List<@NotBlank String> redactedBodyUrls = new ArrayList<>(); - @NotNull - private List<@NotBlank String> mappers = new ArrayList<>( - Arrays.asList( - RetrofitRequestMethodMapper.KEY, - RetrofitRequestProtocolMapper.KEY, - RetrofitRequestUrlMapper.KEY, - RetrofitRequestHeadersMapper.KEY, - RetrofitRequestBodySizeMapper.KEY, - RetrofitRequestBodyMapper.KEY, - RetrofitResponseStatusCodeMapper.KEY, - RetrofitResponseMessageMapper.KEY, - RetrofitResponseHeadersMapper.KEY, - RetrofitResponseBodySizeMapper.KEY, - RetrofitResponseBodyMapper.KEY - ) - ); + private List<@NotBlank String> mappers = new ArrayList<>(); + + public List<@NotBlank String> getMappers() { + if (level == LoggingLevel.CUSTOM) { + return mappers; + } else { + Set enabledMappers = new HashSet<>(level.getMappers()); + enabledMappers.addAll(mappers); + + return enabledMappers.stream().toList(); + } + } } @Getter diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitRequestExecutor.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitRequestExecutor.java index 074a443..3b00c9a 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitRequestExecutor.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitRequestExecutor.java @@ -16,7 +16,7 @@ public class RetrofitRequestExecutor { public static T execute(Call> request) { retrofit2.Response> response = doRequest(request); - if (response.body().getData() == null) { + if (response.body() == null || response.body().getData() == null) { throw RetrofitException.of(EMPTY_RESPONSE_BODY_ERROR, request, response); } diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java b/src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java new file mode 100644 index 0000000..a9f8332 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/builder/LoggingLevel.java @@ -0,0 +1,52 @@ +package ee.bitweb.core.retrofit.builder; + +import ee.bitweb.core.retrofit.logging.mappers.*; +import lombok.AccessLevel; +import lombok.AllArgsConstructor; +import lombok.Getter; + +import java.util.ArrayList; +import java.util.List; + +@Getter +@AllArgsConstructor(access = AccessLevel.PRIVATE) +public enum LoggingLevel { + + NONE(List.of()), + BASIC(basicMappers()), + HEADERS(headerMappers()), + BODY(bodyMappers()), + CUSTOM(List.of()); + + private final List mappers; + + private static List basicMappers() { + return new ArrayList<>(List.of( + RetrofitRequestMethodMapper.KEY, + RetrofitRequestUrlMapper.KEY, + RetrofitRequestBodySizeMapper.KEY, + RetrofitResponseStatusCodeMapper.KEY, + RetrofitResponseBodySizeMapper.KEY + )); + } + + private static List headerMappers() { + List mappers = basicMappers(); + mappers.addAll(List.of( + RetrofitRequestHeadersMapper.KEY, + RetrofitResponseHeadersMapper.KEY + )); + + return mappers; + } + + private static List bodyMappers() { + List mappers = headerMappers(); + mappers.addAll(List.of( + RetrofitRequestBodyMapper.KEY, + RetrofitResponseBodyMapper.KEY + )); + + return mappers; + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java index 5f2b6b2..2ea11df 100644 --- a/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java +++ b/src/main/java/ee/bitweb/core/retrofit/builder/RetrofitApiBuilder.java @@ -87,10 +87,8 @@ public RetrofitApiBuilder removeAll(Class definition) } public RetrofitApiBuilder replaceAllOfType(Interceptor interceptor) { - removeAll(interceptor.getClass()); - add(interceptor); - - return this; + return removeAll(interceptor.getClass()) + .add(interceptor); } public RetrofitApiBuilder addAll(Collection interceptors) { @@ -138,13 +136,8 @@ public RetrofitApiBuilder writeTimeout(long timeout) { public T build() { Converter.Factory factory = converterFactory != null ? converterFactory : DEFAULT_CONVERTER_FACTORY; - log.info( - "Built Retrofit API for host {} with definition {}, interceptors {} and converter factory {}", - url, definition.getName(), clientBuilder.interceptors(), factory - ); - if (clientBuilder.interceptors().stream().filter(RetrofitLoggingInterceptor.class::isInstance).toList().size() > 1) { - throw new CoreException("Multiple logging interceptors detected at build."); + throw new CoreException("Multiple logging interceptors detected at build for definition %s".formatted(definition.getName())); } clientBuilder.interceptors().sort((i1, i2) -> { @@ -157,6 +150,11 @@ public T build() { } }); + log.info( + "Built Retrofit API for host {} with definition {}, interceptors {} and converter factory {}", + url, definition.getName(), clientBuilder.interceptors(), factory + ); + return new Retrofit .Builder() .baseUrl(url) diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptor.java b/src/main/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptor.java new file mode 100644 index 0000000..7199b31 --- /dev/null +++ b/src/main/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptor.java @@ -0,0 +1,15 @@ +package ee.bitweb.core.retrofit.logging; + +import okhttp3.Response; +import org.jetbrains.annotations.NotNull; + +import java.io.IOException; + +public class NoopRetrofitLoggingInterceptor implements RetrofitLoggingInterceptor { + + @NotNull + @Override + public Response intercept(@NotNull Chain chain) throws IOException { + return chain.proceed(chain.request()); + } +} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java index 4122923..88b8715 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java @@ -35,11 +35,19 @@ public Response intercept(@NotNull Chain chain) throws IOException { Response finalResponse = response; Request request = finalResponse != null ? finalResponse.request() : chain.request(); - mappers.forEach(mapper -> mapper.map(chain.connection(), request, finalResponse, container)); + mappers.forEach(mapper -> mapper.map(request, finalResponse, container)); writer.write(container); } return response; } + + @Override + public String toString() { + return "RetrofitLoggingInterceptorImplementation{" + + "mappers=" + mappers + + ", writer=" + writer + + '}'; + } } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java index 4841b4b..dbee240 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitLoggingMapper.java @@ -1,7 +1,6 @@ package ee.bitweb.core.retrofit.logging.mappers; import ee.bitweb.core.exception.CoreException; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; @@ -9,15 +8,15 @@ public interface RetrofitLoggingMapper { - String getValue(Connection connection, Request request, Response response); + String getValue(Request request, Response response); String getKey(); - default void map(Connection connection, Request request, Response response, Map container) { + default void map(Request request, Response response, Map container) { if (container.containsKey(getKey())) { throw new CoreException(String.format("Retrofit log container already contains value for key %s", getKey())); } - container.put(getKey(), getValue(connection, request, response)); + container.put(getKey(), getValue(request, response)); } } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java index 4842bc6..452a55d 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java @@ -2,7 +2,6 @@ import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; import okio.Buffer; @@ -23,7 +22,7 @@ public class RetrofitRequestBodyMapper implements RetrofitLoggingMapper { private final Set redactBodyUrls; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { try { return getRequestBody(request); } catch (IOException e) { @@ -37,6 +36,16 @@ public String getKey() { return KEY; } + /** + * Stub method to be able to add custom sanitization of body. For example removing passwords and other sensitive data. + * + * @param body String representation of raw request body + * @return sanitized body + */ + protected String sanitizeBody(String body) { + return body; + } + private String getRequestBody(Request request) throws IOException { var body = request.body(); @@ -61,14 +70,14 @@ private String getRequestBody(Request request) throws IOException { assert charSet != null; var bodyString = buffer.readString(charSet); - if (request.body().contentLength() > maxLoggableRequestSize) { + if (request.body() != null && request.body().contentLength() > maxLoggableRequestSize) { return "%s ... Content size: %s characters".formatted( bodyString.substring(0, maxLoggableRequestSize), request.body().contentLength() ); } - return bodyString; + return sanitizeBody(bodyString); } else { return ("binary body omitted"); } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java index c0f6186..c14307f 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java @@ -2,7 +2,6 @@ import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; @@ -15,7 +14,7 @@ public class RetrofitRequestBodySizeMapper implements RetrofitLoggingMapper { public static final String KEY = "RequestBodySize"; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { try { return request.body() != null ? String.valueOf(request.body().contentLength()) : "-"; } catch (IOException e) { diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java index b299109..bf1ac4a 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java @@ -20,7 +20,7 @@ public class RetrofitRequestHeadersMapper implements RetrofitLoggingMapper { private final Set redactHeaders; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { try { return getRequestHeadersString(request); } catch (IOException e) { diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java index 05e7b50..b441e2f 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java @@ -1,7 +1,6 @@ package ee.bitweb.core.retrofit.logging.mappers; import lombok.RequiredArgsConstructor; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; @@ -16,7 +15,7 @@ public String getKey() { } @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { return request.method(); } } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java deleted file mode 100644 index 6975030..0000000 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestProtocolMapper.java +++ /dev/null @@ -1,22 +0,0 @@ -package ee.bitweb.core.retrofit.logging.mappers; - -import lombok.RequiredArgsConstructor; -import okhttp3.Connection; -import okhttp3.Request; -import okhttp3.Response; - -@RequiredArgsConstructor -public class RetrofitRequestProtocolMapper implements RetrofitLoggingMapper { - - public static final String KEY = "RequestProtocol"; - - @Override - public String getValue(Connection connection, Request request, Response response) { - return connection != null ? connection.protocol().toString() : "-"; - } - - @Override - public String getKey() { - return KEY; - } -} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java index 383b567..a3011e2 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java @@ -1,7 +1,6 @@ package ee.bitweb.core.retrofit.logging.mappers; import lombok.RequiredArgsConstructor; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; @@ -11,7 +10,7 @@ public class RetrofitRequestUrlMapper implements RetrofitLoggingMapper { public static final String KEY = "RequestUrl"; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { return request.url().toString(); } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java index c4003a9..48b9c46 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java @@ -2,7 +2,6 @@ import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; import okio.Buffer; @@ -24,7 +23,7 @@ public class RetrofitResponseBodyMapper implements RetrofitLoggingMapper { private final int maxLoggableResponseSize; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { try { return getResponseBody(response); } catch (IOException e) { @@ -52,6 +51,16 @@ protected String getResponseBody(Response response) throws IOException { } } + /** + * Stub method to be able to add custom sanitization of body. For example removing passwords and other sensitive data. + * + * @param body String representation of raw response body + * @return sanitized body + */ + protected String sanitizeBody(String body) { + return body; + } + private String parseBody(Response response) throws IOException { var responseBody = response.body(); var contentType = responseBody.contentType(); @@ -83,7 +92,7 @@ private String parseBody(Response response) throws IOException { ); } - return bodyString; + return sanitizeBody(bodyString); } else { return ""; } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java index 33c0dd9..4d51059 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java @@ -1,7 +1,6 @@ package ee.bitweb.core.retrofit.logging.mappers; import lombok.RequiredArgsConstructor; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; @@ -11,7 +10,7 @@ public class RetrofitResponseBodySizeMapper implements RetrofitLoggingMapper { public static final String KEY = "ResponseBodySize"; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { return response.body() != null ? String.valueOf(response.body().contentLength()) : "-"; } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java index aebb6a8..30a88f9 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java @@ -18,7 +18,7 @@ public class RetrofitResponseHeadersMapper implements RetrofitLoggingMapper { private final Set redactHeaders; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { return getResponseHeadersString(response); } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java deleted file mode 100644 index 6287424..0000000 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseMessageMapper.java +++ /dev/null @@ -1,22 +0,0 @@ -package ee.bitweb.core.retrofit.logging.mappers; - -import lombok.RequiredArgsConstructor; -import okhttp3.Connection; -import okhttp3.Request; -import okhttp3.Response; - -@RequiredArgsConstructor -public class RetrofitResponseMessageMapper implements RetrofitLoggingMapper { - - public static final String KEY = "ResponseMessage"; - - @Override - public String getValue(Connection connection, Request request, Response response) { - return response.message(); - } - - @Override - public String getKey() { - return KEY; - } -} diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java index 58d690a..4fcd73b 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java @@ -1,7 +1,6 @@ package ee.bitweb.core.retrofit.logging.mappers; import lombok.RequiredArgsConstructor; -import okhttp3.Connection; import okhttp3.Request; import okhttp3.Response; @@ -11,7 +10,7 @@ public class RetrofitResponseStatusCodeMapper implements RetrofitLoggingMapper { public static final String KEY = "ResponseCode"; @Override - public String getValue(Connection connection, Request request, Response response) { + public String getValue(Request request, Response response) { return String.valueOf(response.code()); } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java index 84945fc..2c88914 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java @@ -1,5 +1,6 @@ package ee.bitweb.core.retrofit.logging.writers; +import ee.bitweb.core.exception.CoreException; import ee.bitweb.core.retrofit.logging.RetrofitLoggingInterceptorImplementation; import ee.bitweb.core.retrofit.logging.mappers.RetrofitRequestMethodMapper; import ee.bitweb.core.retrofit.logging.mappers.RetrofitRequestUrlMapper; @@ -30,20 +31,38 @@ public void write(Map container) { } } - private void log(Map container) { + protected void log(Map container) { container.forEach(MDC::put); - log.info( - "Method({}), URL({}) Status({}) ResponseSize({}) Duration({} ms)", - get(container, RetrofitRequestMethodMapper.KEY), - get(container, RetrofitRequestUrlMapper.KEY), - get(container, RetrofitResponseStatusCodeMapper.KEY), - get(container, RetrofitResponseBodySizeMapper.KEY), - get(container, RetrofitLoggingInterceptorImplementation.DURATION_KEY) - ); + if (!log.isInfoEnabled()) { + logOrThrowError(); + } else { + log.info( + "{} {} {} {}bytes {}ms", + get(container, RetrofitRequestMethodMapper.KEY), + get(container, RetrofitRequestUrlMapper.KEY), + get(container, RetrofitResponseStatusCodeMapper.KEY), + get(container, RetrofitResponseBodySizeMapper.KEY), + get(container, RetrofitLoggingInterceptorImplementation.DURATION_KEY) + ); + } + } + + protected void logOrThrowError() { + String message = ( + "Retrofit interceptor has been enabled, but %s cannot write as log level does not permit INFO entries. This behaviour is strongly " + + "discouraged as the interceptor consumes resources for no real result. Please set property " + + "ee.bitweb.core.retrofit.logging-level=NONE if you wish to avoid this logging." + ).formatted(RetrofitLogLoggerWriterAdapter.class.getSimpleName()); + + if (log.isErrorEnabled()) { + log.error(message); + } else { + throw new CoreException(message); + } } - private String get(Map container, String key) { + protected String get(Map container, String key) { if (container.containsKey(key)) { return container.get(key); } diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java index 9ab17ed..c15c565 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java @@ -5,6 +5,7 @@ import ch.qos.logback.classic.LoggerContext; import ee.bitweb.core.TestSpringApplication; import ee.bitweb.core.retrofit.RetrofitProperties; +import ee.bitweb.core.retrofit.builder.LoggingLevel; import ee.bitweb.core.retrofit.builder.SpringAwareRetrofitBuilder; import ee.bitweb.core.retrofit.helpers.ExternalServiceApi; import ee.bitweb.core.trace.context.TraceIdContext; @@ -23,15 +24,15 @@ import java.util.ArrayList; import java.util.regex.Pattern; -import static org.junit.jupiter.api.Assertions.assertEquals; -import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.junit.jupiter.api.Assertions.*; @Tag("integration") @SpringBootTest( classes = TestSpringApplication.class, properties = { "ee.bitweb.core.trace.auto-configuration=true", - "ee.bitweb.core.retrofit.auto-configuration=true" + "ee.bitweb.core.retrofit.auto-configuration=true", + "ee.bitweb.core.retrofit.logging.level=body" } ) @ActiveProfiles("retrofit") @@ -80,8 +81,10 @@ void afterEach() { } @Test - @DisplayName("Logging level NONE") - void loggingLevelNone() throws Exception { + @DisplayName("Logging level BODY") + void loggingLevelBody() throws Exception { + retrofitProperties.getLogging().setLevel(LoggingLevel.BODY); + executeRetrofitRequest(); assertEquals(1, memoryAppender.getSize()); @@ -89,43 +92,37 @@ void loggingLevelNone() throws Exception { assertLogLevel(); assertLogMessage(); - assertEquals(13, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()); - assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")); - assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")); - assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")); - assertTrue( - Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() - ); - assertEquals("-", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestProtocol")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("Duration")).find() - ); - assertEquals("OK", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseMessage")); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")).find() - ); - assertTrue( - Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")).find() - ); - assertEquals( - "Content-Length: 32; Content-Type: application; X-Trace-ID: TEST", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") - ); - assertEquals( - "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") - ); - assertEquals( - "{\"message\":\"message1\",\"value\":1}", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") - ); - assertEquals( - "{\"message\":\"message2\",\"value\":2}", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") + assertAll( + () -> assertEquals(11, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()), + () -> assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")), + () -> assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")), + () -> assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")), + () -> assertTrue( + Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() + ), + () -> assertTrue( + Pattern.compile("[0-9]*") + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("Duration")).find() + ), + () -> assertEquals("34", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")), + () -> assertEquals("32", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")), + () -> assertEquals( + "Content-Length: 34; Content-Type: application; X-Trace-ID: TEST", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") + ), + () -> assertEquals( + "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") + ), + () -> assertEquals( + "{\"message\":\"message123\",\"value\":1}", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") + ), + () -> assertEquals( + "{\"message\":\"message2\",\"value\":2}", + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") + ) ); } @@ -134,9 +131,8 @@ private void assertLogLevel() { } private void assertLogMessage() { - logger.info(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()); assertTrue(Pattern.compile( - "Method\\(POST\\), URL\\(http:\\/\\/localhost:[0-9]*\\/data-post\\) Status\\(200\\) ResponseSize\\([0-9]*\\) Duration\\([0-9]* ms\\)" + "POST http:\\/\\/localhost:[0-9]*\\/data-post 200 [0-9]*bytes [0-9]*ms" ).matcher(memoryAppender.getLoggedEvents().get(0).getFormattedMessage()).find()); } @@ -145,7 +141,7 @@ private void executeRetrofitRequest() throws IOException { mockServerRequest(); - api.postData(new ExternalServiceApi.Payload("message1", 1)).execute(); + api.postData(new ExternalServiceApi.Payload("message123", 1)).execute(); } private static void mockServerRequest() { @@ -163,4 +159,4 @@ private static JSONObject createPayload() { return payload; } -} \ No newline at end of file +} diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java index 9dfeb8e..caaa661 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java @@ -29,7 +29,7 @@ void isRedactUrl() { new HashMap<>() ); - var value = mapper.getValue(null, request, null); + var value = mapper.getValue(request, null); Assertions.assertEquals("(body redacted)", value); } @@ -50,7 +50,7 @@ void bodyHasUnknownEncoding() { new HashMap<>() ); - var value = mapper.getValue(null, request, null); + var value = mapper.getValue(request, null); Assertions.assertEquals("(encoded body omitted)", value); } @@ -71,8 +71,8 @@ void maxLoggableRequestSize() { new HashMap<>() ); - var value = mapper.getValue(null, request, null); + var value = mapper.getValue(request, null); Assertions.assertEquals("12 ... Content size: 3 characters", value); } -} \ No newline at end of file +} diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java index 07a46a2..c605aba 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java @@ -36,7 +36,7 @@ void isRedactUrl() { null ); - var value = mapper.getValue(null, null, response); + var value = mapper.getValue(null, response); Assertions.assertEquals("(body redacted)", value); } @@ -62,7 +62,7 @@ void promisesBody() { null ); - var value = mapper.getValue(null, null, response); + var value = mapper.getValue(null, response); Assertions.assertEquals("", value); } @@ -88,7 +88,7 @@ void bodyHasUnknownEncoding() { null ); - var value = mapper.getValue(null, null, response); + var value = mapper.getValue(null, response); Assertions.assertEquals("(encoded body omitted)", value); } @@ -114,7 +114,7 @@ void bodyMissing() { null ); - var value = mapper.getValue(null, null, response); + var value = mapper.getValue(null, response); Assertions.assertEquals("(body missing)", value); } @@ -131,4 +131,4 @@ private Request request(String method) { new HashMap<>() ); } -} \ No newline at end of file +} From 3b824196fd3afda14ab823a53d3184af2fe273f2 Mon Sep 17 00:00:00 2001 From: Rain Ramm Date: Mon, 4 Nov 2024 11:22:45 +0200 Subject: [PATCH 10/14] Add and improve tests --- .../RetrofitRequestBodySizeMapper.java | 5 +- .../mappers/RetrofitResponseBodyMapper.java | 3 +- .../RetrofitLogLoggerWriterAdapter.java | 2 + .../RetrofitRequestBodySizeMapperTest.java | 67 ++++++++ .../RetrofitResponseBodyMapperTest.java | 114 ++++++++++++- .../RetrofitLogLoggerWriterAdapterTest.java | 151 ++++++++++++++++++ 6 files changed, 334 insertions(+), 8 deletions(-) create mode 100644 src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapperTest.java create mode 100644 src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java index c14307f..55ea27f 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java @@ -3,6 +3,7 @@ import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; import okhttp3.Request; +import okhttp3.RequestBody; import okhttp3.Response; import java.io.IOException; @@ -16,7 +17,9 @@ public class RetrofitRequestBodySizeMapper implements RetrofitLoggingMapper { @Override public String getValue(Request request, Response response) { try { - return request.body() != null ? String.valueOf(request.body().contentLength()) : "-"; + RequestBody body = request.body(); + + return body != null ? String.valueOf(body.contentLength()) : "-"; } catch (IOException e) { log.error("Failed to parse request content length.", e); return "Parse error."; diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java index 48b9c46..2edb36f 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java @@ -71,9 +71,8 @@ private String parseBody(Response response) throws IOException { source.request(Long.MAX_VALUE); var buffer = source.getBuffer(); - Long gzippedLength = null; if ("gzip".equalsIgnoreCase(response.header("Content-Encoding"))) { - gzippedLength = buffer.size(); + long gzippedLength = buffer.size(); var gzipSource = new GzipSource(buffer.clone()); buffer = new Buffer(); gzipSource.read(buffer, gzippedLength); diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java index 2c88914..df463ed 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapter.java @@ -27,6 +27,8 @@ public void write(Map container) { } finally { if (currentContext != null) { MDC.setContextMap(currentContext); + } else { + MDC.clear(); } } } diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapperTest.java new file mode 100644 index 0000000..4ac0aa5 --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapperTest.java @@ -0,0 +1,67 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import okhttp3.Request; +import okhttp3.RequestBody; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.ExtendWith; +import org.mockito.Mock; +import org.mockito.Mockito; +import org.mockito.junit.jupiter.MockitoExtension; + +import java.io.IOException; + +import static org.junit.jupiter.api.Assertions.*; + +@Tag("unit") +@ExtendWith(MockitoExtension.class) +class RetrofitRequestBodySizeMapperTest { + + @Mock + Request request; + + @Mock + RequestBody requestBody; + + @Test + @DisplayName("Returns correct request size") + void testRequestBodyLengthIsSuccessfullyRetrieved() throws IOException { + Mockito.when(request.body()).thenReturn(requestBody); + Mockito.when(requestBody.contentLength()).thenReturn(123L); + RetrofitRequestBodySizeMapper mapper = new RetrofitRequestBodySizeMapper(); + + assertEquals("123", mapper.getValue(request, null)); + + Mockito.verify(request, Mockito.times(1)).body(); + Mockito.verify(requestBody, Mockito.times(1)).contentLength(); + Mockito.verifyNoMoreInteractions(request, requestBody); + } + + @Test + @DisplayName("When request body is not available, should return '-'") + void testRequestBodyIsNotAvailable() { + Mockito.when(request.body()).thenReturn(null); + RetrofitRequestBodySizeMapper mapper = new RetrofitRequestBodySizeMapper(); + + assertEquals("-", mapper.getValue(request, null)); + + Mockito.verify(request, Mockito.times(1)).body(); + Mockito.verifyNoMoreInteractions(request); + Mockito.verifyNoInteractions(requestBody); + } + + @Test + @DisplayName("When request body content size throws exception, should return 'Parse error.'") + void testRequestBodySizeThrowsException() throws IOException { + Mockito.when(request.body()).thenReturn(requestBody); + Mockito.when(requestBody.contentLength()).thenThrow(IOException.class); + RetrofitRequestBodySizeMapper mapper = new RetrofitRequestBodySizeMapper(); + + assertEquals("Parse error.", mapper.getValue(request, null)); + + Mockito.verify(request, Mockito.times(1)).body(); + Mockito.verify(requestBody, Mockito.times(1)).contentLength(); + Mockito.verifyNoMoreInteractions(request, requestBody); + } +} diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java index c605aba..8dc80a6 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapperTest.java @@ -1,14 +1,16 @@ package ee.bitweb.core.retrofit.logging.mappers; import okhttp3.*; -import org.junit.jupiter.api.Assertions; import org.junit.jupiter.api.DisplayName; import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; +import java.io.ByteArrayOutputStream; +import java.io.IOException; import java.util.HashMap; import java.util.HashSet; import java.util.Set; +import java.util.zip.GZIPOutputStream; import static org.junit.jupiter.api.Assertions.*; @@ -38,7 +40,7 @@ void isRedactUrl() { var value = mapper.getValue(null, response); - Assertions.assertEquals("(body redacted)", value); + assertEquals("(body redacted)", value); } @Test @@ -64,7 +66,7 @@ void promisesBody() { var value = mapper.getValue(null, response); - Assertions.assertEquals("", value); + assertEquals("", value); } @Test @@ -90,7 +92,7 @@ void bodyHasUnknownEncoding() { var value = mapper.getValue(null, response); - Assertions.assertEquals("(encoded body omitted)", value); + assertEquals("(encoded body omitted)", value); } @Test @@ -116,7 +118,99 @@ void bodyMissing() { var value = mapper.getValue(null, response); - Assertions.assertEquals("(body missing)", value); + assertEquals("(body missing)", value); + } + + @Test + @DisplayName("Response body is correctly returned") + void bodyAvailable() { + var mapper = new RetrofitResponseBodyMapper(new HashSet<>(), 4096); + var response = new Response( + request("GET"), + Protocol.HTTP_2, + "OK", + 200, + null, + new Headers.Builder().build(), + ResponseBody.create("123".getBytes(), MediaType.get("application/text")), + null, + null, + null, + 1, + 2, + null + ); + + assertEquals("123", mapper.getValue(null, response)); + } + + @Test + @DisplayName("Response body is correctly shortened") + void bodyIsShortened() { + var mapper = new RetrofitResponseBodyMapper(new HashSet<>(), 2); + var response = new Response( + request("GET"), + Protocol.HTTP_2, + "OK", + 200, + null, + new Headers.Builder().build(), + ResponseBody.create("123".getBytes(), MediaType.get("application/text")), + null, + null, + null, + 1, + 2, + null + ); + + assertEquals("12 ... Content size: 3 characters", mapper.getValue(null, response)); + } + + @Test + @DisplayName("Response body is correctly returned when empty") + void bodyIsEmpty() { + var mapper = new RetrofitResponseBodyMapper(new HashSet<>(), 4096); + var response = new Response( + request("GET"), + Protocol.HTTP_2, + "OK", + 200, + null, + new Headers.Builder().build(), + ResponseBody.create(new byte[]{}, MediaType.get("application/text")), + null, + null, + null, + 1, + 2, + null + ); + + assertEquals("", mapper.getValue(null, response)); + } + + @Test + @DisplayName("Response body is correctly returned when response is gzipped") + void bodyIsGzipped() throws IOException { + var mapper = new RetrofitResponseBodyMapper(new HashSet<>(), 4096); + var response = new Response( + request("GET"), + Protocol.HTTP_2, + "OK", + 200, + null, + new Headers.Builder().add("Content-Encoding", "gzip").build(), + ResponseBody.create(gzip("some amount of data"), MediaType.get("application/text")), + null, + null, + null, + 1, + 2, + null + ); + + assertEquals("some amount of data", mapper.getValue(null, response)); } private Request request(String method) { @@ -131,4 +225,14 @@ private Request request(String method) { new HashMap<>() ); } + + private byte[] gzip(String data) throws IOException { + ByteArrayOutputStream os = new ByteArrayOutputStream(); + GZIPOutputStream gzipOs = new GZIPOutputStream(os); + byte[] buffer = data.getBytes(); + gzipOs.write(buffer, 0, buffer.length); + gzipOs.close(); + + return os.toByteArray(); + } } diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java new file mode 100644 index 0000000..4d96a78 --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java @@ -0,0 +1,151 @@ +package ee.bitweb.core.retrofit.logging.writers; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.Logger; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ee.bitweb.core.exception.CoreException; +import ee.bitweb.core.utils.MemoryAppender; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; +import org.slf4j.MDC; + +import java.util.Map; + +import static org.junit.jupiter.api.Assertions.*; + +@Tag("unit") +class RetrofitLogLoggerWriterAdapterTest { + + Logger logger; + MemoryAppender memoryAppender; + + @BeforeEach + void setUp() { + logger = (Logger) LoggerFactory.getLogger("RetrofitLogger"); + memoryAppender = new MemoryAppender(); + memoryAppender.setContext((LoggerContext) LoggerFactory.getILoggerFactory()); + logger.setLevel(Level.INFO); + logger.addAppender(memoryAppender); + memoryAppender.start(); + } + + @Test + @DisplayName("Event is logged with correct MDC and MDC is restored") + void testMessageIsWrittenToLoggerWithCorrectContext() { + // given + MDC.put("current", "1"); + Map container = Map.of( + "RequestMethod", "GET", + "RequestUrl", "https://localhost:3000/api?data=true&test", + "ResponseCode", "404", + "Duration", "14" + ); + RetrofitLogLoggerWriterAdapter writer = new RetrofitLogLoggerWriterAdapter(); + + // when + writer.write(container); + + // then validate logging event + assertEquals(1, memoryAppender.getSize()); + ILoggingEvent loggingEvent = memoryAppender.getLoggedEvents().get(0); + assertEquals(Level.INFO, loggingEvent.getLevel()); + assertEquals("GET https://localhost:3000/api?data=true&test 404 -bytes 14ms", loggingEvent.getFormattedMessage()); + + // then validate logging event MDC + assertAll( + () -> assertEquals(5, loggingEvent.getMDCPropertyMap().size()), + () -> assertEquals("1", loggingEvent.getMDCPropertyMap().get("current")), + () -> assertEquals("404", loggingEvent.getMDCPropertyMap().get("ResponseCode")), + () -> assertEquals("GET", loggingEvent.getMDCPropertyMap().get("RequestMethod")), + () -> assertEquals("https://localhost:3000/api?data=true&test", loggingEvent.getMDCPropertyMap().get("RequestUrl")), + () -> assertEquals("14", loggingEvent.getMDCPropertyMap().get("Duration")), + () -> assertNull(loggingEvent.getMDCPropertyMap().get("ResponseBodySize")) + ); + + // then validate current MDC + assertAll( + () -> assertEquals(1, MDC.getCopyOfContextMap().size()), + () -> assertEquals("1", MDC.getCopyOfContextMap().get("current")) + ); + } + + @Test + @DisplayName("Event is logged with correct MDC and an empty MDC is restored") + void validateMdcIsRestoredWhenEmpty() { + // given + Map container = Map.of( + "RequestMethod", "GET", + "RequestUrl", "https://localhost:3000/api?data=true&test", + "ResponseCode", "404", + "ResponseBodySize", "0", + "Duration", "14" + ); + RetrofitLogLoggerWriterAdapter writer = new RetrofitLogLoggerWriterAdapter(); + + // when + writer.write(container); + + // then validate current MDC + assertAll( + () -> assertNull(MDC.getCopyOfContextMap()) + ); + } + + @Test + @DisplayName("Error should be logged when logging level less than INFO") + void validateErrorIsLoggedWhenLoggingLevelIsLessThanInfo() { + // given + Map container = Map.of( + "RequestMethod", "GET", + "RequestUrl", "https://localhost:3000/api?data=true&test", + "ResponseCode", "404", + "ResponseBodySize", "0", + "Duration", "14" + ); + RetrofitLogLoggerWriterAdapter writer = new RetrofitLogLoggerWriterAdapter(); + logger.setLevel(Level.WARN); + + // when + writer.write(container); + + // then + assertEquals(1, memoryAppender.getSize()); + ILoggingEvent loggingEvent = memoryAppender.getLoggedEvents().get(0); + assertEquals(Level.ERROR, loggingEvent.getLevel()); + assertEquals( + "Retrofit interceptor has been enabled, but RetrofitLogLoggerWriterAdapter cannot write as log level does not permit INFO entries. " + + "This behaviour is strongly discouraged as the interceptor consumes resources for no real result. Please set property " + + "ee.bitweb.core.retrofit.logging-level=NONE if you wish to avoid this logging.", + loggingEvent.getFormattedMessage() + ); + } + + @Test + void validateExceptionIsThrownWhenLoggingLevelIsLessThanError() { + // given + Map container = Map.of( + "RequestMethod", "GET", + "RequestUrl", "https://localhost:3000/api?data=true&test", + "ResponseCode", "404", + "ResponseBodySize", "0", + "Duration", "14" + ); + RetrofitLogLoggerWriterAdapter writer = new RetrofitLogLoggerWriterAdapter(); + logger.setLevel(Level.OFF); + + // when + CoreException ex = assertThrows(CoreException.class, () -> writer.write(container)); + + // then + assertEquals( + "Retrofit interceptor has been enabled, but RetrofitLogLoggerWriterAdapter cannot write as log level does not permit INFO entries. " + + "This behaviour is strongly discouraged as the interceptor consumes resources for no real result. Please set property " + + "ee.bitweb.core.retrofit.logging-level=NONE if you wish to avoid this logging.", + ex.getMessage() + ); + } +} From d357824699c7ec0ed5cabaaf86ec3aae0fa8b877 Mon Sep 17 00:00:00 2001 From: Rain Ramm Date: Mon, 4 Nov 2024 11:37:51 +0200 Subject: [PATCH 11/14] Always upload test artifacts --- .github/workflows/build.yml | 15 ++++++++------- 1 file changed, 8 insertions(+), 7 deletions(-) diff --git a/.github/workflows/build.yml b/.github/workflows/build.yml index b479a15..274c167 100644 --- a/.github/workflows/build.yml +++ b/.github/workflows/build.yml @@ -33,20 +33,21 @@ jobs: - name: Run tests and generate reports run: ./gradlew testAndReport - - name: Run Sonar analysis - if: matrix.Java == '17' - env: - GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }} - SONAR_TOKEN: ${{ secrets.SONAR_TOKEN }} - run: ./gradlew sonar -x test --no-watch-fs - - name: Upload Artifact uses: actions/upload-artifact@v4 + if: always() with: name: report-java-${{ matrix.Java }} path: build/reports/** retention-days: 5 + - name: Run Sonar analysis + if: matrix.Java == '17' + env: + GITHUB_TOKEN: ${{ secrets.GITHUB_TOKEN }} + SONAR_TOKEN: ${{ secrets.SONAR_TOKEN }} + run: ./gradlew sonar -x test --no-watch-fs + build: runs-on: ubuntu-latest needs: [test] From 2fdc22f746a25dde59d60aaa6973d01df0a3dbb3 Mon Sep 17 00:00:00 2001 From: Rain Ramm Date: Mon, 4 Nov 2024 14:56:20 +0200 Subject: [PATCH 12/14] Change mapper names to snake_case Add tests --- .../writers/AuditLogLoggerWriterAdapter.java | 2 + ...rofitLoggingInterceptorImplementation.java | 2 +- .../mappers/RetrofitRequestBodyMapper.java | 2 +- .../RetrofitRequestBodySizeMapper.java | 2 +- .../mappers/RetrofitRequestHeadersMapper.java | 2 +- .../mappers/RetrofitRequestMethodMapper.java | 2 +- .../mappers/RetrofitRequestUrlMapper.java | 2 +- .../mappers/RetrofitResponseBodyMapper.java | 2 +- .../RetrofitResponseBodySizeMapper.java | 7 +- .../RetrofitResponseHeadersMapper.java | 2 +- .../RetrofitResponseStatusCodeMapper.java | 2 +- .../AuditLogLoggerWriterAdapterUnitTests.java | 56 ++++++++------ .../core/retrofit/RetrofitPropertiesTest.java | 43 +++++++++++ .../retrofit/builder/LoggingLevelTest.java | 76 +++++++++++++++++++ .../RetrofitLoggingInterceptorTest.java | 20 ++--- .../RetrofitResponseBodySizeMapperTest.java | 51 +++++++++++++ .../RetrofitLogLoggerWriterAdapterTest.java | 28 +++---- 17 files changed, 245 insertions(+), 56 deletions(-) create mode 100644 src/test/java/ee/bitweb/core/retrofit/RetrofitPropertiesTest.java create mode 100644 src/test/java/ee/bitweb/core/retrofit/builder/LoggingLevelTest.java create mode 100644 src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapperTest.java diff --git a/src/main/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapter.java b/src/main/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapter.java index 1facf18..d56bd7b 100644 --- a/src/main/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapter.java +++ b/src/main/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapter.java @@ -41,6 +41,8 @@ public void write(Map container) { if (currentContext != null) { MDC.setContextMap(currentContext); + } else { + MDC.clear(); } } diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java index 88b8715..340474c 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorImplementation.java @@ -15,7 +15,7 @@ @RequiredArgsConstructor public class RetrofitLoggingInterceptorImplementation implements RetrofitLoggingInterceptor { - public static final String DURATION_KEY = "Duration"; + public static final String DURATION_KEY = "duration"; private final List mappers; private final RetrofitLogWriteAdapter writer; diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java index 452a55d..587fab5 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java @@ -16,7 +16,7 @@ @RequiredArgsConstructor public class RetrofitRequestBodyMapper implements RetrofitLoggingMapper { - public static final String KEY = "RequestBody"; + public static final String KEY = "request_body"; private final int maxLoggableRequestSize; private final Set redactBodyUrls; diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java index 55ea27f..1c567e8 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodySizeMapper.java @@ -12,7 +12,7 @@ @RequiredArgsConstructor public class RetrofitRequestBodySizeMapper implements RetrofitLoggingMapper { - public static final String KEY = "RequestBodySize"; + public static final String KEY = "request_body_size"; @Override public String getValue(Request request, Response response) { diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java index bf1ac4a..9ea787b 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestHeadersMapper.java @@ -15,7 +15,7 @@ @RequiredArgsConstructor public class RetrofitRequestHeadersMapper implements RetrofitLoggingMapper { - public static final String KEY = "RequestHeaders"; + public static final String KEY = "request_headers"; private final Set redactHeaders; diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java index b441e2f..2febfad 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestMethodMapper.java @@ -7,7 +7,7 @@ @RequiredArgsConstructor public class RetrofitRequestMethodMapper implements RetrofitLoggingMapper { - public static final String KEY = "RequestMethod"; + public static final String KEY = "request_method"; @Override public String getKey() { diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java index a3011e2..1afac97 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestUrlMapper.java @@ -7,7 +7,7 @@ @RequiredArgsConstructor public class RetrofitRequestUrlMapper implements RetrofitLoggingMapper { - public static final String KEY = "RequestUrl"; + public static final String KEY = "request_url"; @Override public String getValue(Request request, Response response) { diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java index 2edb36f..2fd9274 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodyMapper.java @@ -17,7 +17,7 @@ @RequiredArgsConstructor public class RetrofitResponseBodyMapper implements RetrofitLoggingMapper { - public static final String KEY = "ResponseBody"; + public static final String KEY = "response_body"; private final Set redactBodyUrls; private final int maxLoggableResponseSize; diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java index 4d51059..f2d3503 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapper.java @@ -3,15 +3,18 @@ import lombok.RequiredArgsConstructor; import okhttp3.Request; import okhttp3.Response; +import okhttp3.ResponseBody; @RequiredArgsConstructor public class RetrofitResponseBodySizeMapper implements RetrofitLoggingMapper { - public static final String KEY = "ResponseBodySize"; + public static final String KEY = "response_body_size"; @Override public String getValue(Request request, Response response) { - return response.body() != null ? String.valueOf(response.body().contentLength()) : "-"; + ResponseBody body = response.body(); + + return body != null ? String.valueOf(body.contentLength()) : "-"; } @Override diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java index 30a88f9..2dc3b63 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseHeadersMapper.java @@ -13,7 +13,7 @@ @RequiredArgsConstructor public class RetrofitResponseHeadersMapper implements RetrofitLoggingMapper { - public static final String KEY = "ResponseHeaders"; + public static final String KEY = "response_headers"; private final Set redactHeaders; diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java index 4fcd73b..36528f6 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseStatusCodeMapper.java @@ -7,7 +7,7 @@ @RequiredArgsConstructor public class RetrofitResponseStatusCodeMapper implements RetrofitLoggingMapper { - public static final String KEY = "ResponseCode"; + public static final String KEY = "response_code"; @Override public String getValue(Request request, Response response) { diff --git a/src/test/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapterUnitTests.java b/src/test/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapterUnitTests.java index f088097..f4df90e 100644 --- a/src/test/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapterUnitTests.java +++ b/src/test/java/ee/bitweb/core/audit/writers/AuditLogLoggerWriterAdapterUnitTests.java @@ -4,21 +4,24 @@ import ch.qos.logback.classic.Logger; import ch.qos.logback.classic.LoggerContext; import ch.qos.logback.classic.spi.ILoggingEvent; -import ee.bitweb.core.audit.AuditLogFilter; -import ee.bitweb.core.audit.mappers.*; import ee.bitweb.core.utils.MemoryAppender; -import org.junit.jupiter.api.Assertions; +import org.junit.jupiter.api.AfterEach; import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; import org.junit.jupiter.api.extension.ExtendWith; import org.mockito.junit.jupiter.MockitoExtension; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import org.springframework.http.HttpStatus; import java.util.HashMap; import java.util.List; import java.util.Map; +import static org.junit.jupiter.api.Assertions.*; + +@Tag("unit") @ExtendWith(MockitoExtension.class) class AuditLogLoggerWriterAdapterUnitTests { @@ -37,6 +40,11 @@ void beforeEach() { memoryAppender.start(); } + @AfterEach + void tearDown() { + MDC.clear(); + } + @Test void createASingleLogWithNoSecondaryFields() { @@ -44,26 +52,30 @@ void createASingleLogWithNoSecondaryFields() { List events = memoryAppender.getLoggedEvents(); - Assertions.assertEquals(1, events.size()); - Assertions.assertEquals( + assertEquals(1, events.size()); + assertEquals( "Method(POST), URL(/some-url) Status(200 OK) ResponseSize(9) Duration(123 ms)", events.get(0).getFormattedMessage() ); - Assertions.assertEquals(8, events.get(0).getMDCPropertyMap().size()); + assertEquals(8, events.get(0).getMDCPropertyMap().size()); + assertNull(MDC.getCopyOfContextMap()); } @Test void createASingleLogWithSecondaryFieldsAndDebugDisabled() { + MDC.put("key", "value"); adapter.write(createDefaultMap()); List events = memoryAppender.getLoggedEvents(); - Assertions.assertEquals(1, events.size()); - Assertions.assertEquals( + assertEquals(1, events.size()); + assertEquals( "Method(POST), URL(/some-url) Status(200 OK) ResponseSize(9) Duration(123 ms)", events.get(0).getFormattedMessage() ); - Assertions.assertEquals(8, events.get(0).getMDCPropertyMap().size()); + assertEquals(8, events.get(0).getMDCPropertyMap().size()); + assertEquals(1, MDC.getCopyOfContextMap().size()); + assertEquals("value", MDC.get("key")); } @Test @@ -73,31 +85,31 @@ void createASecondaryLogWithSecondaryFieldsAndDebugEnabled() { List events = memoryAppender.getLoggedEvents(); - Assertions.assertEquals(2, events.size()); - Assertions.assertEquals( + assertEquals(2, events.size()); + assertEquals( "Method(POST), URL(/some-url) Status(200 OK) ResponseSize(9) Duration(123 ms)", events.get(0).getFormattedMessage() ); - Assertions.assertEquals( + assertEquals( "Debug audit log", events.get(1).getFormattedMessage() ); - Assertions.assertEquals(8, events.get(0).getMDCPropertyMap().size()); - Assertions.assertEquals(4, events.get(1).getMDCPropertyMap().size()); - + assertEquals(8, events.get(0).getMDCPropertyMap().size()); + assertEquals(4, events.get(1).getMDCPropertyMap().size()); + assertNull(MDC.getCopyOfContextMap()); } public Map createDefaultMap() { Map map = new HashMap<>(); - map.put(TraceIdMapper.KEY, "some-trace-id"); - map.put(ResponseStatusMapper.KEY, HttpStatus.OK.toString()); - map.put(RequestUrlDataMapper.KEY, "/some-url"); - map.put(AuditLogFilter.DURATION_KEY, "123"); - map.put(RequestMethodMapper.KEY, "POST"); - map.put(RequestBodyMapper.KEY, "Some payload"); - map.put(ResponseBodyMapper.KEY, "Some body"); + map.put("trace_id", "some-trace-id"); + map.put("response_status", HttpStatus.OK.toString()); + map.put("url", "/some-url"); + map.put("duration", "123"); + map.put("method", "POST"); + map.put("request_body", "Some payload"); + map.put("response_body", "Some body"); return map; } diff --git a/src/test/java/ee/bitweb/core/retrofit/RetrofitPropertiesTest.java b/src/test/java/ee/bitweb/core/retrofit/RetrofitPropertiesTest.java new file mode 100644 index 0000000..2dafb8c --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/RetrofitPropertiesTest.java @@ -0,0 +1,43 @@ +package ee.bitweb.core.retrofit; + +import ee.bitweb.core.retrofit.builder.LoggingLevel; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; + +import java.util.List; + +import static org.junit.jupiter.api.Assertions.*; + +@Tag("unit") +class RetrofitPropertiesTest { + + @Test + @DisplayName("Must return correct mappers with default config") + void testLoggingReturnsCorrectMappersWithDefaultConfiguration() { + RetrofitProperties.Logging properties = new RetrofitProperties.Logging(); + + assertEquals(5, properties.getMappers().size()); + } + + @Test + @DisplayName("Must return only one custom mapper with level CUSTOM") + void testLoggingReturnsConfiguredMappersWithCustomLevel() { + RetrofitProperties.Logging properties = new RetrofitProperties.Logging(); + properties.setLevel(LoggingLevel.CUSTOM); + properties.getMappers().add("custom-mapper"); + + assertEquals(1, properties.getMappers().size()); + assertEquals("custom-mapper", properties.getMappers().get(0)); + } + + @Test + @DisplayName("Must add custom mappers to default mappers") + void testLoggingReturnMergedMappersWhenAdditionalMappersAreProvided() { + RetrofitProperties.Logging properties = new RetrofitProperties.Logging(); + properties.setMappers(List.of("custom-mapper")); + + assertEquals(6, properties.getMappers().size()); + assertTrue(properties.getMappers().contains("custom-mapper")); + } +} diff --git a/src/test/java/ee/bitweb/core/retrofit/builder/LoggingLevelTest.java b/src/test/java/ee/bitweb/core/retrofit/builder/LoggingLevelTest.java new file mode 100644 index 0000000..1ae38f7 --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/builder/LoggingLevelTest.java @@ -0,0 +1,76 @@ +package ee.bitweb.core.retrofit.builder; + +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; + +import java.util.List; + +import static org.junit.jupiter.api.Assertions.*; + +@Tag("unit") +class LoggingLevelTest { + + @Test + @DisplayName("Ensure correct default mappers for level NONE") + void testLevelNone() { + assertTrue(LoggingLevel.NONE.getMappers().isEmpty()); + } + + @Test + @DisplayName("Ensure correct default mappers for level CUSTOM") + void testLevelCustom() { + assertTrue(LoggingLevel.CUSTOM.getMappers().isEmpty()); + } + + @Test + @DisplayName("Ensure correct default mappers for level BASIC") + void testLevelBasic() { + List mappers = LoggingLevel.BASIC.getMappers(); + + assertAll( + () -> assertEquals(5, mappers.size()), + () -> assertTrue(mappers.contains("request_method")), + () -> assertTrue(mappers.contains("request_url")), + () -> assertTrue(mappers.contains("request_body_size")), + () -> assertTrue(mappers.contains("response_code")), + () -> assertTrue(mappers.contains("response_body_size")) + ); + } + + @Test + @DisplayName("Ensure correct default mappers for level HEADERS") + void testLevelHeaders() { + List mappers = LoggingLevel.HEADERS.getMappers(); + + assertAll( + () -> assertEquals(7, mappers.size()), + () -> assertTrue(mappers.contains("request_method")), + () -> assertTrue(mappers.contains("request_url")), + () -> assertTrue(mappers.contains("request_body_size")), + () -> assertTrue(mappers.contains("response_code")), + () -> assertTrue(mappers.contains("response_body_size")), + () -> assertTrue(mappers.contains("request_headers")), + () -> assertTrue(mappers.contains("response_headers")) + ); + } + + @Test + @DisplayName("Ensure correct default mappers for level BODY") + void testLevelBody() { + List mappers = LoggingLevel.BODY.getMappers(); + + assertAll( + () -> assertEquals(9, mappers.size()), + () -> assertTrue(mappers.contains("request_method")), + () -> assertTrue(mappers.contains("request_url")), + () -> assertTrue(mappers.contains("request_body_size")), + () -> assertTrue(mappers.contains("response_code")), + () -> assertTrue(mappers.contains("response_body_size")), + () -> assertTrue(mappers.contains("request_headers")), + () -> assertTrue(mappers.contains("response_headers")), + () -> assertTrue(mappers.contains("request_body")), + () -> assertTrue(mappers.contains("response_body")) + ); + } +} diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java index c15c565..a8d1f4c 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/RetrofitLoggingInterceptorTest.java @@ -95,33 +95,33 @@ void loggingLevelBody() throws Exception { assertAll( () -> assertEquals(11, memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().size()), () -> assertEquals("TEST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("trace_id")), - () -> assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseCode")), - () -> assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestMethod")), + () -> assertEquals("200", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("response_code")), + () -> assertEquals("POST", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("request_method")), () -> assertTrue( Pattern.compile("http:\\/\\/localhost:[0-9]*\\/data-post") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestUrl")).find() + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("request_url")).find() ), () -> assertTrue( Pattern.compile("[0-9]*") - .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("Duration")).find() + .matcher(memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("duration")).find() ), - () -> assertEquals("34", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBodySize")), - () -> assertEquals("32", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBodySize")), + () -> assertEquals("34", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("request_body_size")), + () -> assertEquals("32", memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("response_body_size")), () -> assertEquals( "Content-Length: 34; Content-Type: application; X-Trace-ID: TEST", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestHeaders") + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("request_headers") ), () -> assertEquals( "connection: keep-alive; Content-Length: 32; Content-Type: application/json; charset=utf-8", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseHeaders") + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("response_headers") ), () -> assertEquals( "{\"message\":\"message123\",\"value\":1}", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("RequestBody") + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("request_body") ), () -> assertEquals( "{\"message\":\"message2\",\"value\":2}", - memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("ResponseBody") + memoryAppender.getLoggedEvents().get(0).getMDCPropertyMap().get("response_body") ) ); } diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapperTest.java new file mode 100644 index 0000000..4262a57 --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitResponseBodySizeMapperTest.java @@ -0,0 +1,51 @@ +package ee.bitweb.core.retrofit.logging.mappers; + +import okhttp3.Response; +import okhttp3.ResponseBody; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.ExtendWith; +import org.mockito.Mock; +import org.mockito.Mockito; +import org.mockito.junit.jupiter.MockitoExtension; + +import static org.junit.jupiter.api.Assertions.*; + +@Tag("unit") +@ExtendWith(MockitoExtension.class) +class RetrofitResponseBodySizeMapperTest { + + @Mock + Response response; + + @Mock + ResponseBody responseBody; + + @Test + @DisplayName("Returns correct response size") + void testResponseBodyLengthIsSuccessfullyRetrieved() { + Mockito.when(response.body()).thenReturn(responseBody); + Mockito.when(responseBody.contentLength()).thenReturn(1234L); + RetrofitResponseBodySizeMapper mapper = new RetrofitResponseBodySizeMapper(); + + assertEquals("1234", mapper.getValue(null, response)); + + Mockito.verify(response, Mockito.times(1)).body(); + Mockito.verify(responseBody, Mockito.times(1)).contentLength(); + Mockito.verifyNoMoreInteractions(response, responseBody); + } + + @Test + @DisplayName("When response body is not available, should return '-'") + void testResponseBodyIsNotAvailable() { + Mockito.when(response.body()).thenReturn(null); + RetrofitResponseBodySizeMapper mapper = new RetrofitResponseBodySizeMapper(); + + assertEquals("-", mapper.getValue(null, response)); + + Mockito.verify(response, Mockito.times(1)).body(); + Mockito.verifyNoMoreInteractions(response); + Mockito.verifyNoInteractions(responseBody); + } +} diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java index 4d96a78..fc5c91b 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/writers/RetrofitLogLoggerWriterAdapterTest.java @@ -6,10 +6,7 @@ import ch.qos.logback.classic.spi.ILoggingEvent; import ee.bitweb.core.exception.CoreException; import ee.bitweb.core.utils.MemoryAppender; -import org.junit.jupiter.api.BeforeEach; -import org.junit.jupiter.api.DisplayName; -import org.junit.jupiter.api.Tag; -import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.*; import org.slf4j.LoggerFactory; import org.slf4j.MDC; @@ -33,16 +30,21 @@ void setUp() { memoryAppender.start(); } + @AfterEach + void tearDown() { + MDC.clear(); + } + @Test @DisplayName("Event is logged with correct MDC and MDC is restored") void testMessageIsWrittenToLoggerWithCorrectContext() { // given MDC.put("current", "1"); Map container = Map.of( - "RequestMethod", "GET", - "RequestUrl", "https://localhost:3000/api?data=true&test", - "ResponseCode", "404", - "Duration", "14" + "request_method", "GET", + "request_url", "https://localhost:3000/api?data=true&test", + "response_code", "404", + "duration", "14" ); RetrofitLogLoggerWriterAdapter writer = new RetrofitLogLoggerWriterAdapter(); @@ -59,11 +61,11 @@ void testMessageIsWrittenToLoggerWithCorrectContext() { assertAll( () -> assertEquals(5, loggingEvent.getMDCPropertyMap().size()), () -> assertEquals("1", loggingEvent.getMDCPropertyMap().get("current")), - () -> assertEquals("404", loggingEvent.getMDCPropertyMap().get("ResponseCode")), - () -> assertEquals("GET", loggingEvent.getMDCPropertyMap().get("RequestMethod")), - () -> assertEquals("https://localhost:3000/api?data=true&test", loggingEvent.getMDCPropertyMap().get("RequestUrl")), - () -> assertEquals("14", loggingEvent.getMDCPropertyMap().get("Duration")), - () -> assertNull(loggingEvent.getMDCPropertyMap().get("ResponseBodySize")) + () -> assertEquals("404", loggingEvent.getMDCPropertyMap().get("response_code")), + () -> assertEquals("GET", loggingEvent.getMDCPropertyMap().get("request_method")), + () -> assertEquals("https://localhost:3000/api?data=true&test", loggingEvent.getMDCPropertyMap().get("request_url")), + () -> assertEquals("14", loggingEvent.getMDCPropertyMap().get("duration")), + () -> assertNull(loggingEvent.getMDCPropertyMap().get("response_body_size")) ); // then validate current MDC From 86f1a4f535fa9d2baff9850f364b50b8cd3f3ad2 Mon Sep 17 00:00:00 2001 From: Rain Ramm Date: Tue, 5 Nov 2024 11:11:19 +0200 Subject: [PATCH 13/14] Add tests --- .../mappers/RetrofitRequestBodyMapper.java | 49 +-- .../NoopRetrofitLoggingInterceptorTest.java | 42 +++ .../RetrofitRequestBodyMapperTest.java | 299 +++++++++++++++--- 3 files changed, 316 insertions(+), 74 deletions(-) create mode 100644 src/test/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptorTest.java diff --git a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java index 587fab5..c89a5c7 100644 --- a/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java +++ b/src/main/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapper.java @@ -3,6 +3,7 @@ import lombok.RequiredArgsConstructor; import lombok.extern.slf4j.Slf4j; import okhttp3.Request; +import okhttp3.RequestBody; import okhttp3.Response; import okio.Buffer; @@ -46,12 +47,12 @@ protected String sanitizeBody(String body) { return body; } - private String getRequestBody(Request request) throws IOException { + String getRequestBody(Request request) throws IOException { var body = request.body(); if (body == null) { return "null"; - } else if (RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, request.url().toString())) { + } else if (RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, request.url().url().toExternalForm())) { return "(body redacted)"; } else if (RetrofitBodyMapperHelper.bodyHasUnknownEncoding(request.headers())) { return "(encoded body omitted)"; @@ -60,27 +61,31 @@ private String getRequestBody(Request request) throws IOException { } else if (body.isOneShot()) { return "(one-shot body omitted)"; } else { - var buffer = new Buffer(); - body.writeTo(buffer); - - var contentType = body.contentType(); - Charset charSet = contentType != null ? contentType.charset(UTF_8) : UTF_8; - - if (RetrofitBodyMapperHelper.isProbablyUtf8(buffer)) { - assert charSet != null; - var bodyString = buffer.readString(charSet); - - if (request.body() != null && request.body().contentLength() > maxLoggableRequestSize) { - return "%s ... Content size: %s characters".formatted( - bodyString.substring(0, maxLoggableRequestSize), - request.body().contentLength() - ); - } - - return sanitizeBody(bodyString); - } else { - return ("binary body omitted"); + return getBodyString(body); + } + } + + String getBodyString(RequestBody body) throws IOException { + var buffer = new Buffer(); + body.writeTo(buffer); + + var contentType = body.contentType(); + Charset charSet = contentType != null ? contentType.charset(UTF_8) : UTF_8; + + if (RetrofitBodyMapperHelper.isProbablyUtf8(buffer)) { + assert charSet != null; + var bodyString = buffer.readString(charSet); + + if (body.contentLength() == -1 || body.contentLength() > maxLoggableRequestSize) { + return "%s ... Content size: %s characters".formatted( + bodyString.substring(0, maxLoggableRequestSize), + body.contentLength() + ); } + + return sanitizeBody(bodyString); + } else { + return "(binary body omitted)"; } } } diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptorTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptorTest.java new file mode 100644 index 0000000..621845e --- /dev/null +++ b/src/test/java/ee/bitweb/core/retrofit/logging/NoopRetrofitLoggingInterceptorTest.java @@ -0,0 +1,42 @@ +package ee.bitweb.core.retrofit.logging; + +import okhttp3.Interceptor; +import okhttp3.Request; +import okhttp3.Response; +import org.junit.jupiter.api.DisplayName; +import org.junit.jupiter.api.Tag; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.ExtendWith; +import org.mockito.Mock; +import org.mockito.Mockito; +import org.mockito.junit.jupiter.MockitoExtension; + +import java.io.IOException; + +@Tag("unit") +@ExtendWith(MockitoExtension.class) +class NoopRetrofitLoggingInterceptorTest { + + @Mock + Interceptor.Chain chain; + + @Mock + Response response; + + @Mock + Request request; + + @Test + @DisplayName("Chain must proceed") + void testChainProceeds() throws IOException { + Mockito.when(chain.request()).thenReturn(request); + Mockito.when(chain.proceed(request)).thenReturn(response); + + NoopRetrofitLoggingInterceptor interceptor = new NoopRetrofitLoggingInterceptor(); + interceptor.intercept(chain); + + Mockito.verify(chain, Mockito.times(1)).proceed(request); + Mockito.verifyNoMoreInteractions(chain); + Mockito.verifyNoInteractions(response, request); + } +} diff --git a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java index caaa661..f92cda8 100644 --- a/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java +++ b/src/test/java/ee/bitweb/core/retrofit/logging/mappers/RetrofitRequestBodyMapperTest.java @@ -1,78 +1,273 @@ package ee.bitweb.core.retrofit.logging.mappers; import okhttp3.*; -import org.junit.jupiter.api.Assertions; +import okio.Buffer; import org.junit.jupiter.api.DisplayName; import org.junit.jupiter.api.Tag; import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.extension.ExtendWith; +import org.mockito.Mock; +import org.mockito.MockedStatic; +import org.mockito.Mockito; +import org.mockito.invocation.InvocationOnMock; +import org.mockito.junit.jupiter.MockitoExtension; -import java.util.HashMap; +import java.io.ByteArrayInputStream; +import java.io.IOException; +import java.net.MalformedURLException; +import java.net.URL; import java.util.HashSet; import java.util.Set; +import static org.junit.jupiter.api.Assertions.*; + @Tag("unit") +@ExtendWith(MockitoExtension.class) class RetrofitRequestBodyMapperTest { + @Mock + RequestBody requestBody; + + @Mock + Request request; + + @Mock + HttpUrl httpUrl; + + @Mock + Headers headers; + + @Mock + MediaType mediaType; + + private static Object setStringToBuffer(InvocationOnMock invocation) throws IOException { + Buffer buffer = invocation.getArgument(0); + + buffer.readFrom(new ByteArrayInputStream("some data that may or may not be over limit".getBytes())); + + return null; + } + + @Test + @DisplayName("Body is null") + void nullBody() { + Mockito.when(request.body()).thenReturn(null); + + var mapper = new RetrofitRequestBodyMapper(2, new HashSet<>()); + + assertEquals("null", mapper.getValue(request, null)); + + Mockito.verify(request, Mockito.only()).body(); + Mockito.verifyNoMoreInteractions(request); + Mockito.verifyNoInteractions(requestBody, httpUrl); + } + @Test - @DisplayName("Is redact url") - void isRedactUrl() { - var mapper = new RetrofitRequestBodyMapper(0, Set.of("https://www.google.com/")); - - var request = new Request( - new HttpUrl.Builder() - .scheme("https") - .host("www.google.com") - .build(), - "GET", - new Headers.Builder().build(), - RequestBody.create("123".getBytes(), MediaType.get("application/text")), - new HashMap<>() - ); - - var value = mapper.getValue(request, null); - - Assertions.assertEquals("(body redacted)", value); + @DisplayName("Body must be redacted") + void redactBody() throws MalformedURLException { + Mockito.when(httpUrl.url()).thenReturn(new URL("http://localhost:6542/")); + Mockito.when(request.url()).thenReturn(httpUrl); + Mockito.when(request.body()).thenReturn(requestBody); + + Set redactBodyUrls = Set.of("http://localhost:6542/"); + var mapper = new RetrofitRequestBodyMapper(0, redactBodyUrls); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, "http://localhost:6542/")).thenReturn(true); + + assertEquals("(body redacted)", mapper.getValue(request, null)); + } + + Mockito.verify(request, Mockito.times(1)).body(); + Mockito.verify(request, Mockito.times(1)).url(); + Mockito.verify(httpUrl, Mockito.only()).url(); + Mockito.verifyNoMoreInteractions(request, httpUrl); + Mockito.verifyNoInteractions(requestBody); } @Test @DisplayName("Body has unknown encoding") - void bodyHasUnknownEncoding() { - var mapper = new RetrofitRequestBodyMapper(0, new HashSet<>()); - - var request = new Request( - new HttpUrl.Builder() - .scheme("https") - .host("www.google.com") - .build(), - "GET", - new Headers.Builder().add("Content-Encoding", "unknownEncoding").build(), - RequestBody.create("123".getBytes(), MediaType.get("application/text")), - new HashMap<>() - ); - - var value = mapper.getValue(request, null); - - Assertions.assertEquals("(encoded body omitted)", value); + void unknownEncoding() throws MalformedURLException { + Mockito.when(httpUrl.url()).thenReturn(new URL("http://localhost:6542/")); + Mockito.when(request.url()).thenReturn(httpUrl); + Mockito.when(request.body()).thenReturn(requestBody); + Mockito.when(request.headers()).thenReturn(headers); + + Set redactBodyUrls = Set.of(); + var mapper = new RetrofitRequestBodyMapper(0, redactBodyUrls); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, "http://localhost:6542/")).thenReturn(false); + mockedStatic.when(() -> RetrofitBodyMapperHelper.bodyHasUnknownEncoding(headers)).thenReturn(true); + + assertEquals("(encoded body omitted)", mapper.getValue(request, null)); + } + + Mockito.verify(request, Mockito.times(1)).body(); + Mockito.verify(request, Mockito.times(1)).url(); + Mockito.verify(request, Mockito.times(1)).headers(); + Mockito.verify(httpUrl, Mockito.only()).url(); + Mockito.verifyNoMoreInteractions(request, httpUrl); + Mockito.verifyNoInteractions(requestBody); } @Test - @DisplayName("Max loggable request size") - void maxLoggableRequestSize() { - var mapper = new RetrofitRequestBodyMapper(2, new HashSet<>()); + @DisplayName("Duplex body") + void duplexBody() throws MalformedURLException { + Mockito.when(httpUrl.url()).thenReturn(new URL("http://localhost:6542/")); + Mockito.when(request.url()).thenReturn(httpUrl); + Mockito.when(request.body()).thenReturn(requestBody); + Mockito.when(request.headers()).thenReturn(headers); + Mockito.when(requestBody.isDuplex()).thenReturn(true); + + Set redactBodyUrls = Set.of(); + var mapper = new RetrofitRequestBodyMapper(0, redactBodyUrls); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, "http://localhost:6542/")).thenReturn(false); + mockedStatic.when(() -> RetrofitBodyMapperHelper.bodyHasUnknownEncoding(headers)).thenReturn(false); + + assertEquals("(duplex request body omitted)", mapper.getValue(request, null)); + } + + Mockito.verify(request, Mockito.times(1)).body(); + Mockito.verify(request, Mockito.times(1)).url(); + Mockito.verify(request, Mockito.times(1)).headers(); + Mockito.verify(requestBody, Mockito.times(1)).isDuplex(); + Mockito.verify(httpUrl, Mockito.only()).url(); + Mockito.verifyNoMoreInteractions(request, httpUrl, requestBody); + } + + @Test + @DisplayName("One-shot body") + void oneShotBody() throws MalformedURLException { + Mockito.when(httpUrl.url()).thenReturn(new URL("http://localhost:6542/")); + Mockito.when(request.url()).thenReturn(httpUrl); + Mockito.when(request.body()).thenReturn(requestBody); + Mockito.when(request.headers()).thenReturn(headers); + Mockito.when(requestBody.isDuplex()).thenReturn(false); + Mockito.when(requestBody.isOneShot()).thenReturn(true); + + Set redactBodyUrls = Set.of(); + var mapper = new RetrofitRequestBodyMapper(0, redactBodyUrls); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isRedactBodyUrl(redactBodyUrls, "http://localhost:6542/")).thenReturn(false); + mockedStatic.when(() -> RetrofitBodyMapperHelper.bodyHasUnknownEncoding(headers)).thenReturn(false); + + assertEquals("(one-shot body omitted)", mapper.getValue(request, null)); + } + + Mockito.verify(request, Mockito.times(1)).body(); + Mockito.verify(request, Mockito.times(1)).url(); + Mockito.verify(request, Mockito.times(1)).headers(); + Mockito.verify(requestBody, Mockito.times(1)).isDuplex(); + Mockito.verify(requestBody, Mockito.times(1)).isOneShot(); + Mockito.verify(httpUrl, Mockito.only()).url(); + Mockito.verifyNoMoreInteractions(request, httpUrl, requestBody); + } + + @Test + @DisplayName("Request body is not UTF-8") + void requestBodyIsNotUtf8() throws IOException { + Mockito.doNothing().when(requestBody).writeTo(Mockito.isA(Buffer.class)); + Mockito.when(requestBody.contentType()).thenReturn(MediaType.get("application/octet-stream")); + var mapper = new RetrofitRequestBodyMapper(0, Set.of()); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isProbablyUtf8(Mockito.isA(Buffer.class))).thenReturn(false); + + assertEquals("(binary body omitted)", mapper.getBodyString(requestBody)); + } + + Mockito.verify(requestBody, Mockito.times(1)).writeTo(Mockito.isA(Buffer.class)); + Mockito.verifyNoMoreInteractions(requestBody); + Mockito.verifyNoInteractions(request, httpUrl, headers); + } + + @Test + @DisplayName("Request body is returned even when content type is not available") + void contentTypeIsNotAvailable() throws IOException { + Mockito.doAnswer(RetrofitRequestBodyMapperTest::setStringToBuffer).when(requestBody).writeTo(Mockito.isA(Buffer.class)); + Mockito.when(requestBody.contentType()).thenReturn(null); + Mockito.when(requestBody.contentLength()).thenReturn(43L); + var mapper = new RetrofitRequestBodyMapper(100, Set.of()); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isProbablyUtf8(Mockito.isA(Buffer.class))).thenReturn(true); + + assertEquals("some data that may or may not be over limit", mapper.getBodyString(requestBody)); + } + + Mockito.verify(requestBody, Mockito.times(1)).writeTo(Mockito.isA(Buffer.class)); + Mockito.verify(requestBody, Mockito.times(1)).contentType(); + Mockito.verifyNoMoreInteractions(requestBody); + Mockito.verifyNoInteractions(request, httpUrl, headers); + } + + @Test + @DisplayName("Exception is thrown when charset is null") + void charsetIsNull() throws IOException { + Mockito.doNothing().when(requestBody).writeTo(Mockito.isA(Buffer.class)); + Mockito.when(mediaType.charset(Mockito.any())).thenReturn(null); + Mockito.when(requestBody.contentType()).thenReturn(mediaType); + var mapper = new RetrofitRequestBodyMapper(100, Set.of()); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isProbablyUtf8(Mockito.isA(Buffer.class))).thenReturn(true); + + assertThrows(AssertionError.class, () -> mapper.getBodyString(requestBody)); + } + + Mockito.verify(requestBody, Mockito.times(1)).writeTo(Mockito.isA(Buffer.class)); + Mockito.verify(requestBody, Mockito.times(1)).contentType(); + Mockito.verifyNoMoreInteractions(requestBody); + Mockito.verifyNoInteractions(request, httpUrl, headers); + } + + @Test + @DisplayName("Request content length is negative") + void requestContentLengthIsNegative() throws IOException { + Mockito.doAnswer(RetrofitRequestBodyMapperTest::setStringToBuffer).when(requestBody).writeTo(Mockito.isA(Buffer.class)); + Mockito.when(requestBody.contentType()).thenReturn(MediaType.get("text/plain")); + Mockito.when(requestBody.contentLength()).thenReturn(-1L); + var mapper = new RetrofitRequestBodyMapper(11, Set.of()); + + try (MockedStatic mockedStatic = Mockito.mockStatic(RetrofitBodyMapperHelper.class)) { + mockedStatic.when(() -> RetrofitBodyMapperHelper.isProbablyUtf8(Mockito.isA(Buffer.class))).thenReturn(true); + + assertEquals("some data t ... Content size: -1 characters", mapper.getBodyString(requestBody)); + } + + Mockito.verify(requestBody, Mockito.times(1)).writeTo(Mockito.isA(Buffer.class)); + Mockito.verifyNoMoreInteractions(requestBody); + Mockito.verifyNoInteractions(request, httpUrl, headers); + } + + @Test + @DisplayName("Request content is limited") + void requestContentIsLimited() throws IOException { + var customBody = RequestBody.create("some data".getBytes(), MediaType.parse("text/plain")); + var mapper = new RetrofitRequestBodyMapper(2, Set.of()); + + assertEquals("so ... Content size: 9 characters", mapper.getBodyString(customBody)); + } + + @Test + @DisplayName("Request content is returned in full") + void requestContentIsReturnedInFull() throws MalformedURLException { + var customBody = RequestBody.create("some data".getBytes(), MediaType.parse("text/plain")); + Mockito.when(httpUrl.url()).thenReturn(new URL("http://localhost:6542/")); + Mockito.when(request.url()).thenReturn(httpUrl); + Mockito.when(request.headers()).thenReturn(headers); + Mockito.when(request.body()).thenReturn(customBody); - var request = new Request( - new HttpUrl.Builder() - .scheme("https") - .host("www.google.com") - .build(), - "GET", - new Headers.Builder().build(), - RequestBody.create("123".getBytes(), MediaType.get("application/text")), - new HashMap<>() - ); + var mapper = new RetrofitRequestBodyMapper(9, Set.of()); - var value = mapper.getValue(request, null); + assertEquals("some data", mapper.getValue(request, null)); - Assertions.assertEquals("12 ... Content size: 3 characters", value); + Mockito.verify(request, Mockito.times(1)).url(); + Mockito.verify(request, Mockito.times(1)).headers(); + Mockito.verifyNoInteractions(requestBody); } } From cf3fd18b38ff44e681a71bdc6938d2de8091f8aa Mon Sep 17 00:00:00 2001 From: ERICH JAGOMAGIS Date: Tue, 5 Nov 2024 11:55:35 +0200 Subject: [PATCH 14/14] Removed old comment --- .../java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java | 1 - 1 file changed, 1 deletion(-) diff --git a/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java b/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java index 80f87f1..4d91160 100644 --- a/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java +++ b/src/main/java/ee/bitweb/core/retrofit/RetrofitAutoConfiguration.java @@ -99,7 +99,6 @@ public RetrofitLoggingInterceptor defaultRetrofitLoggingInterceptor( return new RetrofitLoggingInterceptorImplementation(mappers, new RetrofitLogLoggerWriterAdapter()); } - // testida üle, kui on vajadus mapper üle kirjutada @Bean @ConditionalOnMissingBean @ConditionalOnEnabledRetrofitMapper(mapper = RetrofitRequestMethodMapper.KEY)