Merge pull request #7670 from maryarm/BAEL-3009

BAEL-3009: Logging Spring WebClient calls
This commit is contained in:
rpvilao 2019-09-06 18:14:43 +02:00 committed by GitHub
commit 0ca78b440d
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 358 additions and 3 deletions

View File

@ -56,7 +56,6 @@
</dependency>
<!-- runtime and test scoped -->
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-devtools</artifactId>
@ -89,6 +88,14 @@
<groupId>org.projectlombok</groupId>
<artifactId>lombok</artifactId>
</dependency>
<!-- WebClient logging with Jetty -->
<dependency>
<groupId>org.eclipse.jetty</groupId>
<artifactId>jetty-reactive-httpclient</artifactId>
<version>${jetty-reactive-httpclient.version}</version>
<scope>test</scope>
</dependency>
</dependencies>
<build>
@ -110,6 +117,7 @@
<jsonb-api.version>1.0</jsonb-api.version>
<geronimo-json_1.1_spec.version>1.0</geronimo-json_1.1_spec.version>
<commons-collections4.version>4.1</commons-collections4.version>
<jetty-reactive-httpclient.version>1.0.3</jetty-reactive-httpclient.version>
</properties>
</project>

View File

@ -0,0 +1,154 @@
package com.baeldung.reactive.logging;
import ch.qos.logback.classic.spi.LoggingEvent;
import ch.qos.logback.core.Appender;
import com.baeldung.reactive.logging.filters.LogFilters;
import com.baeldung.reactive.logging.netty.CustomLogger;
import com.fasterxml.jackson.databind.ObjectMapper;
import java.net.URI;
import lombok.AllArgsConstructor;
import lombok.Data;
import org.eclipse.jetty.client.api.Request;
import org.eclipse.jetty.util.ssl.SslContextFactory;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.slf4j.LoggerFactory;
import org.springframework.http.client.reactive.JettyClientHttpConnector;
import org.springframework.http.client.reactive.ReactorClientHttpConnector;
import org.springframework.web.reactive.function.BodyInserters;
import org.springframework.web.reactive.function.client.WebClient;
import reactor.netty.channel.BootstrapHandlers;
import reactor.netty.http.client.HttpClient;
import static com.baeldung.reactive.logging.jetty.RequestLogEnhancer.enhance;
import static org.mockito.ArgumentMatchers.argThat;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;
public class WebClientLoggingIntegrationTest {
@AllArgsConstructor
@Data
class Post {
private String title;
private String body;
private int userId;
}
private Appender jettyAppender;
private Appender nettyAppender;
private Appender mockAppender;
private String sampleUrl = "https://jsonplaceholder.typicode.com/posts";
private Post post;
private String sampleResponseBody;
@BeforeEach
private void setup() throws Exception {
post = new Post("Learn WebClient logging with Baeldung!", "", 1);
sampleResponseBody = new ObjectMapper().writeValueAsString(post);
ch.qos.logback.classic.Logger jetty = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger("com.baeldung.reactive.logging.jetty");
jettyAppender = mock(Appender.class);
when(jettyAppender.getName()).thenReturn("com.baeldung.reactive.logging.jetty");
jetty.addAppender(jettyAppender);
ch.qos.logback.classic.Logger netty = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger("reactor.netty.http.client");
nettyAppender = mock(Appender.class);
when(nettyAppender.getName()).thenReturn("reactor.netty.http.client");
netty.addAppender(nettyAppender);
ch.qos.logback.classic.Logger test = (ch.qos.logback.classic.Logger) LoggerFactory.getLogger("com.baeldung.reactive");
mockAppender = mock(Appender.class);
when(mockAppender.getName()).thenReturn("com.baeldung.reactive");
test.addAppender(mockAppender);
}
@Test
public void givenJettyHttpClient_whenEndpointIsConsumed_thenRequestAndResponseBodyLogged() {
SslContextFactory.Client sslContextFactory = new SslContextFactory.Client();
org.eclipse.jetty.client.HttpClient httpClient = new org.eclipse.jetty.client.HttpClient(sslContextFactory) {
@Override
public Request newRequest(URI uri) {
Request request = super.newRequest(uri);
return enhance(request);
}
};
WebClient
.builder()
.clientConnector(new JettyClientHttpConnector(httpClient))
.build()
.post()
.uri(sampleUrl)
.body(BodyInserters.fromObject(post))
.retrieve()
.bodyToMono(String.class)
.block();
verify(jettyAppender).doAppend(argThat(argument -> (((LoggingEvent) argument).getFormattedMessage()).contains(sampleResponseBody)));
}
@Test
public void givenNettyHttpClientWithWiretap_whenEndpointIsConsumed_thenRequestAndResponseBodyLogged() {
reactor.netty.http.client.HttpClient httpClient = HttpClient
.create()
.wiretap(true);
WebClient
.builder()
.clientConnector(new ReactorClientHttpConnector(httpClient))
.build()
.post()
.uri(sampleUrl)
.body(BodyInserters.fromObject(post))
.exchange()
.block();
verify(nettyAppender).doAppend(argThat(argument -> (((LoggingEvent) argument).getFormattedMessage()).contains("00000300")));
}
@Test
public void givenNettyHttpClientWithCustomLogger_whenEndpointIsConsumed_thenRequestAndResponseBodyLogged() {
reactor.netty.http.client.HttpClient httpClient = HttpClient
.create()
.tcpConfiguration(
tc -> tc.bootstrap(
b -> BootstrapHandlers.updateLogSupport(b, new CustomLogger(HttpClient.class))));
WebClient
.builder()
.clientConnector(new ReactorClientHttpConnector(httpClient))
.build()
.post()
.uri(sampleUrl)
.body(BodyInserters.fromObject(post))
.exchange()
.block();
verify(nettyAppender).doAppend(argThat(argument -> (((LoggingEvent) argument).getFormattedMessage()).contains(sampleResponseBody)));
}
@Test
public void givenDefaultHttpClientWithFilter_whenEndpointIsConsumed_thenRequestAndResponseLogged() {
WebClient
.builder()
.filters(exchangeFilterFunctions -> {
exchangeFilterFunctions.addAll(LogFilters.prepareFilters());
})
.build()
.post()
.uri(sampleUrl)
.body(BodyInserters.fromObject(post))
.exchange()
.block();
verify(mockAppender).doAppend(argThat(argument -> (((LoggingEvent) argument).getFormattedMessage()).contains("domain=.typicode.com;")));
}
}

View File

@ -0,0 +1,54 @@
package com.baeldung.reactive.logging.filters;
import java.util.Arrays;
import java.util.List;
import lombok.extern.slf4j.Slf4j;
import org.springframework.web.reactive.function.client.ExchangeFilterFunction;
import reactor.core.publisher.Mono;
@Slf4j
public class LogFilters {
public static List<ExchangeFilterFunction> prepareFilters() {
return Arrays.asList(logRequest(), logResponse());
}
private static ExchangeFilterFunction logRequest() {
return ExchangeFilterFunction.ofRequestProcessor(clientRequest -> {
if (log.isDebugEnabled()) {
StringBuilder sb = new StringBuilder("Request: \n")
.append(clientRequest.method())
.append(" ")
.append(clientRequest.url());
clientRequest
.headers()
.forEach((name, values) -> values.forEach(value -> sb
.append("\n")
.append(name)
.append(":")
.append(value)));
log.debug(sb.toString());
}
return Mono.just(clientRequest);
});
}
private static ExchangeFilterFunction logResponse() {
return ExchangeFilterFunction.ofResponseProcessor(clientResponse -> {
if (log.isDebugEnabled()) {
StringBuilder sb = new StringBuilder("Response: \n")
.append("Status: ")
.append(clientResponse.rawStatusCode());
clientResponse
.headers()
.asHttpHeaders()
.forEach((key, value1) -> value1.forEach(value -> sb
.append("\n")
.append(key)
.append(":")
.append(value)));
log.debug(sb.toString());
}
return Mono.just(clientResponse);
});
}
}

View File

@ -0,0 +1,93 @@
package com.baeldung.reactive.logging.jetty;
import java.nio.ByteBuffer;
import java.nio.charset.Charset;
import java.nio.charset.StandardCharsets;
import java.util.Locale;
import lombok.extern.slf4j.Slf4j;
import org.eclipse.jetty.client.api.Request;
import org.eclipse.jetty.http.HttpField;
import org.eclipse.jetty.http.HttpFields;
import org.eclipse.jetty.http.HttpHeader;
@Slf4j
public class RequestLogEnhancer {
public static Request enhance(Request request) {
StringBuilder group = new StringBuilder();
request.onRequestBegin(theRequest -> group
.append("Request ")
.append(theRequest.getMethod())
.append(" ")
.append(theRequest.getURI())
.append("\n"));
request.onRequestHeaders(theRequest -> {
for (HttpField header : theRequest.getHeaders())
group
.append(header)
.append("\n");
});
request.onRequestContent((theRequest, content) -> {
group.append(toString(content, getCharset(theRequest.getHeaders())));
});
request.onRequestSuccess(theRequest -> {
log.debug(group.toString());
group.delete(0, group.length());
});
group.append("\n");
request.onResponseBegin(theResponse -> {
group
.append("Response \n")
.append(theResponse.getVersion())
.append(" ")
.append(theResponse.getStatus());
if (theResponse.getReason() != null) {
group
.append(" ")
.append(theResponse.getReason());
}
group.append("\n");
});
request.onResponseHeaders(theResponse -> {
for (HttpField header : theResponse.getHeaders())
group
.append(header)
.append("\n");
});
request.onResponseContent((theResponse, content) -> {
group.append(toString(content, getCharset(theResponse.getHeaders())));
});
request.onResponseSuccess(theResponse -> {
log.debug(group.toString());
});
return request;
}
private static String toString(ByteBuffer buffer, Charset charset) {
byte[] bytes;
if (buffer.hasArray()) {
bytes = new byte[buffer.capacity()];
System.arraycopy(buffer.array(), 0, bytes, 0, buffer.capacity());
} else {
bytes = new byte[buffer.remaining()];
buffer.get(bytes, 0, bytes.length);
}
return new String(bytes, charset);
}
private static Charset getCharset(HttpFields headers) {
String contentType = headers.get(HttpHeader.CONTENT_TYPE);
if (contentType != null) {
String[] tokens = contentType
.toLowerCase(Locale.US)
.split("charset=");
if (tokens.length == 2) {
String encoding = tokens[1].replaceAll("[;\"]", "");
return Charset.forName(encoding);
}
}
return StandardCharsets.UTF_8;
}
}

View File

@ -0,0 +1,42 @@
package com.baeldung.reactive.logging.netty;
import io.netty.buffer.ByteBuf;
import io.netty.channel.ChannelHandlerContext;
import io.netty.handler.logging.LoggingHandler;
import java.nio.charset.Charset;
import static io.netty.util.internal.PlatformDependent.allocateUninitializedArray;
import static java.lang.Math.max;
import static java.nio.charset.Charset.defaultCharset;
public class CustomLogger extends LoggingHandler {
public CustomLogger(Class<?> clazz) {
super(clazz);
}
@Override
protected String format(ChannelHandlerContext ctx, String event, Object arg) {
if (arg instanceof ByteBuf) {
ByteBuf msg = (ByteBuf) arg;
return decode(msg, msg.readerIndex(), msg.readableBytes(), defaultCharset());
}
return super.format(ctx, event, arg);
}
private String decode(ByteBuf src, int readerIndex, int len, Charset charset) {
if (len != 0) {
byte[] array;
int offset;
if (src.hasArray()) {
array = src.array();
offset = src.arrayOffset() + readerIndex;
} else {
array = allocateUninitializedArray(max(len, 1024));
offset = 0;
src.getBytes(readerIndex, array, 0, len);
}
return new String(array, offset, len, charset);
}
return "";
}
}

View File

@ -6,11 +6,15 @@
<Pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</Pattern>
</layout>
</appender>
<logger name="org.springframework" level="INFO" />
<logger name="com.baeldung.reactive.logging.jetty" level="DEBUG" />
<logger name="reactor.netty.http.client.HttpClient" level="DEBUG" />
<logger name="com.baeldung.reactive.logging" level="DEBUG" />
<root level="INFO">
<appender-ref ref="stdout" />
</root>
</configuration>