diff --git a/README.md b/README.md index 94aacb29..8ef9d691 100644 --- a/README.md +++ b/README.md @@ -27,7 +27,7 @@ All in all, you should do the following: * adjust your logging configuration accordingly. -Say, you want to make use of the *servlet filter* feature, then you need to add the following dependency to your POM with property `cf-logging-version` referring to the latest nexus version (currently `2.2.0`): +Say, you want to make use of the *servlet filter* feature, then you need to add the following dependency to your POM with property `cf-logging-version` referring to the latest nexus version (currently `2.2.1`): ```xml diff --git a/cf-java-logging-support-core/pom.xml b/cf-java-logging-support-core/pom.xml index 3a2d56a5..3e2507bd 100644 --- a/cf-java-logging-support-core/pom.xml +++ b/cf-java-logging-support-core/pom.xml @@ -32,7 +32,7 @@ com.sap.hcp.cf.logging cf-java-logging-support-parent - 2.2.0 + 2.2.1-SNAPSHOT ../pom.xml diff --git a/cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/RequestRecordBuilder.java b/cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/RequestRecordBuilder.java new file mode 100644 index 00000000..f1e6be92 --- /dev/null +++ b/cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/RequestRecordBuilder.java @@ -0,0 +1,59 @@ +package com.sap.hcp.cf.logging.common; + +import com.sap.hcp.cf.logging.common.RequestRecord.Direction; + +public class RequestRecordBuilder { + + private final RequestRecord requestRecord; + + private RequestRecordBuilder(String layerKey) { + this.requestRecord = new RequestRecord(layerKey); + } + + private RequestRecordBuilder(String layerKey, Direction direction) { + this.requestRecord = new RequestRecord(layerKey, direction); + } + + public static RequestRecordBuilder requestRecord(String layerKey) { + return new RequestRecordBuilder(layerKey); + } + + public static RequestRecordBuilder requestRecord(String layerKey, Direction direction) { + return new RequestRecordBuilder(layerKey, direction); + } + + public RequestRecord build() { + return requestRecord; + } + + public RequestRecordBuilder addTag(String fieldKey, String tag) { + requestRecord.addTag(fieldKey, tag); + return this; + } + + public RequestRecordBuilder addOptionalTag(boolean optionalFieldCanBeLogged, String fieldKey, String tag) { + + if (!optionalFieldCanBeLogged && tag != null) { + requestRecord.addTag(fieldKey, Defaults.REDACTED); + } + + if (!optionalFieldCanBeLogged && tag.equals(Defaults.UNKNOWN)) { + requestRecord.addTag(fieldKey, tag); + } + + if (optionalFieldCanBeLogged) { + requestRecord.addTag(fieldKey, tag); + } + return this; + } + + public RequestRecordBuilder addContextTag(String fieldKey, String tag) { + requestRecord.addContextTag(fieldKey, tag); + return this; + } + + public RequestRecordBuilder addValue(String fieldKey, Value value) { + requestRecord.addValue(fieldKey, value); + return this; + } +} diff --git a/cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/RequestRecordConfigurator.java b/cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/RequestRecordConfigurator.java deleted file mode 100644 index ba7ef52d..00000000 --- a/cf-java-logging-support-core/src/main/java/com/sap/hcp/cf/logging/common/RequestRecordConfigurator.java +++ /dev/null @@ -1,30 +0,0 @@ -package com.sap.hcp.cf.logging.common; - -public class RequestRecordConfigurator { - - private final RequestRecord requestRecord; - - private RequestRecordConfigurator(RequestRecord requestRecord) { - this.requestRecord = requestRecord; - } - - public static RequestRecordConfigurator to(RequestRecord requestRecord) { - return new RequestRecordConfigurator(requestRecord); - } - - public RequestRecordConfigurator addOptionalTag(boolean optionalFieldCanBeLogged, String fieldKey, String tag) { - - if (!optionalFieldCanBeLogged && tag != null) { - requestRecord.addTag(fieldKey, Defaults.REDACTED); - } - - if (!optionalFieldCanBeLogged && tag.equals(Defaults.UNKNOWN)) { - requestRecord.addTag(fieldKey, tag); - } - - if (optionalFieldCanBeLogged) { - requestRecord.addTag(fieldKey, tag); - } - return this; - } -} diff --git a/cf-java-logging-support-core/src/test/java/com/sap/hcp/cf/logging/common/RequestRecordConfiguratorTest.java b/cf-java-logging-support-core/src/test/java/com/sap/hcp/cf/logging/common/RequestRecordBuilderTest.java similarity index 74% rename from cf-java-logging-support-core/src/test/java/com/sap/hcp/cf/logging/common/RequestRecordConfiguratorTest.java rename to cf-java-logging-support-core/src/test/java/com/sap/hcp/cf/logging/common/RequestRecordBuilderTest.java index b7b2c6bc..6c0ec3f8 100644 --- a/cf-java-logging-support-core/src/test/java/com/sap/hcp/cf/logging/common/RequestRecordConfiguratorTest.java +++ b/cf-java-logging-support-core/src/test/java/com/sap/hcp/cf/logging/common/RequestRecordBuilderTest.java @@ -1,6 +1,6 @@ package com.sap.hcp.cf.logging.common; -import static com.sap.hcp.cf.logging.common.RequestRecordConfigurator.to; +import static com.sap.hcp.cf.logging.common.RequestRecordBuilder.requestRecord; import static org.junit.Assert.assertEquals; import java.io.IOException; @@ -10,52 +10,48 @@ import com.fasterxml.jackson.jr.ob.JSON; import com.fasterxml.jackson.jr.ob.JSONObjectException; -public class RequestRecordConfiguratorTest { +public class RequestRecordBuilderTest { @Test public void testAddingSingleActivatedOptionalTagToRequestRecord() throws JSONObjectException, IOException { - RequestRecord requestRecord = new RequestRecord("TEST"); boolean canBeLogged = true; String key = "TestKey"; String tag = "TestTag"; - to(requestRecord).addOptionalTag(canBeLogged, key, tag); + RequestRecord requestRecord = requestRecord("TEST").addOptionalTag(canBeLogged, key, tag).build(); assertEquals(tag, getFieldFromRequestRecord(requestRecord, key)); } @Test public void testAddingSingleForbiddenOptionalTagToRequestRecord() throws JSONObjectException, IOException { - RequestRecord requestRecord = new RequestRecord("TEST"); boolean canBeLogged = false; String key = "TestKey"; String tag = "TestTag"; - to(requestRecord).addOptionalTag(canBeLogged, key, tag); + RequestRecord requestRecord = requestRecord("TEST").addOptionalTag(canBeLogged, key, tag).build(); assertEquals(Defaults.REDACTED, getFieldFromRequestRecord(requestRecord, key)); } @Test public void testAddingSingleForbiddenOptionalNullTagToRequestRecord() throws JSONObjectException, IOException { - RequestRecord requestRecord = new RequestRecord("TEST"); boolean canBeLogged = false; String key = "TestKey"; String tag = Defaults.UNKNOWN; - to(requestRecord).addOptionalTag(canBeLogged, key, tag); + RequestRecord requestRecord = requestRecord("TEST").addOptionalTag(canBeLogged, key, tag).build(); assertEquals(Defaults.UNKNOWN, getFieldFromRequestRecord(requestRecord, key)); } @Test public void testAddingSingleActivatedOptionalNullTagToRequestRecord() throws JSONObjectException, IOException { - RequestRecord requestRecord = new RequestRecord("TEST"); boolean canBeLogged = true; String key = "TestKey"; String tag = Defaults.UNKNOWN; - to(requestRecord).addOptionalTag(canBeLogged, key, tag); + RequestRecord requestRecord = requestRecord("TEST").addOptionalTag(canBeLogged, key, tag).build(); assertEquals(Defaults.UNKNOWN, getFieldFromRequestRecord(requestRecord, key)); } diff --git a/cf-java-logging-support-jersey/pom.xml b/cf-java-logging-support-jersey/pom.xml index a50fc3e4..1b1cc2a5 100644 --- a/cf-java-logging-support-jersey/pom.xml +++ b/cf-java-logging-support-jersey/pom.xml @@ -9,7 +9,7 @@ ../pom.xml com.sap.hcp.cf.logging cf-java-logging-support-parent - 2.2.0 + 2.2.1-SNAPSHOT cf-java-logging-support-jersey diff --git a/cf-java-logging-support-jersey/src/main/java/com/sap/hcp/cf/logging/jersey/filter/RequestHandler.java b/cf-java-logging-support-jersey/src/main/java/com/sap/hcp/cf/logging/jersey/filter/RequestHandler.java index c39732d6..94251b2d 100644 --- a/cf-java-logging-support-jersey/src/main/java/com/sap/hcp/cf/logging/jersey/filter/RequestHandler.java +++ b/cf-java-logging-support-jersey/src/main/java/com/sap/hcp/cf/logging/jersey/filter/RequestHandler.java @@ -1,7 +1,5 @@ package com.sap.hcp.cf.logging.jersey.filter; -import static com.sap.hcp.cf.logging.common.RequestRecordConfigurator.to; - import java.net.URI; import com.sap.hcp.cf.logging.common.Defaults; @@ -11,6 +9,7 @@ import com.sap.hcp.cf.logging.common.LogOptionalFieldsSettings; import com.sap.hcp.cf.logging.common.LongValue; import com.sap.hcp.cf.logging.common.RequestRecord; +import com.sap.hcp.cf.logging.common.RequestRecordBuilder; public class RequestHandler { final LogOptionalFieldsSettings logOptionalFieldsSettings; @@ -38,38 +37,28 @@ public RequestRecord handle(RequestContextAdapter adapter) { } } - RequestRecord lrec = new RequestRecord(adapter.getName(), adapter.getDirection()); - lrec.start(); - - addHeaders(adapter, lrec); - + boolean isSensitiveConnectionData = logOptionalFieldsSettings.isLogSensitiveConnectionData(); + boolean isLogRemoteUserField = logOptionalFieldsSettings.isLogRemoteUserField(); + boolean isLogRefererField = logOptionalFieldsSettings.isLogRefererField(); + RequestRecord lrec = RequestRecordBuilder.requestRecord(adapter.getName(), adapter.getDirection()) + .addTag(Fields.REQUEST, getValue(getRequestUri(adapter))) + .addTag(Fields.METHOD, getValue(adapter.getMethod())) + .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_IP, getValue(adapter.getUri().getAuthority())) + .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_HOST, getValue(adapter.getUri().getHost())) + .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_PORT, + Integer.toString(adapter.getUri().getPort())) + .addOptionalTag(isSensitiveConnectionData, Fields.X_FORWARDED_FOR, + getHeader(adapter, HttpHeaders.X_FORWARDED_FOR)) + .addOptionalTag(isLogRemoteUserField, Fields.REMOTE_USER, getValue(adapter.getUser())) + .addOptionalTag(isLogRefererField, Fields.REFERER, getHeader(adapter, HttpHeaders.REFERER)) + .addContextTag(Fields.REQUEST_ID, getHeader(adapter, HttpHeaders.X_VCAP_REQUEST_ID)) + .addValue(Fields.REQUEST_SIZE_B, new LongValue(adapter.getRequestSize())).build(); + + lrec.start(); return lrec; } - private void addHeaders(RequestContextAdapter adapter, RequestRecord lrec) { - - lrec.addTag(Fields.REQUEST, getValue(getRequestUri(adapter))); - lrec.addTag(Fields.METHOD, getValue(adapter.getMethod())); - - boolean isSensitiveConnectionData = logOptionalFieldsSettings.isLogSensitiveConnectionData(); - - to(lrec).addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_IP, getValue(adapter.getUri().getAuthority())) - .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_HOST, getValue(adapter.getUri().getHost())) - .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_PORT, Integer.toString(adapter.getUri() - .getPort())) - .addOptionalTag(isSensitiveConnectionData, Fields.X_FORWARDED_FOR, getHeader(adapter, - HttpHeaders.X_FORWARDED_FOR)) - .addOptionalTag(logOptionalFieldsSettings.isLogRemoteUserField(), Fields.REMOTE_USER, getValue(adapter - .getUser())) - .addOptionalTag(logOptionalFieldsSettings.isLogRefererField(), Fields.REFERER, getHeader(adapter, - HttpHeaders.REFERER)); - lrec.addContextTag(Fields.REQUEST_ID, getHeader(adapter, HttpHeaders.X_VCAP_REQUEST_ID)); - - lrec.addValue(Fields.REQUEST_SIZE_B, new LongValue(adapter.getRequestSize())); - - } - private String getValue(String value) { return value != null ? value : Defaults.UNKNOWN; } diff --git a/cf-java-logging-support-log4j2/pom.xml b/cf-java-logging-support-log4j2/pom.xml index 2982900b..d171cb14 100644 --- a/cf-java-logging-support-log4j2/pom.xml +++ b/cf-java-logging-support-log4j2/pom.xml @@ -11,7 +11,7 @@ ../pom.xml com.sap.hcp.cf.logging cf-java-logging-support-parent - 2.2.0 + 2.2.1-SNAPSHOT diff --git a/cf-java-logging-support-logback/pom.xml b/cf-java-logging-support-logback/pom.xml index 7711472e..144326c2 100644 --- a/cf-java-logging-support-logback/pom.xml +++ b/cf-java-logging-support-logback/pom.xml @@ -10,7 +10,7 @@ ../pom.xml com.sap.hcp.cf.logging cf-java-logging-support-parent - 2.2.0 + 2.2.1-SNAPSHOT diff --git a/cf-java-logging-support-servlet/pom.xml b/cf-java-logging-support-servlet/pom.xml index d340c655..2037436f 100644 --- a/cf-java-logging-support-servlet/pom.xml +++ b/cf-java-logging-support-servlet/pom.xml @@ -9,7 +9,7 @@ com.sap.hcp.cf.logging cf-java-logging-support-parent - 2.2.0 + 2.2.1-SNAPSHOT ../pom.xml diff --git a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImpl.java b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImpl.java index 2809320a..c45f3c5d 100644 --- a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImpl.java +++ b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImpl.java @@ -11,8 +11,6 @@ import javax.servlet.ServletException; import javax.servlet.ServletRequest; import javax.servlet.ServletResponse; -import javax.servlet.http.HttpServletRequest; -import javax.servlet.http.HttpServletResponse; import org.slf4j.MDC; @@ -20,47 +18,27 @@ public class LoggingAsyncContextImpl implements AsyncContext { private AsyncContext asyncContext; - public LoggingAsyncContextImpl(AsyncContext asyncContext, final RequestLoggingVisitor loggingVisitor) { + public LoggingAsyncContextImpl(AsyncContext asyncContext, final RequestLogger requestLogger) { this.asyncContext = asyncContext; asyncContext.addListener(new AsyncListener() { @Override public void onTimeout(AsyncEvent event) throws IOException { - generateLog(loggingVisitor); + requestLogger.logRequest(); } - private void generateLog(final RequestLoggingVisitor loggingVisitor) { - ServletRequest request = getRequest(); - ServletResponse response = getResponse(); - if (request instanceof HttpServletRequest && response instanceof HttpServletResponse) { - HttpServletRequest httpRequest = (HttpServletRequest) request; - HttpServletResponse httpResponse = (HttpServletResponse) response; - Map contextMap = getContextMap(); - Map currentContextMap = MDC.getCopyOfContextMap(); - try { - MDC.setContextMap(contextMap); - loggingVisitor.logRequest(httpRequest, httpResponse); - } finally { - if (currentContextMap != null) { - MDC.setContextMap(currentContextMap); - } - } - } - } - - @Override public void onStartAsync(AsyncEvent event) throws IOException { } @Override public void onError(AsyncEvent event) throws IOException { - generateLog(loggingVisitor); + requestLogger.logRequest(); } @Override public void onComplete(AsyncEvent event) throws IOException { - generateLog(loggingVisitor); + requestLogger.logRequest(); } }); } diff --git a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingContextRequestWrapper.java b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingContextRequestWrapper.java index d5b1f124..5c761906 100644 --- a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingContextRequestWrapper.java +++ b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingContextRequestWrapper.java @@ -8,9 +8,9 @@ public class LoggingContextRequestWrapper extends HttpServletRequestWrapper { - private RequestLoggingVisitor loggingVisitor; + private RequestLogger loggingVisitor; - public LoggingContextRequestWrapper(HttpServletRequest request, RequestLoggingVisitor loggingVisitor) { + public LoggingContextRequestWrapper(HttpServletRequest request, RequestLogger loggingVisitor) { super(request); this.loggingVisitor = loggingVisitor; } diff --git a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLogger.java b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLogger.java new file mode 100644 index 00000000..835001a7 --- /dev/null +++ b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLogger.java @@ -0,0 +1,90 @@ +package com.sap.hcp.cf.logging.servlet.filter; + +import java.util.Collections; +import java.util.Map; + +import javax.servlet.http.HttpServletRequest; +import javax.servlet.http.HttpServletResponse; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.slf4j.MDC; + +import com.sap.hcp.cf.logging.common.Defaults; +import com.sap.hcp.cf.logging.common.Fields; +import com.sap.hcp.cf.logging.common.HttpHeaders; +import com.sap.hcp.cf.logging.common.LongValue; +import com.sap.hcp.cf.logging.common.Markers; +import com.sap.hcp.cf.logging.common.RequestRecord; + +public class RequestLogger { + + private static final Logger LOG = LoggerFactory.getLogger(RequestLogger.class); + + private HttpServletRequest httpRequest; + private HttpServletResponse httpResponse; + private RequestRecord requestRecord; + + public RequestLogger(RequestRecord requestRecord, HttpServletRequest httpRequest, + HttpServletResponse httpResponse) { + this.requestRecord = requestRecord; + this.httpRequest = httpRequest; + this.httpResponse = httpResponse; + } + + public void logRequest() { + requestRecord.stop(); + addRequestHandlingParameters(); + generateLog(); + } + + private void addRequestHandlingParameters() { + requestRecord.addValue(Fields.REQUEST_SIZE_B, new LongValue(httpRequest.getContentLength())); + LongValue responseSize = getResponseSize(httpResponse); + if (responseSize != null) { + requestRecord.addValue(Fields.RESPONSE_SIZE_B, responseSize); + } + requestRecord.addTag(Fields.RESPONSE_CONTENT_TYPE, getValue(httpResponse.getHeader(HttpHeaders.CONTENT_TYPE))); + requestRecord.addValue(Fields.RESPONSE_STATUS, new LongValue(httpResponse.getStatus())); + } + + private LongValue getResponseSize(HttpServletResponse httpResponse) { + String headerValue = httpResponse.getHeader(HttpHeaders.CONTENT_LENGTH); + if (headerValue != null) { + return new LongValue(Long.valueOf(headerValue)); + } + if (httpResponse != null && httpResponse instanceof ContentLengthTrackingResponseWrapper) { + ContentLengthTrackingResponseWrapper wrapper = (ContentLengthTrackingResponseWrapper) httpResponse; + return new LongValue(wrapper.getContentLength()); + } + return null; + } + + private String getValue(String value) { + return value != null ? value : Defaults.UNKNOWN; + } + + private void generateLog() { + Map contextMap = getContextMap(); + Map currentContextMap = MDC.getCopyOfContextMap(); + try { + MDC.setContextMap(contextMap); + LOG.info(Markers.REQUEST_MARKER, "{}", requestRecord); + } finally { + if (currentContextMap != null) { + MDC.setContextMap(currentContextMap); + } + } + } + + private Map getContextMap() { + try { + @SuppressWarnings("unchecked") + Map fromRequest = (Map) httpRequest.getAttribute(MDC.class.getName()); + return fromRequest != null ? fromRequest : Collections.emptyMap(); + } catch (ClassCastException ignored) { + return Collections.emptyMap(); + } + } + +} diff --git a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilter.java b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilter.java index 7aaa35fb..f7ee8dc8 100644 --- a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilter.java +++ b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilter.java @@ -1,7 +1,5 @@ package com.sap.hcp.cf.logging.servlet.filter; -import static com.sap.hcp.cf.logging.common.RequestRecordConfigurator.to; - import java.io.IOException; import javax.servlet.Filter; @@ -15,8 +13,6 @@ import org.slf4j.MDC; -import com.sap.hcp.cf.logging.common.Defaults; -import com.sap.hcp.cf.logging.common.Fields; import com.sap.hcp.cf.logging.common.HttpHeaders; import com.sap.hcp.cf.logging.common.LogContext; import com.sap.hcp.cf.logging.common.LogOptionalFieldsSettings; @@ -38,12 +34,21 @@ public class RequestLoggingFilter implements Filter { private boolean wrapRequest = true; private DynLogEnvironment dynLogEnvironment; private DynamicLogLevelProcessor dynamicLogLevelProcessor; - protected LogOptionalFieldsSettings logOptionalFieldsSettings; + private RequestRecordFactory requestRecordFactory; public RequestLoggingFilter() { - String invokingClass = this.getClass().getName().toString(); - logOptionalFieldsSettings = new LogOptionalFieldsSettings(invokingClass); - dynLogEnvironment = new DynLogEnvironment(); + this(createRequestRecordFactory()); + } + + private static RequestRecordFactory createRequestRecordFactory() { + String invokingClass = RequestLoggingFilter.class.getName(); + LogOptionalFieldsSettings logOptionalFieldsSettings = new LogOptionalFieldsSettings(invokingClass); + return new RequestRecordFactory(logOptionalFieldsSettings); + } + + RequestLoggingFilter(RequestRecordFactory requestRecordFactory) { + this.requestRecordFactory = requestRecordFactory; + this.dynLogEnvironment = new DynLogEnvironment(); if (dynLogEnvironment.getRsaPublicKey() != null) { dynamicLogLevelProcessor = new DynamicLogLevelProcessor(dynLogEnvironment); } @@ -88,9 +93,9 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse LogContext.initializeContext(getCorrelationIdFromHeader(httpRequest)); try { - RequestRecord rr = new RequestRecord(LOG_PROVIDER); - ContentLengthTrackingResponseWrapper responseWrapper = null; - ContentLengthTrackingRequestWrapper requestWrapper = null; + + RequestRecord rr = requestRecordFactory.create(httpRequest); + httpRequest.setAttribute(MDC.class.getName(), MDC.getCopyOfContextMap()); /* * -- we essentially do three things here: -- a) we create a log @@ -100,18 +105,16 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse * content length (hopefully) */ if (wrapResponse) { - responseWrapper = new ContentLengthTrackingResponseWrapper(httpResponse); + httpResponse = new ContentLengthTrackingResponseWrapper(httpResponse); } - RequestLoggingVisitor loggingVisitor = new RequestLoggingVisitor(rr, responseWrapper); - if (wrapRequest) { - httpRequest = new LoggingContextRequestWrapper(httpRequest, loggingVisitor); httpRequest = new ContentLengthTrackingRequestWrapper(httpRequest); } - addHeaders(httpRequest, rr); - httpRequest.setAttribute(MDC.class.getName(), MDC.getCopyOfContextMap()); + RequestLogger loggingVisitor = new RequestLogger(rr, httpRequest, httpResponse); + httpRequest = new LoggingContextRequestWrapper(httpRequest, loggingVisitor); + /* -- start measuring right before calling up the filter chain -- */ @@ -121,7 +124,7 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse } if (!httpRequest.isAsyncStarted()) { - loggingVisitor.logRequest(httpRequest, httpResponse); + loggingVisitor.logRequest(); } /* * -- close this @@ -141,32 +144,4 @@ private String getCorrelationIdFromHeader(HttpServletRequest httpRequest) { return cId; } - private String getHeader(HttpServletRequest request, String headerName) { - return getValue(request.getHeader(headerName)); - } - - private String getValue(String value) { - return value != null ? value : Defaults.UNKNOWN; - } - - private void addHeaders(HttpServletRequest request, RequestRecord lrec) { - lrec.addTag(Fields.REQUEST, request.getQueryString() != null - ? request.getRequestURI() + "?" + request.getQueryString() : request.getRequestURI()); - lrec.addTag(Fields.METHOD, request.getMethod()); - lrec.addTag(Fields.PROTOCOL, getValue(request.getProtocol())); - - boolean isSensitiveConnectionData = logOptionalFieldsSettings.isLogSensitiveConnectionData(); - - to(lrec).addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_IP, getValue(request.getRemoteAddr())) - .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_HOST, getValue(request.getRemoteHost())) - .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_PORT, - Integer.toString(request.getRemotePort())) - .addOptionalTag(isSensitiveConnectionData, Fields.X_FORWARDED_FOR, - getHeader(request, HttpHeaders.X_FORWARDED_FOR)) - .addOptionalTag(logOptionalFieldsSettings.isLogRemoteUserField(), Fields.REMOTE_USER, - getValue(request.getRemoteUser())) - .addOptionalTag(logOptionalFieldsSettings.isLogRefererField(), Fields.REFERER, - getHeader(request, HttpHeaders.REFERER)); - lrec.addContextTag(Fields.REQUEST_ID, getHeader(request, HttpHeaders.X_VCAP_REQUEST_ID)); - } } diff --git a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingVisitor.java b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingVisitor.java deleted file mode 100644 index 123d896d..00000000 --- a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingVisitor.java +++ /dev/null @@ -1,50 +0,0 @@ -package com.sap.hcp.cf.logging.servlet.filter; - -import javax.servlet.http.HttpServletRequest; -import javax.servlet.http.HttpServletResponse; - -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -import com.sap.hcp.cf.logging.common.Defaults; -import com.sap.hcp.cf.logging.common.Fields; -import com.sap.hcp.cf.logging.common.HttpHeaders; -import com.sap.hcp.cf.logging.common.LongValue; -import com.sap.hcp.cf.logging.common.Markers; -import com.sap.hcp.cf.logging.common.RequestRecord; - -public class RequestLoggingVisitor { - - private static final Logger LOG = LoggerFactory.getLogger(RequestLoggingVisitor.class); - - private ContentLengthTrackingResponseWrapper responseWrapper; - private RequestRecord requestRecord; - - public RequestLoggingVisitor(RequestRecord requestRecord, ContentLengthTrackingResponseWrapper responseWrapper) { - this.requestRecord = requestRecord; - this.responseWrapper = responseWrapper; - } - - public void logRequest(HttpServletRequest httpRequest, HttpServletResponse httpResponse) { - requestRecord.stop(); - requestRecord.addValue(Fields.REQUEST_SIZE_B, new LongValue(httpRequest.getContentLength())); - String headerValue = httpResponse.getHeader(HttpHeaders.CONTENT_LENGTH); - if (headerValue != null) { - requestRecord.addValue(Fields.RESPONSE_SIZE_B, new LongValue(Long.valueOf(headerValue))); - } else { - if (responseWrapper != null) { - requestRecord.addValue(Fields.RESPONSE_SIZE_B, new LongValue(responseWrapper.getContentLength())); - } - } - requestRecord.addTag(Fields.RESPONSE_CONTENT_TYPE, getValue(httpResponse.getHeader(HttpHeaders.CONTENT_TYPE))); - requestRecord.addValue(Fields.RESPONSE_STATUS, new LongValue(httpResponse.getStatus())); - - LOG.info(Markers.REQUEST_MARKER, "{}", requestRecord); - - } - - private String getValue(String value) { - return value != null ? value : Defaults.UNKNOWN; - } - -} diff --git a/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestRecordFactory.java b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestRecordFactory.java new file mode 100644 index 00000000..834c619a --- /dev/null +++ b/cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestRecordFactory.java @@ -0,0 +1,54 @@ +package com.sap.hcp.cf.logging.servlet.filter; + +import static com.sap.hcp.cf.logging.common.RequestRecordBuilder.requestRecord; + +import javax.servlet.http.HttpServletRequest; + +import com.sap.hcp.cf.logging.common.Defaults; +import com.sap.hcp.cf.logging.common.Fields; +import com.sap.hcp.cf.logging.common.HttpHeaders; +import com.sap.hcp.cf.logging.common.LogOptionalFieldsSettings; +import com.sap.hcp.cf.logging.common.RequestRecord; + +public class RequestRecordFactory { + + private final LogOptionalFieldsSettings logOptionalFieldsSettings; + + public RequestRecordFactory(LogOptionalFieldsSettings logOptionalFieldsSettings) { + this.logOptionalFieldsSettings = logOptionalFieldsSettings; + } + + public RequestRecord create(HttpServletRequest request) { + boolean isSensitiveConnectionData = logOptionalFieldsSettings.isLogSensitiveConnectionData(); + boolean isLogRemoteUserField = logOptionalFieldsSettings.isLogRemoteUserField(); + boolean isLogRefererField = logOptionalFieldsSettings.isLogRefererField(); + return requestRecord("[SERVLET]").addTag(Fields.REQUEST, getFullRequestUri(request)) + .addTag(Fields.METHOD, request.getMethod()) + .addTag(Fields.PROTOCOL, getValue(request.getProtocol())) + .addContextTag(Fields.REQUEST_ID, getHeader(request, HttpHeaders.X_VCAP_REQUEST_ID)) + .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_IP, getValue(request.getRemoteAddr())) + .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_HOST, getValue(request.getRemoteHost())) + .addOptionalTag(isSensitiveConnectionData, Fields.REMOTE_PORT, + Integer.toString(request.getRemotePort())) + .addOptionalTag(isSensitiveConnectionData, Fields.X_FORWARDED_FOR, + getHeader(request, HttpHeaders.X_FORWARDED_FOR)) + .addOptionalTag(isLogRemoteUserField, Fields.REMOTE_USER, getValue(request.getRemoteUser())) + .addOptionalTag(isLogRefererField, Fields.REFERER, getHeader(request, HttpHeaders.REFERER)) + .build(); + } + + private String getFullRequestUri(HttpServletRequest request) { + String queryString = request.getQueryString(); + String requestURI = request.getRequestURI(); + return queryString != null ? requestURI + "?" + queryString : requestURI; + } + + private String getHeader(HttpServletRequest request, String headerName) { + return getValue(request.getHeader(headerName)); + } + + private String getValue(String value) { + return value != null ? value : Defaults.UNKNOWN; + } + +} diff --git a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImplTest.java b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImplTest.java index 76019236..cdba4641 100644 --- a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImplTest.java +++ b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImplTest.java @@ -10,7 +10,6 @@ import static org.junit.Assert.assertThat; import static org.mockito.Matchers.any; import static org.mockito.Mockito.doAnswer; -import static org.mockito.Mockito.mock; import static org.mockito.Mockito.reset; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.when; @@ -21,7 +20,6 @@ import java.util.concurrent.Future; import javax.servlet.AsyncContext; -import javax.servlet.AsyncEvent; import javax.servlet.AsyncListener; import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; @@ -45,7 +43,7 @@ public class LoggingAsyncContextImplTest { private AsyncContext wrappedContext; @Mock - private RequestLoggingVisitor loggingVisitor; + private RequestLogger requestLogger; @Mock private HttpServletRequest request; @@ -147,24 +145,4 @@ public void run() { assertThat(finalContextMap, hasEntry("initial-key", "initial-value")); } - @Test - public void writesRequestLogWithMDCEntries() throws Exception { - Map mdcAttributes = new HashMap<>(); - mdcAttributes.put("this-key", "this-value"); - mdcAttributes.put("that-key", "that-value"); - when(request.getAttribute(MDC.class.getName())).thenReturn(mdcAttributes); - Map contextMap = new HashMap<>(); - doAnswer(new Answer() { - - @Override - public Void answer(InvocationOnMock invocation) throws Throwable { - contextMap.putAll(MDC.getCopyOfContextMap()); - return null; - } - }).when(loggingVisitor).logRequest(any(HttpServletRequest.class), any(HttpServletResponse.class)); - asyncListener.getValue().onComplete(mock(AsyncEvent.class)); - - assertThat(contextMap, both(hasEntry("that-key", "that-value")).and(hasEntry("this-key", "this-value"))); - - } } diff --git a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingVisitorTest.java b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggerTest.java similarity index 67% rename from cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingVisitorTest.java rename to cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggerTest.java index e00cec28..e21270e6 100644 --- a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingVisitorTest.java +++ b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggerTest.java @@ -1,5 +1,7 @@ package com.sap.hcp.cf.logging.servlet.filter; +import static org.hamcrest.Matchers.both; +import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.is; import static org.junit.Assert.assertThat; import static org.mockito.Matchers.eq; @@ -7,16 +9,20 @@ import static org.mockito.Mockito.verifyZeroInteractions; import static org.mockito.Mockito.when; +import java.util.HashMap; +import java.util.Map; + import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; +import org.junit.Rule; import org.junit.Test; import org.junit.runner.RunWith; import org.mockito.ArgumentCaptor; import org.mockito.Captor; -import org.mockito.InjectMocks; import org.mockito.Mock; import org.mockito.runners.MockitoJUnitRunner; +import org.slf4j.MDC; import com.sap.hcp.cf.logging.common.Fields; import com.sap.hcp.cf.logging.common.HttpHeaders; @@ -24,7 +30,10 @@ import com.sap.hcp.cf.logging.common.Value; @RunWith(MockitoJUnitRunner.class) -public class RequestLoggingVisitorTest { +public class RequestLoggerTest { + + @Rule + public SystemOutRule systemOut = new SystemOutRule(); @Mock private ContentLengthTrackingResponseWrapper responseWrapper; @@ -38,22 +47,23 @@ public class RequestLoggingVisitorTest { @Mock private HttpServletResponse httpResponse; - @InjectMocks - private RequestLoggingVisitor visitor; - @Captor private ArgumentCaptor valueCaptor; + private RequestLogger createLoggerWithoutResponse(HttpServletResponse response) { + return new RequestLogger(requestRecord, httpRequest, response); + } + @Test public void stopsRequestRecord() throws Exception { - visitor.logRequest(httpRequest, httpResponse); + createLoggerWithoutResponse(httpResponse).logRequest(); verify(requestRecord).stop(); } @Test public void addsHttpStatusAsValue() throws Exception { when(httpResponse.getStatus()).thenReturn(123); - visitor.logRequest(httpRequest, httpResponse); + createLoggerWithoutResponse(httpResponse).logRequest(); verify(requestRecord).addValue(eq(Fields.RESPONSE_STATUS), valueCaptor.capture()); assertThat(valueCaptor.getValue().asLong(), is(123L)); } @@ -61,14 +71,14 @@ public void addsHttpStatusAsValue() throws Exception { @Test public void addsResponseContentTypeAsTag() throws Exception { when(httpResponse.getHeader(HttpHeaders.CONTENT_TYPE)).thenReturn("application/vnd.test"); - visitor.logRequest(httpRequest, httpResponse); + createLoggerWithoutResponse(httpResponse).logRequest(); verify(requestRecord).addTag(Fields.RESPONSE_CONTENT_TYPE, "application/vnd.test"); } @Test public void addsRequestContentLengthAsValue() throws Exception { when(httpRequest.getContentLength()).thenReturn(12345); - visitor.logRequest(httpRequest, httpResponse); + createLoggerWithoutResponse(httpResponse).logRequest(); verify(requestRecord).addValue(eq(Fields.REQUEST_SIZE_B), valueCaptor.capture()); assertThat(valueCaptor.getValue().asLong(), is(12345L)); } @@ -76,7 +86,7 @@ public void addsRequestContentLengthAsValue() throws Exception { @Test public void addsResponseContentLengthAsValueFromHeaderIfAvailable() throws Exception { when(httpResponse.getHeader(HttpHeaders.CONTENT_LENGTH)).thenReturn("1234"); - visitor.logRequest(httpRequest, httpResponse); + createLoggerWithoutResponse(httpResponse).logRequest(); verify(requestRecord).addValue(eq(Fields.RESPONSE_SIZE_B), valueCaptor.capture()); verifyZeroInteractions(responseWrapper); assertThat(valueCaptor.getValue().asLong(), is(1234L)); @@ -85,9 +95,23 @@ public void addsResponseContentLengthAsValueFromHeaderIfAvailable() throws Excep @Test public void addsResponseContentLengthAsValueFromWrapperAsFAllback() throws Exception { when(responseWrapper.getContentLength()).thenReturn(1234L); - visitor.logRequest(httpRequest, httpResponse); + createLoggerWithoutResponse(responseWrapper).logRequest(); verify(requestRecord).addValue(eq(Fields.RESPONSE_SIZE_B), valueCaptor.capture()); assertThat(valueCaptor.getValue().asLong(), is(1234L)); } + @Test + public void writesRequestLogWithMDCEntries() throws Exception { + Map mdcAttributes = new HashMap<>(); + mdcAttributes.put("this-key", "this-value"); + mdcAttributes.put("that-key", "that-value"); + when(httpRequest.getAttribute(MDC.class.getName())).thenReturn(mdcAttributes); + createLoggerWithoutResponse(httpResponse).logRequest(); + + assertThat(systemOut.toString(), + both(containsString("\"this-key\":\"this-value\"")) + .and(containsString("\"that-key\":\"that-value\""))); + + } + } diff --git a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilterTest.java b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilterTest.java index 9039a635..8ea5c049 100644 --- a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilterTest.java +++ b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilterTest.java @@ -4,14 +4,16 @@ import static org.hamcrest.core.IsNot.not; import static org.hamcrest.text.IsEmptyString.isEmptyOrNullString; import static org.junit.Assert.assertThat; +import static org.mockito.Matchers.anyMapOf; +import static org.mockito.Matchers.eq; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.when; import java.io.BufferedReader; -import java.io.ByteArrayOutputStream; import java.io.IOException; -import java.io.PrintStream; import java.io.PrintWriter; +import java.util.HashMap; +import java.util.Map; import javax.servlet.FilterChain; import javax.servlet.ServletException; @@ -21,9 +23,13 @@ import javax.servlet.http.HttpServletRequest; import javax.servlet.http.HttpServletResponse; -import org.junit.After; import org.junit.Before; +import org.junit.Rule; import org.junit.Test; +import org.mockito.Mockito; +import org.mockito.invocation.InvocationOnMock; +import org.mockito.stubbing.Answer; +import org.slf4j.MDC; import com.fasterxml.jackson.jr.ob.JSON; import com.fasterxml.jackson.jr.ob.JSONObjectException; @@ -34,182 +40,168 @@ public class RequestLoggingFilterTest { - protected final ByteArrayOutputStream outContent = new ByteArrayOutputStream(); - protected final ByteArrayOutputStream errContent = new ByteArrayOutputStream(); - private PrintStream previousOut; - private PrintStream previousErr; - - private static final String REQUEST_ID = "1234-56-7890-xxx"; - private static final String CORRELATION_ID = "xxx-56-7890-xxx"; - private static final String REQUEST = "/foobar"; - private static final String QUERY_STRING = "baz=bla"; - private static final String FULL_REQUEST = REQUEST + "?" + QUERY_STRING; - private static final String REMOTE_HOST = "acme.org"; - private static final String REFERER = "my.fancy.com"; - - @Before - public void setupStreams() { - previousOut = System.out; - System.setOut(new PrintStream(outContent)); - previousErr = System.err; - System.setErr(new PrintStream(errContent)); - } - - @After - public void teardownStreams() { - System.setOut(previousOut); - System.setErr(previousErr); - } - - @Test - public void testSimple() throws IOException, ServletException { - HttpServletRequest mockReq = mock(HttpServletRequest.class); - HttpServletResponse mockResp = mock(HttpServletResponse.class); - PrintWriter mockWriter = mock(PrintWriter.class); - when(mockResp.getWriter()).thenReturn(mockWriter); - FilterChain mockFilterChain = mock(FilterChain.class); - new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); - assertThat(getField(Fields.REQUEST), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CORRELATION_ID), not(isEmptyOrNullString())); - assertThat(getField(Fields.REQUEST_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REMOTE_HOST), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REQUEST_SIZE_B), is("-1")); - } - - @Test - public void testInputStream() throws IOException, ServletException { - HttpServletRequest mockReq = mock(HttpServletRequest.class); - HttpServletResponse mockResp = mock(HttpServletResponse.class); - PrintWriter mockWriter = mock(PrintWriter.class); - ServletInputStream mockStream = mock(ServletInputStream.class); - - when(mockResp.getWriter()).thenReturn(mockWriter); - when(mockReq.getInputStream()).thenReturn(mockStream); - when(mockStream.read()).thenReturn(1); - FilterChain mockFilterChain = new FilterChain() { - @Override - public void doFilter(ServletRequest request, ServletResponse response) throws IOException, - ServletException { - request.getInputStream().read(); - } - }; - new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); - assertThat(getField(Fields.REQUEST), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CORRELATION_ID), not(isEmptyOrNullString())); - assertThat(getField(Fields.REQUEST_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REMOTE_HOST), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REQUEST_SIZE_B), is("1")); - } - - @Test - public void testReader() throws IOException, ServletException { - HttpServletRequest mockReq = mock(HttpServletRequest.class); - HttpServletResponse mockResp = mock(HttpServletResponse.class); - PrintWriter mockWriter = mock(PrintWriter.class); - BufferedReader mockReader = mock(BufferedReader.class); - - when(mockResp.getWriter()).thenReturn(mockWriter); - when(mockReq.getReader()).thenReturn(mockReader); - when(mockReader.read()).thenReturn(1); - FilterChain mockFilterChain = new FilterChain() { - @Override - public void doFilter(ServletRequest request, ServletResponse response) throws IOException, - ServletException { - request.getReader().read(); - } - }; - new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); - assertThat(getField(Fields.REQUEST), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CORRELATION_ID), not(isEmptyOrNullString())); - assertThat(getField(Fields.REQUEST_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REMOTE_HOST), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REQUEST_SIZE_B), is("1")); - } - - @Test - public void testWithActivatedOptionalFields() throws IOException, ServletException { - HttpServletRequest mockReq = mock(HttpServletRequest.class); - HttpServletResponse mockResp = mock(HttpServletResponse.class); - PrintWriter mockWriter = mock(PrintWriter.class); - when(mockResp.getWriter()).thenReturn(mockWriter); - when(mockReq.getRequestURI()).thenReturn(REQUEST); - when(mockReq.getQueryString()).thenReturn(QUERY_STRING); - when(mockReq.getRemoteHost()).thenReturn(REMOTE_HOST); - // will also set correlation id - when(mockReq.getHeader(HttpHeaders.X_VCAP_REQUEST_ID)).thenReturn(REQUEST_ID); - when(mockReq.getHeader(HttpHeaders.REFERER)).thenReturn(REFERER); - FilterChain mockFilterChain = mock(FilterChain.class); - LogOptionalFieldsSettings mockOptionalFieldsSettings = mock(LogOptionalFieldsSettings.class); - when(mockOptionalFieldsSettings.isLogSensitiveConnectionData()).thenReturn(true); - when(mockOptionalFieldsSettings.isLogRemoteUserField()).thenReturn(true); - when(mockOptionalFieldsSettings.isLogRefererField()).thenReturn(true); - RequestLoggingFilter requestLoggingFilter = new RequestLoggingFilter(); - requestLoggingFilter.logOptionalFieldsSettings = mockOptionalFieldsSettings; - requestLoggingFilter.doFilter(mockReq, mockResp, mockFilterChain); - assertThat(getField(Fields.REQUEST), is(FULL_REQUEST)); - assertThat(getField(Fields.CORRELATION_ID), is(REQUEST_ID)); - assertThat(getField(Fields.REQUEST_ID), is(REQUEST_ID)); - assertThat(getField(Fields.REMOTE_HOST), is(REMOTE_HOST)); - assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REFERER), is(REFERER)); - } - - @Test - public void testWithSuppressedOptionalFields() throws IOException, ServletException { - HttpServletRequest mockReq = mock(HttpServletRequest.class); - HttpServletResponse mockResp = mock(HttpServletResponse.class); - PrintWriter mockWriter = mock(PrintWriter.class); - when(mockResp.getWriter()).thenReturn(mockWriter); - when(mockReq.getRequestURI()).thenReturn(REQUEST); - when(mockReq.getQueryString()).thenReturn(QUERY_STRING); - when(mockReq.getRemoteHost()).thenReturn(REMOTE_HOST); - // will also set correlation id - when(mockReq.getHeader(HttpHeaders.X_VCAP_REQUEST_ID)).thenReturn(REQUEST_ID); - when(mockReq.getHeader(HttpHeaders.REFERER)).thenReturn(REFERER); - FilterChain mockFilterChain = mock(FilterChain.class); - LogOptionalFieldsSettings mockLogOptionalFieldsSettings = mock(LogOptionalFieldsSettings.class); - when(mockLogOptionalFieldsSettings.isLogSensitiveConnectionData()).thenReturn(false); - when(mockLogOptionalFieldsSettings.isLogRemoteUserField()).thenReturn(false); - when(mockLogOptionalFieldsSettings.isLogRefererField()).thenReturn(false); - RequestLoggingFilter requestLoggingFilter = new RequestLoggingFilter(); - requestLoggingFilter.logOptionalFieldsSettings = mockLogOptionalFieldsSettings; - requestLoggingFilter.doFilter(mockReq, mockResp, mockFilterChain); - assertThat(getField(Fields.REQUEST), is(FULL_REQUEST)); - assertThat(getField(Fields.CORRELATION_ID), is(REQUEST_ID)); - assertThat(getField(Fields.REQUEST_ID), is(REQUEST_ID)); - assertThat(getField(Fields.REMOTE_IP), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.REMOTE_HOST), is(Defaults.REDACTED)); - assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); - assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); - } - - @Test - public void testExplicitCorrelationId() throws IOException, ServletException { - HttpServletRequest mockReq = mock(HttpServletRequest.class); - HttpServletResponse mockResp = mock(HttpServletResponse.class); - PrintWriter mockWriter = mock(PrintWriter.class); - when(mockResp.getWriter()).thenReturn(mockWriter); - when(mockReq.getHeader(HttpHeaders.CORRELATION_ID)).thenReturn(CORRELATION_ID); - when(mockReq.getHeader(HttpHeaders.X_VCAP_REQUEST_ID)).thenReturn(REQUEST_ID); - FilterChain mockFilterChain = mock(FilterChain.class); - new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); - assertThat(getField(Fields.CORRELATION_ID), is(CORRELATION_ID)); - assertThat(getField(Fields.CORRELATION_ID), not(REQUEST_ID)); - } - - protected String getField(String fieldName) throws JSONObjectException, IOException { - return JSON.std.mapFrom(getLastLine()).get(fieldName).toString(); - } - - private String getLastLine() { - String[] lines = outContent.toString().split("\n"); - return lines[lines.length - 1]; - } + private static final String REQUEST_ID = "1234-56-7890-xxx"; + private static final String CORRELATION_ID = "xxx-56-7890-xxx"; + private static final String REQUEST = "/foobar"; + private static final String QUERY_STRING = "baz=bla"; + private static final String FULL_REQUEST = REQUEST + "?" + QUERY_STRING; + private static final String REMOTE_HOST = "acme.org"; + private static final String REFERER = "my.fancy.com"; + + @Rule + public SystemOutRule systemOut = new SystemOutRule(); + + @Rule + public SystemErrRule systemErr = new SystemErrRule(); + + private HttpServletRequest mockReq = mock(HttpServletRequest.class); + private HttpServletResponse mockResp = mock(HttpServletResponse.class); + private PrintWriter mockWriter = mock(PrintWriter.class); + + @Before + public void initMocks() throws IOException { + when(mockResp.getWriter()).thenReturn(mockWriter); + + Map contextMap = new HashMap<>(); + Mockito.doAnswer(new Answer() { + @SuppressWarnings("unchecked") + @Override + public Void answer(InvocationOnMock invocation) throws Throwable { + Object[] arguments = invocation.getArguments(); + contextMap.clear(); + contextMap.putAll((Map) arguments[1]); + return null; + } + }).when(mockReq).setAttribute(eq(MDC.class.getName()), anyMapOf(String.class, String.class)); + + when(mockReq.getAttribute(MDC.class.getName())).thenReturn(contextMap); + } + + @Test + public void testSimple() throws IOException, ServletException { + FilterChain mockFilterChain = mock(FilterChain.class); + new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); + assertThat(getField(Fields.REQUEST), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CORRELATION_ID), not(isEmptyOrNullString())); + assertThat(getField(Fields.REQUEST_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REMOTE_HOST), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REQUEST_SIZE_B), is("-1")); + } + + @Test + public void testInputStream() throws IOException, ServletException { + ServletInputStream mockStream = mock(ServletInputStream.class); + + when(mockReq.getInputStream()).thenReturn(mockStream); + when(mockStream.read()).thenReturn(1); + FilterChain mockFilterChain = new FilterChain() { + @Override + public void doFilter(ServletRequest request, ServletResponse response) + throws IOException, ServletException { + request.getInputStream().read(); + } + }; + new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); + assertThat(getField(Fields.REQUEST), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CORRELATION_ID), not(isEmptyOrNullString())); + assertThat(getField(Fields.REQUEST_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REMOTE_HOST), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REQUEST_SIZE_B), is("1")); + } + + @Test + public void testReader() throws IOException, ServletException { + BufferedReader mockReader = mock(BufferedReader.class); + + when(mockReq.getReader()).thenReturn(mockReader); + when(mockReader.read()).thenReturn(1); + FilterChain mockFilterChain = new FilterChain() { + @Override + public void doFilter(ServletRequest request, ServletResponse response) + throws IOException, ServletException { + request.getReader().read(); + } + }; + new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); + assertThat(getField(Fields.REQUEST), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CORRELATION_ID), not(isEmptyOrNullString())); + assertThat(getField(Fields.REQUEST_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REMOTE_HOST), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REQUEST_SIZE_B), is("1")); + } + + @Test + public void testWithActivatedOptionalFields() throws IOException, ServletException { + when(mockReq.getRequestURI()).thenReturn(REQUEST); + when(mockReq.getQueryString()).thenReturn(QUERY_STRING); + when(mockReq.getRemoteHost()).thenReturn(REMOTE_HOST); + // will also set correlation id + when(mockReq.getHeader(HttpHeaders.X_VCAP_REQUEST_ID)).thenReturn(REQUEST_ID); + when(mockReq.getHeader(HttpHeaders.REFERER)).thenReturn(REFERER); + FilterChain mockFilterChain = mock(FilterChain.class); + LogOptionalFieldsSettings mockOptionalFieldsSettings = mock(LogOptionalFieldsSettings.class); + when(mockOptionalFieldsSettings.isLogSensitiveConnectionData()).thenReturn(true); + when(mockOptionalFieldsSettings.isLogRemoteUserField()).thenReturn(true); + when(mockOptionalFieldsSettings.isLogRefererField()).thenReturn(true); + RequestRecordFactory requestRecordFactory = new RequestRecordFactory(mockOptionalFieldsSettings); + RequestLoggingFilter requestLoggingFilter = new RequestLoggingFilter(requestRecordFactory); + requestLoggingFilter.doFilter(mockReq, mockResp, mockFilterChain); + assertThat(getField(Fields.REQUEST), is(FULL_REQUEST)); + assertThat(getField(Fields.CORRELATION_ID), is(REQUEST_ID)); + assertThat(getField(Fields.REQUEST_ID), is(REQUEST_ID)); + assertThat(getField(Fields.REMOTE_HOST), is(REMOTE_HOST)); + assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REFERER), is(REFERER)); + } + + @Test + public void testWithSuppressedOptionalFields() throws IOException, ServletException { + when(mockReq.getRequestURI()).thenReturn(REQUEST); + when(mockReq.getQueryString()).thenReturn(QUERY_STRING); + when(mockReq.getRemoteHost()).thenReturn(REMOTE_HOST); + // will also set correlation id + when(mockReq.getHeader(HttpHeaders.X_VCAP_REQUEST_ID)).thenReturn(REQUEST_ID); + when(mockReq.getHeader(HttpHeaders.REFERER)).thenReturn(REFERER); + FilterChain mockFilterChain = mock(FilterChain.class); + LogOptionalFieldsSettings mockLogOptionalFieldsSettings = mock(LogOptionalFieldsSettings.class); + when(mockLogOptionalFieldsSettings.isLogSensitiveConnectionData()).thenReturn(false); + when(mockLogOptionalFieldsSettings.isLogRemoteUserField()).thenReturn(false); + when(mockLogOptionalFieldsSettings.isLogRefererField()).thenReturn(false); + RequestRecordFactory requestRecordFactory = new RequestRecordFactory(mockLogOptionalFieldsSettings); + RequestLoggingFilter requestLoggingFilter = new RequestLoggingFilter(requestRecordFactory); + requestLoggingFilter.doFilter(mockReq, mockResp, mockFilterChain); + assertThat(getField(Fields.REQUEST), is(FULL_REQUEST)); + assertThat(getField(Fields.CORRELATION_ID), is(REQUEST_ID)); + assertThat(getField(Fields.REQUEST_ID), is(REQUEST_ID)); + assertThat(getField(Fields.REMOTE_IP), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.REMOTE_HOST), is(Defaults.REDACTED)); + assertThat(getField(Fields.COMPONENT_ID), is(Defaults.UNKNOWN)); + assertThat(getField(Fields.CONTAINER_ID), is(Defaults.UNKNOWN)); + } + + @Test + public void testExplicitCorrelationId() throws IOException, ServletException { + when(mockReq.getHeader(HttpHeaders.CORRELATION_ID)).thenReturn(CORRELATION_ID); + when(mockReq.getHeader(HttpHeaders.X_VCAP_REQUEST_ID)).thenReturn(REQUEST_ID); + FilterChain mockFilterChain = mock(FilterChain.class); + new RequestLoggingFilter().doFilter(mockReq, mockResp, mockFilterChain); + assertThat(getField(Fields.CORRELATION_ID), is(CORRELATION_ID)); + assertThat(getField(Fields.CORRELATION_ID), not(REQUEST_ID)); + } + + protected String getField(String fieldName) throws JSONObjectException, IOException { + return JSON.std.mapFrom(getLastLine()).get(fieldName).toString(); + } + + private String getLastLine() { + String[] lines = systemOut.toString().split("\n"); + return lines[lines.length - 1]; + } } diff --git a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/SystemErrRule.java b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/SystemErrRule.java new file mode 100644 index 00000000..0adfa22e --- /dev/null +++ b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/SystemErrRule.java @@ -0,0 +1,30 @@ +package com.sap.hcp.cf.logging.servlet.filter; + +import java.io.ByteArrayOutputStream; +import java.io.OutputStream; +import java.io.PrintStream; + +import org.junit.rules.ExternalResource; + +public class SystemErrRule extends ExternalResource { + + private PrintStream originalErr; + private OutputStream output = new ByteArrayOutputStream(); + + @Override + protected void before() throws Throwable { + this.originalErr = System.err; + System.setErr(new PrintStream(output)); + } + + @Override + protected void after() { + System.setOut(originalErr); + System.out.append(output.toString()); + }; + + @Override + public String toString() { + return output.toString(); + } +} diff --git a/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/SystemOutRule.java b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/SystemOutRule.java new file mode 100644 index 00000000..b4d380ad --- /dev/null +++ b/cf-java-logging-support-servlet/src/test/java/com/sap/hcp/cf/logging/servlet/filter/SystemOutRule.java @@ -0,0 +1,30 @@ +package com.sap.hcp.cf.logging.servlet.filter; + +import java.io.ByteArrayOutputStream; +import java.io.OutputStream; +import java.io.PrintStream; + +import org.junit.rules.ExternalResource; + +public class SystemOutRule extends ExternalResource { + + private PrintStream originalOut; + private OutputStream output = new ByteArrayOutputStream(); + + @Override + protected void before() throws Throwable { + this.originalOut = System.out; + System.setOut(new PrintStream(output)); + } + + @Override + protected void after() { + System.setOut(originalOut); + System.out.append(output.toString()); + }; + + @Override + public String toString() { + return output.toString(); + } +} diff --git a/pom.xml b/pom.xml index 6fff03c3..a1f7b775 100644 --- a/pom.xml +++ b/pom.xml @@ -4,7 +4,7 @@ com.sap.hcp.cf.logging cf-java-logging-support-parent - 2.2.0 + 2.2.1-SNAPSHOT pom Cloud Foundry Java logging support components diff --git a/sample/manifest.yml b/sample/manifest.yml index 7dd4f9c1..71bfa088 100644 --- a/sample/manifest.yml +++ b/sample/manifest.yml @@ -5,7 +5,7 @@ applications: # - name: logging-sample-app instances: 1 - path: target/logging-sample-app-2.2.0.war + path: target/logging-sample-app-2.2.1-SNAPSHOT.war routes: - route: logging-sample-app env: diff --git a/sample/pom.xml b/sample/pom.xml index 6c13dfaa..bf46b707 100644 --- a/sample/pom.xml +++ b/sample/pom.xml @@ -6,7 +6,7 @@ com.sap.hcp.cf.logging cf-java-logging-support-parent - 2.2.0 + 2.2.1-SNAPSHOT ../pom.xml @@ -18,7 +18,7 @@ 1.7.12 2.22.2 2.0.1 - 2.2.0 + 2.2.1-SNAPSHOT