diff --git a/README.md b/README.md index 92cfe2ae7..8512ad14d 100644 --- a/README.md +++ b/README.md @@ -334,6 +334,20 @@ context.addFilter("LogbookFilter", new LogbookFilter(logbook)) .addMappingForUrlPatterns(EnumSet.of(REQUEST, ASYNC, ERROR), true, "/*"); ``` +The `LogbookFilter` will, by default, treat requests with a `application/x-www-form-urlencoded` body not different from +any other request, i.e you will see the request body in the logs. The downside of this approach is that you won't be +able to use any of the `HttpServletRequest.getParameter*(..)` methods. See issue [#94](../../issues/94) for some more +details. + +As of Logbook 1.5.0, you can now specify one of three strategies that define how Logbook deals with this situation by +using the `logbook.servlet.form-request` system property: + +| Value | Pros | Cons | +|------------------|-----------------------------------------------------------------------------------|----------------------------------------------------| +| `body` (default) | Body is logged | Downstream code can **not use `getParameter*()`** | +| `parameter` | Body is logged | Downstream code can **not use `getInputStream()`** | +| `off` | Downstream code can decide whether to use `getInputStream()` or `getParameter*()` | Body is **not logged** | + #### Security Secure applications usually need a slightly different setup. You should generally avoid logging unauthorized requests, especially the body, because it quickly allows attackers to flood your logfile — and, consequently, your precious disk space. Assuming that your application handles authorization inside another filter, you have two choices: @@ -443,8 +457,6 @@ logbook: ## Known Issues -The Logbook Servlet integration is **incompatible with incoming POST requests that use `application/x-www-form-urlencoded`** form parameters and use any of the `HttpServletRequest.getParameter*(..)` methods. See issue [#94](../../issues/94) for details. - 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 diff --git a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/FormRequestMode.java b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/FormRequestMode.java new file mode 100644 index 000000000..bde257de3 --- /dev/null +++ b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/FormRequestMode.java @@ -0,0 +1,21 @@ +package org.zalando.logbook.servlet; + +import javax.annotation.Nullable; + +import static java.util.Locale.ROOT; + +enum FormRequestMode { + + BODY, PARAMETER, OFF; + + static FormRequestMode fromProperties() { + @Nullable final String property = System.getProperty("logbook.servlet.form-request"); + + if (property == null) { + return BODY; + } + + return FormRequestMode.valueOf(property.toUpperCase(ROOT)); + } + +} diff --git a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/LogbookFilter.java b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/LogbookFilter.java index af19671d5..e46a92844 100644 --- a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/LogbookFilter.java +++ b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/LogbookFilter.java @@ -18,7 +18,7 @@ public LogbookFilter() { } public LogbookFilter(final Logbook logbook) { - this(logbook, Strategy.NORMAL); + this(logbook, new NormalStrategy()); } public LogbookFilter(final Logbook logbook, final Strategy strategy) { diff --git a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/NormalStrategy.java b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/NormalStrategy.java index 017f494e1..a4087a073 100644 --- a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/NormalStrategy.java +++ b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/NormalStrategy.java @@ -14,13 +14,19 @@ import java.util.function.Consumer; import static javax.servlet.RequestDispatcher.ERROR_EXCEPTION_TYPE; +import static org.zalando.logbook.RawRequestFilters.replaceBody; import static org.zalando.logbook.servlet.Attributes.CORRELATOR; -final class NormalStrategy implements Strategy { +public final class NormalStrategy implements Strategy { private final RawRequestFilter filter; + private final FormRequestMode formRequestMode = FormRequestMode.fromProperties(); - NormalStrategy(final RawRequestFilter filter) { + public NormalStrategy() { + this(replaceBody(message -> "")); + } + + public NormalStrategy(final RawRequestFilter filter) { this.filter = filter; } @@ -28,7 +34,7 @@ final class NormalStrategy implements Strategy { public void doFilter(final Logbook logbook, final HttpServletRequest httpRequest, final HttpServletResponse httpResponse, final FilterChain chain) throws ServletException, IOException { - final RemoteRequest request = new RemoteRequest(httpRequest); + final RemoteRequest request = new RemoteRequest(httpRequest, formRequestMode); final Optional correlator = logRequestIfNecessary(logbook, request); if (correlator.isPresent()) { diff --git a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/RemoteRequest.java b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/RemoteRequest.java index c07ea9680..394f424f3 100644 --- a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/RemoteRequest.java +++ b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/RemoteRequest.java @@ -13,6 +13,7 @@ import java.io.IOException; import java.io.InputStreamReader; import java.nio.charset.Charset; +import java.util.Arrays; import java.util.Enumeration; import java.util.List; import java.util.Map; @@ -20,18 +21,24 @@ import static java.nio.charset.StandardCharsets.UTF_8; import static java.util.Collections.list; +import static java.util.stream.Collectors.joining; final class RemoteRequest extends HttpServletRequestWrapper implements RawHttpRequest, HttpRequest { + private static final byte[] EMPTY_BODY = new byte[0]; + + private final FormRequestMode formRequestMode; + /** * Null until we successfully intercepted it. */ @Nullable private byte[] body; - RemoteRequest(final HttpServletRequest request) { + RemoteRequest(final HttpServletRequest request, final FormRequestMode formRequestMode) { super(request); + this.formRequestMode = formRequestMode; } @Override @@ -89,10 +96,33 @@ public Charset getCharset() { @Override public HttpRequest withBody() throws IOException { + if (isFormRequest()) { + switch (formRequestMode) { + case PARAMETER: + this.body = reconstructBodyFromParameters(); + return this; + case OFF: + this.body = EMPTY_BODY; + return this; + } + } + body = ByteStreams.toByteArray(super.getInputStream()); return this; } + private byte[] reconstructBodyFromParameters() { + return getParameterMap().entrySet().stream() + .flatMap(entry -> Arrays.stream(entry.getValue()) + .map(value -> entry.getKey() + "=" + value)) + .collect(joining("&")) + .getBytes(UTF_8); + } + + private boolean isFormRequest() { + return "application/x-www-form-urlencoded".equals(getContentType()); + } + @Override public ServletInputStream getInputStream() throws IOException { return body == null ? diff --git a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/SecurityStrategy.java b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/SecurityStrategy.java index f90135766..35d4a9a1a 100644 --- a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/SecurityStrategy.java +++ b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/SecurityStrategy.java @@ -11,13 +11,19 @@ import java.io.IOException; import java.util.Optional; +import static org.zalando.logbook.RawRequestFilters.replaceBody; import static org.zalando.logbook.servlet.Attributes.CORRELATOR; -final class SecurityStrategy implements Strategy { +public final class SecurityStrategy implements Strategy { private final RawRequestFilter filter; + private final FormRequestMode formRequestMode = FormRequestMode.fromProperties(); - SecurityStrategy(final RawRequestFilter filter) { + public SecurityStrategy() { + this(replaceBody(message -> "")); + } + + public SecurityStrategy(final RawRequestFilter filter) { this.filter = filter; } @@ -25,7 +31,7 @@ final class SecurityStrategy implements Strategy { public void doFilter(final Logbook logbook, final HttpServletRequest httpRequest, final HttpServletResponse httpResponse, final FilterChain chain) throws ServletException, IOException { - final RemoteRequest request = new RemoteRequest(httpRequest); + final RemoteRequest request = new RemoteRequest(httpRequest, formRequestMode); final String protocolVersion = request.getProtocolVersion(); final LocalResponse response = new LocalResponse(httpResponse, protocolVersion); diff --git a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/Strategy.java b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/Strategy.java index ee02fecdd..f19bc9661 100644 --- a/logbook-servlet/src/main/java/org/zalando/logbook/servlet/Strategy.java +++ b/logbook-servlet/src/main/java/org/zalando/logbook/servlet/Strategy.java @@ -13,9 +13,6 @@ public interface Strategy { - Strategy NORMAL = new NormalStrategy(replaceBody(message -> "")); - Strategy SECURITY = new SecurityStrategy(replaceBody(message -> "")); - void doFilter(final Logbook logbook, final HttpServletRequest httpRequest, final HttpServletResponse httpResponse, final FilterChain chain) throws ServletException, IOException; diff --git a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/FormattingTest.java b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/FormattingTest.java index 70ea7eaa2..58d25fdac 100644 --- a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/FormattingTest.java +++ b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/FormattingTest.java @@ -86,7 +86,6 @@ void shouldFormatPostParameterRequest() throws Exception { .contentType(MediaType.APPLICATION_FORM_URLENCODED) .content("name=Alice&age=7.5")); - final HttpRequest request = interceptRequest(); assertThat(request, hasFeature("method", HttpRequest::getMethod, is("POST"))); diff --git a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/MultiFilterSecurityTest.java b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/MultiFilterSecurityTest.java index 0db047045..dcdca5fc2 100644 --- a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/MultiFilterSecurityTest.java +++ b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/MultiFilterSecurityTest.java @@ -49,7 +49,7 @@ public final class MultiFilterSecurityTest { .writer(writer) .build(); - private final Filter firstFilter = spy(new SpyableFilter(new LogbookFilter(logbook, Strategy.SECURITY))); + private final Filter firstFilter = spy(new SpyableFilter(new LogbookFilter(logbook, new SecurityStrategy()))); private final Filter lastFilter = spy(new SpyableFilter(new LogbookFilter(logbook))); private final ExampleController controller = spy(new ExampleController()); diff --git a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/WritingTest.java b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/WritingTest.java index 877cf670c..44d6e060e 100644 --- a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/WritingTest.java +++ b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/WritingTest.java @@ -13,7 +13,9 @@ import org.zalando.logbook.HttpLogWriter; import org.zalando.logbook.Logbook; import org.zalando.logbook.Precorrelation; +import org.zalando.logbook.servlet.junit.RestoreSystemProperties; +import javax.annotation.concurrent.NotThreadSafe; import java.io.IOException; import static org.hamcrest.MatcherAssert.assertThat; @@ -30,18 +32,28 @@ /** * Verifies that {@link LogbookFilter} delegates to {@link HttpLogWriter} correctly. */ +@NotThreadSafe +@RestoreSystemProperties public final class WritingTest { private final HttpLogFormatter formatter = spy(new ForwardingHttpLogFormatter(new DefaultHttpLogFormatter())); private final HttpLogWriter writer = mock(HttpLogWriter.class); - private final MockMvc mvc = MockMvcBuilders - .standaloneSetup(new ExampleController()) - .addFilter(new LogbookFilter(Logbook.builder() - .formatter(formatter) - .writer(writer) - .build())) - .build(); + private MockMvc mvc = initialize(); + + private MockMvc initialize() { + return MockMvcBuilders + .standaloneSetup(new ExampleController()) + .addFilter(new LogbookFilter(Logbook.builder() + .formatter(formatter) + .writer(writer) + .build())) + .build(); + } + + private void reinitialize() { + this.mvc = initialize(); + } @BeforeEach public void setUp() throws IOException { @@ -74,6 +86,69 @@ void shouldLogRequest() throws Exception { "Hello, world!")); } + @Test + void shouldNotLogFormRequest() throws Exception { + System.setProperty("logbook.servlet.form-request", "off"); + + reinitialize(); + + mvc.perform(get("/api/sync") + .with(protocol("HTTP/1.1")) + .accept(MediaType.APPLICATION_JSON) + .header("Host", "localhost") + .contentType(MediaType.APPLICATION_FORM_URLENCODED) + .content("hello=world")); + + @SuppressWarnings("unchecked") final ArgumentCaptor> captor = ArgumentCaptor.forClass( + Precorrelation.class); + verify(writer).writeRequest(captor.capture()); + final Precorrelation precorrelation = captor.getValue(); + + assertThat(precorrelation.getRequest(), startsWith("Incoming Request:")); + assertThat(precorrelation.getRequest(), endsWith( + "GET http://localhost/api/sync HTTP/1.1\n" + + "Accept: application/json\n" + + "Host: localhost\n" + + "Content-Type: application/x-www-form-urlencoded")); + } + + @Test + void shouldNotLogFormRequestBody() throws Exception { + System.setProperty("logbook.servlet.form-request", "body"); + reinitialize(); + shouldLogFormRequest(); + } + + @Test + void shouldNotLogFormRequestParameter() throws Exception { + System.setProperty("logbook.servlet.form-request", "parameter"); + reinitialize(); + shouldLogFormRequest(); + } + + private void shouldLogFormRequest() throws Exception { + mvc.perform(get("/api/sync") + .with(protocol("HTTP/1.1")) + .accept(MediaType.APPLICATION_JSON) + .header("Host", "localhost") + .contentType(MediaType.APPLICATION_FORM_URLENCODED) + .content("hello=world")); + + @SuppressWarnings("unchecked") final ArgumentCaptor> captor = ArgumentCaptor.forClass( + Precorrelation.class); + verify(writer).writeRequest(captor.capture()); + final Precorrelation precorrelation = captor.getValue(); + + assertThat(precorrelation.getRequest(), startsWith("Incoming Request:")); + assertThat(precorrelation.getRequest(), endsWith( + "GET http://localhost/api/sync HTTP/1.1\n" + + "Accept: application/json\n" + + "Host: localhost\n" + + "Content-Type: application/x-www-form-urlencoded\n" + + "\n" + + "hello=world")); + } + @Test void shouldLogResponse() throws Exception { mvc.perform(get("/api/sync") diff --git a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/junit/RestoreSystemProperties.java b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/junit/RestoreSystemProperties.java new file mode 100644 index 000000000..2c082d2f1 --- /dev/null +++ b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/junit/RestoreSystemProperties.java @@ -0,0 +1,16 @@ +package org.zalando.logbook.servlet.junit; + +import org.junit.jupiter.api.extension.ExtendWith; + +import java.lang.annotation.Retention; +import java.lang.annotation.Target; + +import static java.lang.annotation.ElementType.METHOD; +import static java.lang.annotation.ElementType.TYPE; +import static java.lang.annotation.RetentionPolicy.RUNTIME; + +@Target({ TYPE, METHOD }) +@Retention(RUNTIME) +@ExtendWith(SystemPropertiesExtension.class) +public @interface RestoreSystemProperties { +} diff --git a/logbook-servlet/src/test/java/org/zalando/logbook/servlet/junit/SystemPropertiesExtension.java b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/junit/SystemPropertiesExtension.java new file mode 100644 index 000000000..35b2c4164 --- /dev/null +++ b/logbook-servlet/src/test/java/org/zalando/logbook/servlet/junit/SystemPropertiesExtension.java @@ -0,0 +1,27 @@ +package org.zalando.logbook.servlet.junit; + +import org.junit.jupiter.api.extension.AfterEachCallback; +import org.junit.jupiter.api.extension.BeforeEachCallback; +import org.junit.jupiter.api.extension.Extension; +import org.junit.jupiter.api.extension.ExtensionContext; + +import java.util.Properties; + +public final class SystemPropertiesExtension + implements Extension, BeforeEachCallback, AfterEachCallback { + + private final Properties original = new Properties(); + + @Override + public void beforeEach(final ExtensionContext context) throws Exception { + original.putAll(System.getProperties()); + } + + @Override + public void afterEach(final ExtensionContext context) throws Exception { + final Properties properties = System.getProperties(); + properties.clear(); + properties.putAll(original); + } + +} diff --git a/logbook-spring-boot-starter/src/main/java/org/zalando/logbook/spring/LogbookAutoConfiguration.java b/logbook-spring-boot-starter/src/main/java/org/zalando/logbook/spring/LogbookAutoConfiguration.java index ed3acce7a..848d8f5f4 100644 --- a/logbook-spring-boot-starter/src/main/java/org/zalando/logbook/spring/LogbookAutoConfiguration.java +++ b/logbook-spring-boot-starter/src/main/java/org/zalando/logbook/spring/LogbookAutoConfiguration.java @@ -45,7 +45,7 @@ import org.zalando.logbook.httpclient.LogbookHttpRequestInterceptor; import org.zalando.logbook.httpclient.LogbookHttpResponseInterceptor; import org.zalando.logbook.servlet.LogbookFilter; -import org.zalando.logbook.servlet.Strategy; +import org.zalando.logbook.servlet.SecurityStrategy; import javax.servlet.Filter; import java.util.List; @@ -263,7 +263,7 @@ static class SecurityServletFilterConfiguration { @ConditionalOnProperty(name = "logbook.filter.enabled", havingValue = "true", matchIfMissing = true) @ConditionalOnMissingBean(name = FILTER_NAME) public FilterRegistrationBean unauthorizedLogbookFilter(final Logbook logbook) { - final Filter filter = new LogbookFilter(logbook, Strategy.SECURITY); + final Filter filter = new LogbookFilter(logbook, new SecurityStrategy()); @SuppressWarnings("unchecked") // as of Spring Boot 2.x final FilterRegistrationBean registration = new FilterRegistrationBean(filter); registration.setName(FILTER_NAME);