Fix getRequest and getResponse calls after Response commit

Signed-off-by: Karsten Schnitter <[email protected]>

Author: KarstenSchnitter

cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/LoggingAsyncContextImpl.java

@@ -11,56 +11,34 @@
 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;
 
 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<String, String> contextMap = getContextMap();
-					Map<String, String> 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();
 			}
 		});
 	}

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;
 	}

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<String, String> contextMap = getContextMap();
+		Map<String, String> currentContextMap = MDC.getCopyOfContextMap();
+		try {
+			MDC.setContextMap(contextMap);
+			LOG.info(Markers.REQUEST_MARKER, "{}", requestRecord);
+		} finally {
+			if (currentContextMap != null) {
+				MDC.setContextMap(currentContextMap);
+			}
+		}
+	}
+
+	private Map<String, String> getContextMap() {
+		try {
+			@SuppressWarnings("unchecked")
+			Map<String, String> fromRequest = (Map<String, String>) httpRequest.getAttribute(MDC.class.getName());
+			return fromRequest != null ? fromRequest : Collections.emptyMap();
+		} catch (ClassCastException ignored) {
+			return Collections.emptyMap();
+		}
+	}
+
+}

cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingFilter.java

@@ -95,7 +95,7 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse
 		try {
 
 			RequestRecord rr = requestRecordFactory.create(httpRequest);
-			ContentLengthTrackingResponseWrapper responseWrapper = null;
+			httpRequest.setAttribute(MDC.class.getName(), MDC.getCopyOfContextMap());
 
 			/*
 			 * -- we essentially do three things here: -- a) we create a log
@@ -105,17 +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 ContentLengthTrackingRequestWrapper(httpRequest);
-				httpRequest = new LoggingContextRequestWrapper(httpRequest, loggingVisitor);
 			}
 
-			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 -- */
@@ -125,7 +124,7 @@ private void doFilterRequest(HttpServletRequest httpRequest, HttpServletResponse
 			}
 
 			if (!httpRequest.isAsyncStarted()) {
-				loggingVisitor.logRequest(httpRequest, httpResponse);
+				loggingVisitor.logRequest();
 			}
 			/*
 			 * -- close this

cf-java-logging-support-servlet/src/main/java/com/sap/hcp/cf/logging/servlet/filter/RequestLoggingVisitor.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<String, String> mdcAttributes = new HashMap<>();
-		mdcAttributes.put("this-key", "this-value");
-		mdcAttributes.put("that-key", "that-value");
-		when(request.getAttribute(MDC.class.getName())).thenReturn(mdcAttributes);
-		Map<String, String> contextMap = new HashMap<>();
-		doAnswer(new Answer<Void>() {
-
-			@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")));
-
-	}
 }