Add interceptor method on server which will be called after all other

processing

hapi-fhir-base/src/main/java/ca/uhn/fhir/rest/server/RestfulServer.java

@@ -29,15 +29,8 @@ import java.lang.annotation.Annotation;
 import java.lang.reflect.InvocationTargetException;
 import java.lang.reflect.Method;
 import java.lang.reflect.Modifier;
-import java.util.ArrayList;
+import java.util.*;
-import java.util.Arrays;
-import java.util.Collection;
-import java.util.Collections;
-import java.util.HashMap;
-import java.util.List;
-import java.util.Map;
 import java.util.Map.Entry;
-import java.util.StringTokenizer;
 import java.util.concurrent.locks.Lock;
 import java.util.concurrent.locks.ReentrantLock;
 import java.util.jar.Manifest;
@@ -78,14 +71,16 @@ import ca.uhn.fhir.rest.server.interceptor.ExceptionHandlingInterceptor;
 import ca.uhn.fhir.rest.server.interceptor.IServerInterceptor;
 import ca.uhn.fhir.rest.server.interceptor.ResponseHighlighterInterceptor;
 import ca.uhn.fhir.rest.server.servlet.ServletRequestDetails;
-import ca.uhn.fhir.util.CoverageIgnore;
+import ca.uhn.fhir.util.*;
-import ca.uhn.fhir.util.ReflectionUtil;
-import ca.uhn.fhir.util.UrlPathTokenizer;
-import ca.uhn.fhir.util.UrlUtil;
-import ca.uhn.fhir.util.VersionUtil;
 
 public class RestfulServer extends HttpServlet implements IRestfulServer<ServletRequestDetails> {
 
+	/**
+	 * All incoming requests will have an attribute added to {@link HttpServletRequest#getAttribute(String)}
+	 * with this key. The value will be a Java {@link Date} with the time that request processing began.
+	 */
+	public static final String REQUEST_START_TIME = RestfulServer.class.getName() + "REQUEST_START_TIME";
+
 	/**
 	 * Default setting for {@link #setETagSupport(ETagSupportEnum) ETag Support}: {@link ETagSupportEnum#ENABLED}
 	 */
@@ -658,6 +653,10 @@ public class RestfulServer extends HttpServlet implements IRestfulServer<Servlet
 			 */
 			resourceMethod.invokeServer(this, requestDetails);
 
+			for (IServerInterceptor next : myInterceptors) {
+				next.processingCompletedNormally(requestDetails);
+			}
+
 		} catch (NotModifiedException e) {
 
 			for (int i = getInterceptors().size() - 1; i >= 0; i--) {
@@ -1163,6 +1162,8 @@ public class RestfulServer extends HttpServlet implements IRestfulServer<Servlet
 
 	@Override
 	protected void service(HttpServletRequest theReq, HttpServletResponse theResp) throws ServletException, IOException {
+		theReq.setAttribute(REQUEST_START_TIME, new Date());
+		
 		RequestTypeEnum method;
 		try {
 			method = RequestTypeEnum.valueOf(theReq.getMethod());

hapi-fhir-base/src/main/java/ca/uhn/fhir/rest/server/interceptor/IServerInterceptor.java

@@ -10,7 +10,7 @@ package ca.uhn.fhir.rest.server.interceptor;
  * you may not use this file except in compliance with the License.
  * You may obtain a copy of the License at
  * 
- *      http://www.apache.org/licenses/LICENSE-2.0
+ * http://www.apache.org/licenses/LICENSE-2.0
  * 
  * Unless required by applicable law or agreed to in writing, software
  * distributed under the License is distributed on an "AS IS" BASIS,
@@ -41,8 +41,10 @@ import ca.uhn.fhir.rest.annotation.Search;
 import ca.uhn.fhir.rest.api.RestOperationTypeEnum;
 import ca.uhn.fhir.rest.method.RequestDetails;
 import ca.uhn.fhir.rest.server.IRestfulServerDefaults;
+import ca.uhn.fhir.rest.server.RestfulServer;
 import ca.uhn.fhir.rest.server.exceptions.AuthenticationException;
 import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
+import ca.uhn.fhir.rest.server.servlet.ServletRequestDetails;
 
 /**
  * Provides methods to intercept requests and responses. Note that implementations of this interface may wish to use
@@ -88,7 +90,8 @@ public interface IServerInterceptor {
 	 * @throws IOException
 	 *            If this exception is thrown, it will be re-thrown up to the container for handling.
 	 */
-	boolean handleException(RequestDetails theRequestDetails, BaseServerResponseException theException, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws ServletException, IOException;
+	boolean handleException(RequestDetails theRequestDetails, BaseServerResponseException theException, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse)
+			throws ServletException, IOException;
 
 	/**
 	 * This method is called just before the actual implementing server method is invoked.
@@ -118,10 +121,10 @@ public interface IServerInterceptor {
 
 	/**
 	 * Invoked before an incoming request is processed. Note that this method is called
-	 * after the server has begin preparing the response to the incoming client request. 
+	 * after the server has begin preparing the response to the incoming client request.
 	 * As such, it is not able to supply a response to the incoming request in the way that
 	 * {@link #incomingRequestPreHandled(RestOperationTypeEnum, ActionRequestDetails)} and
-	 * {@link #incomingRequestPostProcessed(RequestDetails, HttpServletRequest, HttpServletResponse)} 
+	 * {@link #incomingRequestPostProcessed(RequestDetails, HttpServletRequest, HttpServletResponse)}
 	 * are.
 	 * <p>
 	 * This method may however throw a subclass of {@link BaseServerResponseException}, and processing
@@ -292,7 +295,8 @@ public interface IServerInterceptor {
 	 *            This exception may be thrown to indicate that the interceptor has detected an unauthorized access
 	 *            attempt. If thrown, processing will stop and an HTTP 401 will be returned to the client.
 	 */
-	boolean outgoingResponse(RequestDetails theRequestDetails, IBaseResource theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws AuthenticationException;
+	boolean outgoingResponse(RequestDetails theRequestDetails, IBaseResource theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse)
+			throws AuthenticationException;
 
 	/**
 	 * This method is called after the server implementation method has been called, but before any attempt to stream the
@@ -364,6 +368,15 @@ public interface IServerInterceptor {
 	 */
 	BaseServerResponseException preProcessOutgoingException(RequestDetails theRequestDetails, Throwable theException, HttpServletRequest theServletRequest) throws ServletException;
 
+	/**
+	 * This method is called after all processing is completed for a request, but only if the
+	 * request completes normally (i.e. no exception is thrown).
+	 * 
+	 * @param theRequestDetails
+	 *           The request itself
+	 */
+	void processingCompletedNormally(ServletRequestDetails theRequestDetails);
+
 	public static class ActionRequestDetails {
 		private final FhirContext myContext;
 		private final IIdType myId;
@@ -400,20 +413,22 @@ public interface IServerInterceptor {
 			myResource = theResource;
 		}
 
-		public ActionRequestDetails(RequestDetails theRequestDetails, String theResourceType, IIdType theId) {
-			this(theRequestDetails, theRequestDetails.getServer().getFhirContext(), theResourceType, theId);
-		}
-
 		/**
 		 * Constructor
 		 * 
-		 * @param theRequestDetails The request details to wrap
+		 * @param theRequestDetails
-		 * @param theId The ID of the resource being created (note that the ID should have the resource type populated)
+		 *           The request details to wrap
+		 * @param theId
+		 *           The ID of the resource being created (note that the ID should have the resource type populated)
 		 */
 		public ActionRequestDetails(RequestDetails theRequestDetails, IIdType theId) {
 			this(theRequestDetails, theId.getResourceType(), theId);
 		}
 
+		public ActionRequestDetails(RequestDetails theRequestDetails, String theResourceType, IIdType theId) {
+			this(theRequestDetails, theRequestDetails.getServer().getFhirContext(), theResourceType, theId);
+		}
+
 		public FhirContext getContext() {
 			return myContext;
 		}
@@ -454,14 +469,14 @@ public interface IServerInterceptor {
 		}
 
 		/**
-		 * Returns the same map which was 
+		 * Returns the same map which was
 		 */
 		public Map<Object, Object> getUserData() {
 			return myRequestDetails.getUserData();
 		}
 
 		/**
-		 * This method may be invoked by user code to notify interceptors that a nested 
+		 * This method may be invoked by user code to notify interceptors that a nested
 		 * operation is being invoked which is denoted by this request details.
 		 */
 		public void notifyIncomingRequestPreHandled(RestOperationTypeEnum theOperationType) {

hapi-fhir-base/src/main/java/ca/uhn/fhir/rest/server/interceptor/InterceptorAdapter.java

@@ -10,7 +10,7 @@ package ca.uhn.fhir.rest.server.interceptor;
  * you may not use this file except in compliance with the License.
  * You may obtain a copy of the License at
  * 
- *      http://www.apache.org/licenses/LICENSE-2.0
+ * http://www.apache.org/licenses/LICENSE-2.0
  * 
  * Unless required by applicable law or agreed to in writing, software
  * distributed under the License is distributed on an "AS IS" BASIS,
@@ -38,13 +38,13 @@ import ca.uhn.fhir.rest.server.servlet.ServletRequestDetails;
 
 /**
  * Base class for {@link IServerInterceptor} implementations. Provides a No-op implementation
- * of all methods, always returning <code>true</code> 
+ * of all methods, always returning <code>true</code>
  */
 public class InterceptorAdapter implements IServerInterceptor {
 
 	@Override
-	public boolean handleException(RequestDetails theRequestDetails, BaseServerResponseException theException, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws ServletException,
+	public boolean handleException(RequestDetails theRequestDetails, BaseServerResponseException theException, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse)
-			IOException {
+			throws ServletException, IOException {
 		return true;
 	}
 
@@ -64,52 +64,60 @@ public class InterceptorAdapter implements IServerInterceptor {
 	}
 
 	@Override
-	public boolean outgoingResponse(RequestDetails theRequestDetails, Bundle theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws AuthenticationException {
+	public boolean outgoingResponse(RequestDetails theRequestDetails) {
+		ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
+		return outgoingResponse(theRequestDetails, details.getServletRequest(), details.getServletResponse());
+	}
+
+	@Override
+	public boolean outgoingResponse(RequestDetails theRequestDetails, Bundle bundle) {
+		ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
+		return outgoingResponse(details, bundle, details.getServletRequest(), details.getServletResponse());
+	}
+
+	@Override
+	public boolean outgoingResponse(RequestDetails theRequestDetails, Bundle theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse)
+			throws AuthenticationException {
 		return true;
 	}
-	
-    @Override
-    public boolean outgoingResponse(RequestDetails theRequestDetails, Bundle bundle) {
-        ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
-        return outgoingResponse(details, bundle, details.getServletRequest(), details.getServletResponse());
-    }	
 
 	@Override
 	public boolean outgoingResponse(RequestDetails theRequestDetails, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws AuthenticationException {
 		return true;
 	}
-	
-    @Override
-    public boolean outgoingResponse(RequestDetails theRequestDetails) {
-        ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
-        return outgoingResponse(theRequestDetails, details.getServletRequest(), details.getServletResponse());
-    }	
 
 	@Override
-	public boolean outgoingResponse(RequestDetails theRequestDetails, IBaseResource theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws AuthenticationException {
+	public boolean outgoingResponse(RequestDetails theRequestDetails, IBaseResource theResponseObject) {
-		return true;
+		ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
+		return outgoingResponse(details, theResponseObject, details.getServletRequest(), details.getServletResponse());
 	}
-	
+
-    @Override
-    public boolean outgoingResponse(RequestDetails theRequestDetails, IBaseResource theResponseObject) {
-        ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
-        return outgoingResponse(details, theResponseObject, details.getServletRequest(), details.getServletResponse());
-    }	
-	
 	@Override
-	public boolean outgoingResponse(RequestDetails theRequestDetails, TagList theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws AuthenticationException {
+	public boolean outgoingResponse(RequestDetails theRequestDetails, IBaseResource theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse)
+			throws AuthenticationException {
+		return true;
+	}
+
+	@Override
+	public boolean outgoingResponse(RequestDetails theRequestDetails, TagList theResponseObject) {
+		ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
+		return outgoingResponse(details, theResponseObject, details.getServletRequest(), details.getServletResponse());
+	}
+
+	@Override
+	public boolean outgoingResponse(RequestDetails theRequestDetails, TagList theResponseObject, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse)
+			throws AuthenticationException {
 		return true;
 	}
-	
-    @Override
-    public boolean outgoingResponse(RequestDetails theRequestDetails, TagList theResponseObject) {
-        ServletRequestDetails details = (ServletRequestDetails) theRequestDetails;
-        return outgoingResponse(details, theResponseObject, details.getServletRequest(), details.getServletResponse());
-    }	
 
 	@Override
 	public BaseServerResponseException preProcessOutgoingException(RequestDetails theRequestDetails, Throwable theException, HttpServletRequest theServletRequest) throws ServletException {
 		return null;
 	}
 
+	@Override
+	public void processingCompletedNormally(ServletRequestDetails theRequestDetails) {
+		// nothing
+	}
+
 }

hapi-fhir-base/src/main/java/ca/uhn/fhir/rest/server/interceptor/LoggingInterceptor.java

@@ -26,6 +26,7 @@ import java.io.IOException;
 
 import java.io.UnsupportedEncodingException;
 import java.net.URLEncoder;
+import java.util.Date;
 import java.util.Map.Entry;
 
 import javax.servlet.ServletException;
@@ -41,11 +42,14 @@ import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
 import ca.uhn.fhir.rest.method.RequestDetails;
+import ca.uhn.fhir.rest.server.Constants;
 import ca.uhn.fhir.rest.server.EncodingEnum;
+import ca.uhn.fhir.rest.server.RestfulServer;
 import ca.uhn.fhir.rest.server.RestfulServerUtils;
 import ca.uhn.fhir.rest.server.RestfulServerUtils.ResponseEncoding;
 import ca.uhn.fhir.rest.server.exceptions.AuthenticationException;
 import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
+import ca.uhn.fhir.rest.server.servlet.ServletRequestDetails;
 
 /**
  * Server interceptor which logs each request using a defined format
@@ -74,7 +78,7 @@ import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
  * </tr>
  * <tr>
  * <td>${remoteAddr}</td>
- * <td>The originaring IP of the request</td>
+ * <td>The originating IP of the request</td>
  * </tr>
  * <tr>
  * <td>${requestHeader.XXXX}</td>
@@ -115,6 +119,15 @@ import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
  * </tr>
  * </table>
  */
+
+/*
+ * TODO: implement this, but it needs the logging to happen at the end
+ * <tr>
+ * <td>${processingTimeMillis}</td>
+ * <td>The number of milliseconds spent processing this request</td>
+ * </tr>
+
+ */
 public class LoggingInterceptor extends InterceptorAdapter {
 
 	private static final org.slf4j.Logger ourLog = org.slf4j.LoggerFactory.getLogger(LoggingInterceptor.class);
@@ -146,18 +159,16 @@ public class LoggingInterceptor extends InterceptorAdapter {
 		return true;
 	}
 
-	@Override
-	public boolean incomingRequestPostProcessed(final RequestDetails theRequestDetails, final HttpServletRequest theRequest, HttpServletResponse theResponse) throws AuthenticationException {
 
+	@Override
+	public void processingCompletedNormally(ServletRequestDetails theRequestDetails) {
 		// Perform any string substitutions from the message format
-		StrLookup<?> lookup = new MyLookup(theRequest, theRequestDetails);
+		StrLookup<?> lookup = new MyLookup(theRequestDetails.getServletRequest(), theRequestDetails);
 		StrSubstitutor subs = new StrSubstitutor(lookup, "${", "}", '\\');
 
 		// Actuall log the line
 		String line = subs.replace(myMessageFormat);
 		myLogger.info(line);
-
-		return true;
 	}
 
 	/**
@@ -308,10 +319,16 @@ public class LoggingInterceptor extends InterceptorAdapter {
 					EncodingEnum encoding = EncodingEnum.forContentType(contentType);
 					if (encoding != null) {
 						byte[] requestContents = myRequestDetails.loadRequestContents();
-						return new String(requestContents, Charsets.UTF_8);
+						return new String(requestContents, Constants.CHARSET_UTF8);
 					}
 				}
 				return "";
+			} else if ("processingTimeMillis".equals(theKey)) {
+				Date startTime = (Date) myRequest.getAttribute(RestfulServer.REQUEST_START_TIME);
+				if (startTime != null) {
+					long time = System.currentTimeMillis() - startTime.getTime();
+					return Long.toString(time);
+				}
 			}
 
 			return "!VAL!";

hapi-fhir-base/src/main/java/ca/uhn/fhir/rest/server/interceptor/ResponseHighlighterInterceptor.java

@@ -24,10 +24,12 @@ import static org.apache.commons.lang3.StringUtils.isNotBlank;
  */
 
 import java.io.IOException;
+import java.util.Date;
 import java.util.Map;
 import java.util.Set;
 
 import javax.servlet.ServletException;
+import javax.servlet.ServletRequest;
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
 
@@ -39,6 +41,7 @@ import ca.uhn.fhir.rest.api.RequestTypeEnum;
 import ca.uhn.fhir.rest.method.RequestDetails;
 import ca.uhn.fhir.rest.server.Constants;
 import ca.uhn.fhir.rest.server.EncodingEnum;
+import ca.uhn.fhir.rest.server.RestfulServer;
 import ca.uhn.fhir.rest.server.RestfulServerUtils;
 import ca.uhn.fhir.rest.server.exceptions.AuthenticationException;
 import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
@@ -206,7 +209,7 @@ public class ResponseHighlighterInterceptor extends InterceptorAdapter {
 			return super.handleException(theRequestDetails, theException, theServletRequest, theServletResponse);
 		}
 
-		streamResponse(theRequestDetails, theServletResponse, theException.getOperationOutcome());
+		streamResponse(theRequestDetails, theServletResponse, theException.getOperationOutcome(), theServletRequest);
 
 		return false;
 	}
@@ -276,12 +279,12 @@ public class ResponseHighlighterInterceptor extends InterceptorAdapter {
 			return super.outgoingResponse(theRequestDetails, theResponseObject, theServletRequest, theServletResponse);
 		}
 
-		streamResponse(theRequestDetails, theServletResponse, theResponseObject);
+		streamResponse(theRequestDetails, theServletResponse, theResponseObject, theServletRequest);
 
 		return false;
 	}
 
-	private void streamResponse(RequestDetails theRequestDetails, HttpServletResponse theServletResponse, IBaseResource resource) {
+	private void streamResponse(RequestDetails theRequestDetails, HttpServletResponse theServletResponse, IBaseResource resource, ServletRequest theServletRequest) {
 		IParser p;
 		Map<String, String[]> parameters = theRequestDetails.getParameters();
 		if (parameters.containsKey(Constants.PARAM_FORMAT)) {
@@ -360,6 +363,16 @@ public class ResponseHighlighterInterceptor extends InterceptorAdapter {
 		b.append("<a href=\"");
 		b.append(createLinkHref(parameters, Constants.FORMATS_HTML_XML));
 		b.append("\">HTML XML</a>.");
+		
+		Date startTime = (Date) theServletRequest.getAttribute(RestfulServer.REQUEST_START_TIME);
+		if (startTime != null) {
+			long time = System.currentTimeMillis() - startTime.getTime();
+			b.append(" Response generated in ");
+			b.append(time);
+			b.append("ms.");
+		}
+
+		
 		b.append("</p>");
 		
 		b.append("\n");

hapi-fhir-structures-dstu/src/test/java/ca/uhn/fhir/rest/client/LoggingInterceptorTest.java

@@ -3,18 +3,17 @@ package ca.uhn.fhir.rest.client;
 import static org.junit.Assert.assertFalse;
 import static org.junit.Assert.assertNotNull;
 import static org.mockito.Matchers.argThat;
-import static org.mockito.Mockito.*;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.times;
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.when;
 
 import java.net.URL;
 
 import org.eclipse.jetty.server.Server;
 import org.eclipse.jetty.servlet.ServletHandler;
 import org.eclipse.jetty.servlet.ServletHolder;
-import org.junit.After;
+import org.junit.*;
-import org.junit.AfterClass;
-import org.junit.Before;
-import org.junit.BeforeClass;
-import org.junit.Test;
 import org.mockito.ArgumentMatcher;
 import org.slf4j.LoggerFactory;
 
@@ -29,18 +28,13 @@ import ca.uhn.fhir.rest.server.IResourceProvider;
 import ca.uhn.fhir.rest.server.RestfulServer;
 import ca.uhn.fhir.util.PortUtil;
 import ca.uhn.fhir.util.TestUtil;
-import ch.qos.logback.classic.BasicConfigurator;
 import ch.qos.logback.classic.Logger;
 import ch.qos.logback.classic.LoggerContext;
 import ch.qos.logback.classic.joran.JoranConfigurator;
 import ch.qos.logback.classic.spi.ILoggingEvent;
 import ch.qos.logback.classic.spi.LoggingEvent;
-import ch.qos.logback.classic.util.LogbackMDCAdapter;
 import ch.qos.logback.core.Appender;
 
-/**
- * Created by dsotnikov on 2/25/2014.
- */
 public class LoggingInterceptorTest {
 
 	private static FhirContext ourCtx = FhirContext.forDstu1();

hapi-fhir-structures-dstu2/src/test/java/ca/uhn/fhir/rest/server/interceptor/LoggingInterceptorDstu2Test.java

@@ -1,5 +1,6 @@
 package ca.uhn.fhir.rest.server.interceptor;
 
+import static org.hamcrest.Matchers.matchesPattern;
 import static org.junit.Assert.assertEquals;
 import static org.junit.Assert.assertThat;
 import static org.junit.Assert.assertTrue;
@@ -59,9 +60,6 @@ import ca.uhn.fhir.rest.server.exceptions.InvalidRequestException;
 import ca.uhn.fhir.util.PortUtil;
 import ca.uhn.fhir.util.TestUtil;
 
-/**
- * Created by dsotnikov on 2/25/2014.
- */
 public class LoggingInterceptorDstu2Test {
 
 	private static CloseableHttpClient ourClient;
@@ -70,6 +68,7 @@ public class LoggingInterceptorDstu2Test {
 	private static Server ourServer;
 	private static RestfulServer servlet;
 	private IServerInterceptor myInterceptor;
+	private static int ourDelayMs;
 	private static Exception ourThrowException;
 
 	@Before
@@ -77,6 +76,7 @@ public class LoggingInterceptorDstu2Test {
 		myInterceptor = mock(IServerInterceptor.class);
 		servlet.setInterceptors(Collections.singletonList(myInterceptor));
 		ourThrowException = null;
+		ourDelayMs=0;
 	}
 
 	@Test
@@ -160,6 +160,27 @@ public class LoggingInterceptorDstu2Test {
 		assertEquals("read -  - Patient/1 - ", captor.getValue());
 	}
 
+	@Test
+	public void testProcessingTime() throws Exception {
+		ourDelayMs = 110;
+
+		LoggingInterceptor interceptor = new LoggingInterceptor();
+		interceptor.setMessageFormat("${processingTimeMillis}");
+		servlet.setInterceptors(Collections.singletonList((IServerInterceptor) interceptor));
+
+		Logger logger = mock(Logger.class);
+		interceptor.setLogger(logger);
+
+		HttpGet httpGet = new HttpGet("http://localhost:" + ourPort + "/Patient/1");
+
+		HttpResponse status = ourClient.execute(httpGet);
+		IOUtils.closeQuietly(status.getEntity().getContent());
+
+		ArgumentCaptor<String> captor = ArgumentCaptor.forClass(String.class);
+		verify(logger, times(1)).info(captor.capture());
+		assertThat(captor.getValue(), matchesPattern("[0-9]{3}"));
+	}
+
 	@Test
 	public void testRequestBodyReadWithContentTypeHeader() throws Exception {
 
@@ -386,7 +407,11 @@ public class LoggingInterceptorDstu2Test {
 		 * @return The resource
 		 */
 		@Read()
-		public Patient getResourceById(@IdParam IdDt theId) {
+		public Patient getResourceById(@IdParam IdDt theId) throws InterruptedException {
+			if (ourDelayMs>0) {
+				Thread.sleep(ourDelayMs);
+			}
+			
 			if (theId.getIdPart().equals("EX")) {
 				throw new InvalidRequestException("FOO");
 			}

hapi-fhir-structures-dstu2/src/test/java/ca/uhn/fhir/rest/server/interceptor/ResponseHighlightingInterceptorTest.java

@@ -1,6 +1,7 @@
 package ca.uhn.fhir.rest.server.interceptor;
 
 import static org.hamcrest.Matchers.containsString;
+import static org.hamcrest.Matchers.matchesPattern;
 import static org.hamcrest.Matchers.not;
 import static org.hamcrest.Matchers.stringContainsInOrder;
 import static org.junit.Assert.assertArrayEquals;
@@ -14,6 +15,7 @@ import static org.mockito.Mockito.when;
 
 import java.io.PrintWriter;
 import java.io.StringWriter;
+import java.nio.charset.StandardCharsets;
 import java.util.Collections;
 import java.util.Enumeration;
 import java.util.HashMap;
@@ -87,12 +89,26 @@ public class ResponseHighlightingInterceptorTest {
 	}
 
 
+	@Test
+	public void testForceResponseTime() throws Exception {
+		HttpGet httpGet = new HttpGet("http://localhost:" + ourPort + "/Patient/1?_format=html/json");
+		
+		HttpResponse status = ourClient.execute(httpGet);
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
+		IOUtils.closeQuietly(status.getEntity().getContent());
+		ourLog.info(responseContent);
+		assertEquals(200, status.getStatusLine().getStatusCode());
+		assertEquals("text/html;charset=utf-8", status.getFirstHeader("content-type").getValue().replace(" ", "").toLowerCase());
+		assertThat(responseContent.replace('\n', ' ').replace('\r', ' '), matchesPattern(".*Response generated in [0-9]+ms.*"));
+		
+	}
+
 	@Test
 	public void testGetInvalidResource() throws Exception {
 		HttpGet httpGet = new HttpGet("http://localhost:" + ourPort + "/Foobar/123");
 		httpGet.addHeader("Accept", "text/html");
 		CloseableHttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 
 		ourLog.info("Resp: {}", responseContent);
@@ -457,7 +473,7 @@ public class ResponseHighlightingInterceptorTest {
 		HttpGet httpGet = new HttpGet("http://localhost:" + ourPort + "/Patient?_query=searchWithWildcardRetVal&_summary=count");
 		httpGet.addHeader("Accept", "html");
 		CloseableHttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 
 		ourLog.info("Resp: {}", responseContent);
@@ -501,7 +517,7 @@ public class ResponseHighlightingInterceptorTest {
 		httpGet.addHeader("Accept", Constants.CT_FHIR_JSON);
 		
 		HttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 		assertEquals(200, status.getStatusLine().getStatusCode());
 		assertEquals(Constants.CT_FHIR_JSON + ";charset=utf-8", status.getFirstHeader("content-type").getValue().replace(" ", "").toLowerCase());
@@ -515,7 +531,7 @@ public class ResponseHighlightingInterceptorTest {
 		httpGet.addHeader("User-Agent", "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:40.0) Gecko/20100101 Firefox/40.1");
 		
 		HttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 		assertEquals(200, status.getStatusLine().getStatusCode());
 		assertEquals(Constants.CT_FHIR_JSON + ";charset=utf-8", status.getFirstHeader("content-type").getValue().replace(" ", "").toLowerCase());
@@ -527,7 +543,7 @@ public class ResponseHighlightingInterceptorTest {
 		httpGet.addHeader("User-Agent", "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:40.0) Gecko/20100101 Firefox/40.1");
 		
 		HttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 		assertEquals(200, status.getStatusLine().getStatusCode());
 		assertEquals(Constants.CT_FHIR_JSON + ";charset=utf-8", status.getFirstHeader("content-type").getValue().replace(" ", "").toLowerCase());
@@ -539,7 +555,7 @@ public class ResponseHighlightingInterceptorTest {
 		httpGet.addHeader("User-Agent", "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:40.0) Gecko/20100101 Firefox/40.1");
 		
 		HttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 		assertEquals(200, status.getStatusLine().getStatusCode());
 		assertEquals(Constants.CT_FHIR_JSON + ";charset=utf-8", status.getFirstHeader("content-type").getValue().replace(" ", "").toLowerCase());
@@ -552,7 +568,7 @@ public class ResponseHighlightingInterceptorTest {
 		httpGet.addHeader("User-Agent", "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:40.0) Gecko/20100101 Firefox/40.1");
 		
 		HttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 		assertEquals(200, status.getStatusLine().getStatusCode());
 		assertEquals(Constants.CT_FHIR_JSON + ";charset=utf-8", status.getFirstHeader("content-type").getValue().replace(" ", "").toLowerCase());
@@ -567,7 +583,7 @@ public class ResponseHighlightingInterceptorTest {
 		httpGet.addHeader("User-Agent", "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:40.0) Gecko/20100101 Firefox/40.1");
 		
 		HttpResponse status = ourClient.execute(httpGet);
-		String responseContent = IOUtils.toString(status.getEntity().getContent());
+		String responseContent = IOUtils.toString(status.getEntity().getContent(), StandardCharsets.UTF_8);
 		IOUtils.closeQuietly(status.getEntity().getContent());
 		assertEquals(200, status.getStatusLine().getStatusCode());
 		assertEquals("text/html;charset=utf-8", status.getFirstHeader("content-type").getValue().replace(" ", "").toLowerCase());

hapi-fhir-structures-dstu3/src/test/java/ca/uhn/fhir/rest/client/PatchClientDstu3Test.java

@@ -62,7 +62,7 @@ public class PatchClientDstu3Test {
 	}
 
 	@Test
-	public void testJsonPatch() throws Exception {
+	public void testJsonPatchAnnotation() throws Exception {
 		ArgumentCaptor<HttpUriRequest> capt = prepareResponse();
 
 		IClientType client = ourCtx.newRestfulClient(IClientType.class, "http://example.com/fhir");
@@ -79,6 +79,26 @@ public class PatchClientDstu3Test {
 		assertEquals("<div xmlns=\"http://www.w3.org/1999/xhtml\">OK</div>", ((OperationOutcome) outcome.getOperationOutcome()).getText().getDivAsString());
 	}
 
+	@Test
+	public void testJsonPatchFluent() throws Exception {
+		ArgumentCaptor<HttpUriRequest> capt = prepareResponse();
+
+		IGenericClient client = ourCtx.newRestfulGenericClient("http://example.com/fhir");
+
+		Patient pt = new Patient();
+		pt.getText().setDivAsString("A PATIENT");
+
+		MethodOutcome outcome = client.patch().resource("").
+				
+				patch(new IdType("Patient/123"), "{}", PatchTypeEnum.JSON_PATCH);
+
+		assertEquals("PATCH", capt.getAllValues().get(0).getMethod());
+		assertEquals("http://example.com/fhir/Patient/123", capt.getAllValues().get(0).getURI().toASCIIString());
+		assertEquals(Constants.CT_JSON_PATCH, capt.getAllValues().get(0).getFirstHeader("content-type").getValue().replaceAll(";.*", ""));
+		assertEquals("{}", extractBodyAsString(capt));
+		assertEquals("<div xmlns=\"http://www.w3.org/1999/xhtml\">OK</div>", ((OperationOutcome) outcome.getOperationOutcome()).getText().getDivAsString());
+	}
+
 
 	private String extractBodyAsString(ArgumentCaptor<HttpUriRequest> capt) throws IOException {
 		String body = IOUtils.toString(((HttpEntityEnclosingRequestBase) capt.getAllValues().get(0)).getEntity().getContent(), "UTF-8");

src/changes/changes.xml

@@ -84,7 +84,7 @@
 			<action type="fix">
 				Server history operation did not populate the Bundle.entry.request.url
 				field, which is required in order for the bundle to pass validation.
-				Thanks to Richard Kavanaugh for spotting this!  
+				Thanks to Richard Ettema for spotting this!  
 			</action>
 		</release>
 		<release version="2.0" date="2016-08-30">