Skip to content

Commit

Permalink
Httpclient gzipped response handling (#1505)
Browse files Browse the repository at this point in the history
* Correct logging of gziped responses

* README modified

* Improvements in gzip header recognition

* Fixed coverage

* Rollback 'javax.' deletion

* Added 'logbook.httpclient.decompress-response' flag

* Formatting

* Formatting

* Formatting

---------

Co-authored-by: Luis Costela <luis.costela@pyxis.com.uy>
  • Loading branch information
lcostela and lcostelaPyxis authored Jul 24, 2023
1 parent acb012d commit ab26376
Show file tree
Hide file tree
Showing 11 changed files with 214 additions and 30 deletions.
33 changes: 16 additions & 17 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -934,21 +934,22 @@ MyClient(RestTemplateBuilder builder, LogbookClientHttpRequestInterceptor interc

The following tables show the available configuration:

| Configuration | Description | Default |
|------------------------------------|------------------------------------------------------------------------------------------------------|-------------------------------|
| `logbook.include` | Include only certain URLs (if defined) | `[]` |
| `logbook.exclude` | Exclude certain URLs (overrides `logbook.include`) | `[]` |
| `logbook.filter.enabled` | Enable the [`LogbookFilter`](#servlet) | `true` |
| `logbook.filter.form-request-mode` | Determines how [form requests](#form-requests) are handled | `body` |
| `logbook.secure-filter.enabled` | Enable the [`SecureLogbookFilter`](#servlet) | `true` |
| `logbook.format.style` | [Formatting style](#formatting) (`http`, `json`, `curl` or `splunk`) | `json` |
| `logbook.strategy` | [Strategy](#strategy) (`default`, `status-at-least`, `body-only-if-status-at-least`, `without-body`) | `default` |
| `logbook.minimum-status` | Minimum status to enable logging (`status-at-least` and `body-only-if-status-at-least`) | `400` |
| `logbook.obfuscate.headers` | List of header names that need obfuscation | `[Authorization]` |
| `logbook.obfuscate.paths` | List of paths that need obfuscation. Check [Filtering](#filtering) for syntax. | `[]` |
| `logbook.obfuscate.parameters` | List of parameter names that need obfuscation | `[access_token]` |
| `logbook.write.chunk-size` | Splits log lines into smaller chunks of size up-to `chunk-size`. | `0` (disabled) |
| `logbook.write.max-body-size` | Truncates the body up to `max-body-size` and appends `...`. | `-1` (disabled) |
| Configuration | Description | Default |
|------------------------------------------|-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|--------------------|
| `logbook.include` | Include only certain URLs (if defined) | `[]` |
| `logbook.exclude` | Exclude certain URLs (overrides `logbook.include`) | `[]` |
| `logbook.filter.enabled` | Enable the [`LogbookFilter`](#servlet) | `true` |
| `logbook.filter.form-request-mode` | Determines how [form requests](#form-requests) are handled | `body` |
| `logbook.secure-filter.enabled` | Enable the [`SecureLogbookFilter`](#servlet) | `true` |
| `logbook.format.style` | [Formatting style](#formatting) (`http`, `json`, `curl` or `splunk`) | `json` |
| `logbook.strategy` | [Strategy](#strategy) (`default`, `status-at-least`, `body-only-if-status-at-least`, `without-body`) | `default` |
| `logbook.minimum-status` | Minimum status to enable logging (`status-at-least` and `body-only-if-status-at-least`) | `400` |
| `logbook.obfuscate.headers` | List of header names that need obfuscation | `[Authorization]` |
| `logbook.obfuscate.paths` | List of paths that need obfuscation. Check [Filtering](#filtering) for syntax. | `[]` |
| `logbook.obfuscate.parameters` | List of parameter names that need obfuscation | `[access_token]` |
| `logbook.write.chunk-size` | Splits log lines into smaller chunks of size up-to `chunk-size`. | `0` (disabled) |
| `logbook.write.max-body-size` | Truncates the body up to `max-body-size` and appends `...`. | `-1` (disabled) |
| `logbook.httpclient.decompress-response` | Enables/disables additional decompression process for HttpClient with gzip encoded body (to logging purposes only). This means extra decompression and possible performance impact. | `false` (disabled) |

##### Example configuration

Expand Down Expand Up @@ -1014,8 +1015,6 @@ for outputs like

1. The Logbook Servlet Filter interferes with downstream code using `getWriter` and/or `getParameter*()`. See [Servlet](#servlet) for more details.
2. The Logbook Servlet Filter does **NOT** support `ERROR` dispatch. You're strongly encouraged to not use it to produce error responses.
2. The Logbook HTTP Client integration is handling gzip-compressed response entities incorrectly if the interceptor runs before a decompressing interceptor. Since logging compressed contents is not
really helpful it's advised to register the logbook interceptor as the last interceptor in the chain.

## Getting Help with Logbook

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,10 +16,12 @@
public final class LogbookHttpAsyncResponseConsumer<T> extends ForwardingHttpAsyncResponseConsumer<T> {

private final HttpAsyncResponseConsumer<T> consumer;
private final boolean decompressResponse;
private HttpResponse response;

public LogbookHttpAsyncResponseConsumer(final HttpAsyncResponseConsumer<T> consumer) {
public LogbookHttpAsyncResponseConsumer(final HttpAsyncResponseConsumer<T> consumer, boolean decompressResponse) {
this.consumer = consumer;
this.decompressResponse = decompressResponse;
}

@Override
Expand All @@ -38,7 +40,7 @@ public void responseCompleted(final HttpContext context) {
final ResponseProcessingStage stage = find(context);

try {
stage.process(new RemoteResponse(response)).write();
stage.process(new RemoteResponse(response, decompressResponse)).write();
} catch (final IOException e) {
throw new UncheckedIOException(e);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -21,10 +21,16 @@
@API(status = STABLE)
public final class LogbookHttpResponseInterceptor implements HttpResponseInterceptor {

private final boolean decompressResponse;

public LogbookHttpResponseInterceptor(boolean decompressResponse) {
this.decompressResponse = decompressResponse;
}

@Override
public void process(final HttpResponse original, final HttpContext context) throws IOException {
final ResponseProcessingStage stage = find(context);
stage.process(new RemoteResponse(original)).write();
stage.process(new RemoteResponse(original, decompressResponse)).write();
}

private ResponseProcessingStage find(final HttpContext context) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -9,14 +9,20 @@
import org.zalando.logbook.Origin;

import javax.annotation.Nullable;

import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.nio.charset.Charset;

import java.util.Arrays;
import java.util.List;
import java.util.Map;
import java.util.Optional;
import java.util.Set;
import java.util.concurrent.atomic.AtomicReference;
import java.util.stream.Stream;
import java.util.zip.GZIPInputStream;

import static java.nio.charset.StandardCharsets.UTF_8;
import static java.util.stream.Collectors.groupingBy;
Expand All @@ -29,6 +35,7 @@ final class RemoteResponse implements org.zalando.logbook.HttpResponse {

private final AtomicReference<State> state = new AtomicReference<>(new Unbuffered());
private final HttpResponse response;
private final boolean decompressResponse;

private interface State {

Expand Down Expand Up @@ -180,10 +187,41 @@ public RemoteResponse withoutBody() {
return this;
}

private static byte[] getDecompressedBytes(byte[] body) throws IOException {
try (ByteArrayInputStream inputStream = new ByteArrayInputStream(body); ByteArrayOutputStream outputStream = new ByteArrayOutputStream()) {
GZIPInputStream gzipInputStream = new GZIPInputStream(inputStream);
byte[] buffer = new byte[1024];
int bytesRead;
while ((bytesRead = gzipInputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, bytesRead);
}
return outputStream.toByteArray();
}
}

@Override
public byte[] getBody() {
return state.updateAndGet(throwingUnaryOperator(state ->
state.buffer(response))).getBody();
public byte[] getBody() throws IOException {
byte[] body = state.updateAndGet(throwingUnaryOperator(s -> s.buffer(response))).getBody();
if (decompressResponse && isGzip()) {
return getDecompressedBytes(body);
}
return body;
}

private boolean isGzip() {
if (response.containsHeader("Content-Encoding")) {
Header[] headers = response.getHeaders("Content-Encoding");
return Arrays.stream(headers).anyMatch(this::isGzipHeaderRepresentation);
}
return false;
}

private boolean isGzipHeaderRepresentation(Header header) {
if ("gzip".equalsIgnoreCase(header.getValue())) {
return true;
} else {
return "x-gzip".equalsIgnoreCase(header.getValue());
}
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -79,12 +79,12 @@ protected HttpResponse sendAndReceive(@Nullable final String body) throws IOExce
}

return client.execute(create(request),
new LogbookHttpAsyncResponseConsumer<>(createConsumer()), callback).get();
new LogbookHttpAsyncResponseConsumer<>(createConsumer(), false), callback).get();
}

@Test
void shouldWrapIOException() throws IOException {
final HttpAsyncResponseConsumer<HttpResponse> unit = new LogbookHttpAsyncResponseConsumer<>(createConsumer());
final HttpAsyncResponseConsumer<HttpResponse> unit = new LogbookHttpAsyncResponseConsumer<>(createConsumer(), false);

final BasicHttpContext context = new BasicHttpContext();
context.setAttribute(Attributes.STAGE, stage);
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,133 @@
package org.zalando.logbook.httpclient;

import static com.github.restdriver.clientdriver.ClientDriverRequest.Method.GET;
import static com.github.restdriver.clientdriver.ClientDriverRequest.Method.POST;
import static com.github.restdriver.clientdriver.RestClientDriver.giveEmptyResponse;
import static com.github.restdriver.clientdriver.RestClientDriver.giveResponse;
import static com.github.restdriver.clientdriver.RestClientDriver.giveResponseAsBytes;
import static com.github.restdriver.clientdriver.RestClientDriver.onRequestTo;
import static org.apache.http.HttpHeaders.CONTENT_ENCODING;
import static org.apache.http.HttpHeaders.CONTENT_TYPE;
import static org.apache.http.entity.ContentType.TEXT_PLAIN;
import static org.assertj.core.api.Assertions.assertThat;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.Mockito.verify;

import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.nio.charset.StandardCharsets;
import java.util.concurrent.ExecutionException;
import java.util.zip.GZIPOutputStream;
import javax.annotation.Nullable;
import org.apache.http.HttpResponse;
import org.apache.http.client.methods.CloseableHttpResponse;
import org.apache.http.client.methods.HttpGet;
import org.apache.http.client.methods.HttpPost;
import org.apache.http.entity.StringEntity;
import org.apache.http.impl.client.CloseableHttpClient;
import org.apache.http.impl.client.HttpClientBuilder;
import org.apache.http.util.EntityUtils;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.Test;
import org.mockito.ArgumentCaptor;
import org.zalando.logbook.Correlation;
import org.zalando.logbook.Logbook;
import org.zalando.logbook.core.DefaultHttpLogFormatter;
import org.zalando.logbook.core.DefaultSink;
import org.zalando.logbook.test.TestStrategy;

public final class LogbookHttpInterceptorsGzipTest extends AbstractHttpTest {

private final Logbook logbook = Logbook.builder()
.strategy(new TestStrategy())
.sink(new DefaultSink(new DefaultHttpLogFormatter(), writer))
.build();

private final CloseableHttpClient client = HttpClientBuilder.create()
.addInterceptorFirst(new LogbookHttpRequestInterceptor(logbook))
.addInterceptorFirst(new LogbookHttpResponseInterceptor(true))
.build();

@AfterEach
void stop() throws IOException {
client.close();
}

@Override
protected HttpResponse sendAndReceive(@Nullable final String body) throws IOException {
return sendAndReceiveWithGzipEncoding(body, "gzip");
}

private CloseableHttpResponse sendAndReceiveWithGzipEncoding(String body, String encoding) throws IOException {
driver.reset();
if (body == null) {
driver.addExpectation(onRequestTo("/").withMethod(GET), giveEmptyResponse());
} else {
ByteArrayOutputStream outputStream = new ByteArrayOutputStream();
try (GZIPOutputStream gzipOutputStream = new GZIPOutputStream(outputStream)) {
gzipOutputStream.write(body.getBytes(StandardCharsets.UTF_8));
}

byte[] compressedBytes = outputStream.toByteArray();
driver.addExpectation(onRequestTo("/").withMethod(POST),
giveResponseAsBytes(new ByteArrayInputStream(compressedBytes), "text/plain").withHeader(CONTENT_ENCODING, encoding));
}
if (body == null) {
return client.execute(new HttpGet(driver.getBaseUrl()));
} else {
final HttpPost post = new HttpPost(driver.getBaseUrl());
post.setEntity(new StringEntity(body));
post.setHeader(CONTENT_TYPE, TEXT_PLAIN.toString());

return client.execute(post);
}
}

@Test
void shouldLogResponseWithBodyGzipHeaderVariant1() throws IOException, ExecutionException, InterruptedException {
extracted("GziP");
}

@Test
void shouldLogResponseWithBodyGzipHeaderVariant2() throws IOException, ExecutionException, InterruptedException {
extracted("GZIP");
}

@Test
void shouldLogResponseWithBodyGzipHeaderVariant3() throws IOException, ExecutionException, InterruptedException {
extracted("x-gzip");
}

@Test
void shouldLogResponseWithBodyGzipHeaderVariant4() throws IOException, ExecutionException, InterruptedException {
extracted("X-GZIP");
}

@Test
void shouldLogResponseWithBodyGzipHeaderVariant5() throws IOException, ExecutionException, InterruptedException {
extracted("x-GziP");
}

private void extracted(String encoding) throws IOException {
driver.addExpectation(onRequestTo("/").withMethod(POST),
giveResponse("Hello, world!", "text/plain"));

final HttpResponse response = sendAndReceiveWithGzipEncoding("Hello, world!", encoding);

assertThat(response.getStatusLine().getStatusCode()).isEqualTo(200);
assertThat(EntityUtils.toString(response.getEntity())).isEqualTo("Hello, world!");

final String message = captureResponse();

assertThat(message)
.startsWith("Incoming Response:")
.contains("HTTP/1.1 200 OK", "Content-Type: text/plain", "Hello, world!");
}

private String captureResponse() throws IOException {
final ArgumentCaptor<String> captor = ArgumentCaptor.forClass(String.class);
verify(writer).write(any(Correlation.class), captor.capture());
return captor.getValue();
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -45,7 +45,7 @@ void defaultBehaviour() {

private final CloseableHttpClient client = HttpClientBuilder.create()
.addInterceptorFirst(new LogbookHttpRequestInterceptor(logbook))
.addInterceptorFirst(new LogbookHttpResponseInterceptor())
.addInterceptorFirst(new LogbookHttpResponseInterceptor(false))
.build();

@AfterEach
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ public final class LogbookHttpInterceptorsTest extends AbstractHttpTest {

private final CloseableHttpClient client = HttpClientBuilder.create()
.addInterceptorFirst(new LogbookHttpRequestInterceptor(logbook))
.addInterceptorFirst(new LogbookHttpResponseInterceptor())
.addInterceptorFirst(new LogbookHttpResponseInterceptor(false))
.build();

@AfterEach
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ final class RemoteResponseTest {

private final BasicHttpEntity entity = new BasicHttpEntity();
private final HttpResponse delegate = new BasicHttpResponse(new ProtocolVersion("HTTP", 1, 1), 200, "OK");
private final RemoteResponse unit = new RemoteResponse(delegate);
private final RemoteResponse unit = new RemoteResponse(delegate, false);

@BeforeEach
void setUpResponseBody() {
Expand Down
Loading

0 comments on commit ab26376

Please sign in to comment.