honeymoose
/
hapi-fhir
mirror of https://github.com/hapifhir/hapi-fhir.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Move stopwatch into hapi-fhir-base and add timing into to client 

LoggingInterceptor
This commit is contained in:
James Agnew 2018-03-04 12:13:18 -05:00
parent 928cf23b4c
commit 2f7751a079
39 changed files with 459 additions and 427 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

12
hapi-fhir-base/src/main/java/ca/uhn/fhir/rest/client/api/IHttpResponse.java
View File

@ -20,6 +20,8 @@ package ca.uhn.fhir.rest.client.api;
* #L%
*/
import ca.uhn.fhir.util.StopWatch;
import java.io.IOException;
import java.io.InputStream;
import java.io.Reader;
@ -91,6 +93,15 @@ public interface IHttpResponse {
*/
String getMimeType();
/**
* @return Returns a StopWatch that was started right before
* the client request was started. The time returned by this
* client includes any time that was spent within the HTTP
* library (possibly including waiting for a connection, and
* any network activity)
*/
StopWatch getRequestStopWatch();
/**
* @return the native response, depending on the client library used
*/
@ -114,5 +125,4 @@ public interface IHttpResponse {
* Read the message entity input stream as an InputStream.
*/
InputStream readEntity() throws IOException;
}

209
hapi-fhir-base/src/main/java/ca/uhn/fhir/util/StopWatch.java Normal file
View File

@ -0,0 +1,209 @@
package ca.uhn.fhir.util;
import com.google.common.annotations.VisibleForTesting;
import org.apache.commons.lang3.time.DateUtils;
import java.text.DecimalFormat;
import java.text.NumberFormat;
import java.util.Date;
import java.util.concurrent.TimeUnit;
/*
* #%L
* HAPI FHIR JPA Server
* %%
* Copyright (C) 2014 - 2018 University Health Network
* %%
* Licensed under the Apache License, Version 2.0 (the "License");
* 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
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
* #L%
*/
/**
* @since HAPI FHIR 3.3.0
*/
public class StopWatch {
private static final NumberFormat DAY_FORMAT = new DecimalFormat("0.0");
private static final NumberFormat TEN_DAY_FORMAT = new DecimalFormat("0");
private static Long ourNowForUnitTest;
private long myStarted = now();
/**
* Constructor
*/
public StopWatch() {
super();
}
/**
* Constructor
*
* @param theStart The time to record as the start for this timer
*/
public StopWatch(Date theStart) {
myStarted = theStart.getTime();
}
public String formatThroughput(int theNumOperations, TimeUnit theUnit) {
double throughput = getThroughput(theNumOperations, theUnit);
return new DecimalFormat("0.0").format(throughput);
}
/**
* Given an amount of something completed so far, and a total amount, calculates how long it will take for something to complete
*
* @param theCompleteToDate The amount so far
* @param theTotal The total (must be higher than theCompleteToDate
* @return A formatted amount of time
*/
public String getEstimatedTimeRemaining(double theCompleteToDate, double theTotal) {
double completeSoFar = theCompleteToDate / theTotal;
double remaining;
if (completeSoFar > 0.5) {
remaining = (1.0 - completeSoFar);
} else {
remaining = (1.0 / completeSoFar);
}
double millis = getMillis();
long millisRemaining = (long) (millis * remaining);
return formatMillis(millisRemaining);
}
public long getMillis(Date theNow) {
return theNow.getTime() - myStarted;
}
public long getMillis() {
long now = now();
return now - myStarted;
}
public long getMillisAndRestart() {
long now = now();
long retVal = now - myStarted;
myStarted = now;
return retVal;
}
/**
* @param theNumOperations Ok for this to be 0, it will be treated as 1
*/
public int getMillisPerOperation(int theNumOperations) {
return (int) (((double) getMillis()) / Math.max(1.0, theNumOperations));
}
public Date getStartedDate() {
return new Date(myStarted);
}
public double getThroughput(int theNumOperations, TimeUnit theUnit) {
if (theNumOperations <= 0) {
return 0.0f;
}
long millisElapsed = Math.max(1, getMillis());
long periodMillis = theUnit.toMillis(1);
double numerator = theNumOperations;
double denominator = ((double) millisElapsed) / ((double) periodMillis);
return numerator / denominator;
}
public void restart() {
myStarted = now();
}
/**
* Formats value in an appropriate format. See {@link #formatMillis(long)}}
* for a description of the format
*
* @see #formatMillis(long)
*/
@Override
public String toString() {
return formatMillis(getMillis());
}
/**
* Append a right-aligned and zero-padded numeric value to a `StringBuilder`.
*/
static private void append(StringBuilder tgt, String pfx, int dgt, long val) {
tgt.append(pfx);
if (dgt > 1) {
int pad = (dgt - 1);
for (long xa = val; xa > 9 && pad > 0; xa /= 10) {
pad--;
}
for (int xa = 0; xa < pad; xa++) {
tgt.append('0');
}
}
tgt.append(val);
}
/**
* Formats a number of milliseconds for display (e.g.
* in a log file), tailoring the output to how big
* the value actually is.
* <p>
* Example outputs:
* </p>
* <ul>
* <li>133ms</li>
* <li>00:00:10.223</li>
* <li>1.7 days</li>
* <li>64 days</li>
* </ul>
*/
public static String formatMillis(long val) {
StringBuilder buf = new StringBuilder(20);
if (val < (10 * DateUtils.MILLIS_PER_SECOND)) {
buf.append(val);
buf.append("ms");
} else if (val >= DateUtils.MILLIS_PER_DAY) {
double days = (double) val / DateUtils.MILLIS_PER_DAY;
if (days >= 10) {
buf.append(TEN_DAY_FORMAT.format(days));
buf.append(" days");
} else if (days != 1.0f) {
buf.append(DAY_FORMAT.format(days));
buf.append(" days");
} else {
buf.append(DAY_FORMAT.format(days));
buf.append(" day");
}
} else {
append(buf, "", 2, ((val % DateUtils.MILLIS_PER_DAY) / DateUtils.MILLIS_PER_HOUR));
append(buf, ":", 2, ((val % DateUtils.MILLIS_PER_HOUR) / DateUtils.MILLIS_PER_MINUTE));
append(buf, ":", 2, ((val % DateUtils.MILLIS_PER_MINUTE) / DateUtils.MILLIS_PER_SECOND));
if (val <= DateUtils.MILLIS_PER_MINUTE) {
append(buf, ".", 3, (val % DateUtils.MILLIS_PER_SECOND));
}
}
return buf.toString();
}
private static long now() {
if (ourNowForUnitTest != null) {
return ourNowForUnitTest;
}
return System.currentTimeMillis();
}
@VisibleForTesting
static void setNowForUnitTestForUnitTest(Long theNowForUnitTest) {
ourNowForUnitTest = theNowForUnitTest;
}
}

8
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/util/StopWatchTest.java → hapi-fhir-base/src/test/java/ca/uhn/fhir/util/StopWatchTest.java
View File

@ -1,4 +1,4 @@
package ca.uhn.fhir.jpa.util;
package ca.uhn.fhir.util;
import org.apache.commons.lang3.time.DateUtils;
import org.hamcrest.Matchers;
@ -33,7 +33,7 @@ public class StopWatchTest {
StopWatch sw = new StopWatch();
StopWatch.setNowForUnitTestForUnitTest(777777777L + DateUtils.MILLIS_PER_MINUTE);
assertEquals("00:00:00.600", sw.getEstimatedTimeRemaining(0.99, 1.0));
assertEquals("600ms", sw.getEstimatedTimeRemaining(0.99, 1.0));
StopWatch.setNowForUnitTestForUnitTest(777777777L + DateUtils.MILLIS_PER_MINUTE);
assertEquals("00:10:00", sw.getEstimatedTimeRemaining(0.1, 1.0));
@ -53,7 +53,7 @@ public class StopWatchTest {
@Test
public void testFormatMillis() {
assertEquals("00:00:01.000", StopWatch.formatMillis(DateUtils.MILLIS_PER_SECOND));
assertEquals("1000ms", StopWatch.formatMillis(DateUtils.MILLIS_PER_SECOND));
assertEquals("00:01:00.000", StopWatch.formatMillis(DateUtils.MILLIS_PER_MINUTE));
assertEquals("00:01:01", StopWatch.formatMillis(DateUtils.MILLIS_PER_MINUTE + DateUtils.MILLIS_PER_SECOND));
assertEquals("01:00:00", StopWatch.formatMillis(DateUtils.MILLIS_PER_HOUR));
@ -143,7 +143,7 @@ public class StopWatchTest {
String string = sw.toString();
ourLog.info(string);
assertThat(string, startsWith("00:00"));
assertThat(string, matchesPattern("^[0-9]{3,4}ms$"));
}
}

4
hapi-fhir-client-okhttp/src/main/java/ca/uhn/fhir/okhttp/client/OkHttpRestfulRequest.java
View File

@ -27,6 +27,7 @@ import java.util.Map;
import ca.uhn.fhir.rest.api.RequestTypeEnum;
import ca.uhn.fhir.rest.client.api.IHttpRequest;
import ca.uhn.fhir.rest.client.api.IHttpResponse;
import ca.uhn.fhir.util.StopWatch;
import okhttp3.Call;
import okhttp3.Call.Factory;
import okhttp3.Request;
@ -65,9 +66,10 @@ public class OkHttpRestfulRequest implements IHttpRequest {
@Override
public IHttpResponse execute() throws IOException {
StopWatch responseStopWatch = new StopWatch();
myRequestBuilder.method(getHttpVerbName(), myRequestBody);
Call call = myClient.newCall(myRequestBuilder.build());
return new OkHttpRestfulResponse(call.execute());
return new OkHttpRestfulResponse(call.execute(), responseStopWatch);
}
@Override

7
hapi-fhir-client-okhttp/src/main/java/ca/uhn/fhir/okhttp/client/OkHttpRestfulResponse.java
View File

@ -4,6 +4,8 @@ import java.io.*;
import java.util.List;
import java.util.Map;
import ca.uhn.fhir.rest.client.impl.BaseHttpResponse;
import ca.uhn.fhir.util.StopWatch;
import org.apache.commons.io.IOUtils;
import ca.uhn.fhir.rest.api.Constants;
@ -38,13 +40,14 @@ import okhttp3.Response;
*
* @author Matthew Clarke | matthew.clarke@orionhealth.com | Orion Health
*/
public class OkHttpRestfulResponse implements IHttpResponse {
public class OkHttpRestfulResponse extends BaseHttpResponse implements IHttpResponse {
private boolean myEntityBuffered = false;
private byte[] myEntityBytes;
private Response myResponse;
public OkHttpRestfulResponse(Response theResponse) {
public OkHttpRestfulResponse(Response theResponse, StopWatch theResponseStopWatch) {
super(theResponseStopWatch);
this.myResponse = theResponse;
}

6
hapi-fhir-client/src/main/java/ca/uhn/fhir/rest/client/apache/ApacheHttpRequest.java
View File

@ -27,10 +27,12 @@ import java.util.LinkedList;
import java.util.List;
import java.util.Map;
import ca.uhn.fhir.util.StopWatch;
import org.apache.commons.io.IOUtils;
import org.apache.http.Header;
import org.apache.http.HttpEntity;
import org.apache.http.HttpEntityEnclosingRequest;
import org.apache.http.HttpResponse;
import org.apache.http.client.HttpClient;
import org.apache.http.client.methods.HttpRequestBase;
import org.apache.http.entity.ContentType;
@ -61,7 +63,9 @@ public class ApacheHttpRequest implements IHttpRequest {
@Override
public IHttpResponse execute() throws IOException {
return new ApacheHttpResponse(myClient.execute(myRequest));
StopWatch responseStopWatch = new StopWatch();
HttpResponse httpResponse = myClient.execute(myRequest);
return new ApacheHttpResponse(httpResponse, responseStopWatch);
}
@Override

7
hapi-fhir-client/src/main/java/ca/uhn/fhir/rest/client/apache/ApacheHttpResponse.java
View File

@ -23,6 +23,8 @@ import java.io.*;
import java.nio.charset.Charset;
import java.util.*;
import ca.uhn.fhir.rest.client.impl.BaseHttpResponse;
import ca.uhn.fhir.util.StopWatch;
import org.apache.commons.io.IOUtils;
import org.apache.http.*;
import org.apache.http.client.methods.CloseableHttpResponse;
@ -38,7 +40,7 @@ import ca.uhn.fhir.rest.server.exceptions.InternalErrorException;
*
* @author Peter Van Houte | peter.vanhoute@agfa.com | Agfa Healthcare
*/
public class ApacheHttpResponse implements IHttpResponse {
public class ApacheHttpResponse extends BaseHttpResponse implements IHttpResponse {
private static final org.slf4j.Logger ourLog = org.slf4j.LoggerFactory.getLogger(ApacheHttpResponse.class);
@ -46,7 +48,8 @@ public class ApacheHttpResponse implements IHttpResponse {
private byte[] myEntityBytes;
private final HttpResponse myResponse;
public ApacheHttpResponse(HttpResponse theResponse) {
public ApacheHttpResponse(HttpResponse theResponse, StopWatch theResponseStopWatch) {
super(theResponseStopWatch);
this.myResponse = theResponse;
}

17
hapi-fhir-client/src/main/java/ca/uhn/fhir/rest/client/impl/BaseHttpResponse.java Normal file
View File

@ -0,0 +1,17 @@
package ca.uhn.fhir.rest.client.impl;
import ca.uhn.fhir.rest.client.api.IHttpResponse;
import ca.uhn.fhir.util.StopWatch;
public abstract class BaseHttpResponse implements IHttpResponse {
private final StopWatch myRequestStopWatch;
public BaseHttpResponse(StopWatch theRequestStopWatch) {
myRequestStopWatch = theRequestStopWatch;
}
@Override
public StopWatch getRequestStopWatch() {
return myRequestStopWatch;
}
}

4
hapi-fhir-client/src/main/java/ca/uhn/fhir/rest/client/interceptor/LoggingInterceptor.java
View File

@ -115,7 +115,9 @@ public class LoggingInterceptor implements IClientInterceptor {
}
respLocation = " (" + locationValue + ")";
}
myLog.info("Client response: {}{}", message, respLocation);
String timing = " in " + theResponse.getRequestStopWatch().toString();
myLog.info("Client response: {}{}{}", message, respLocation, timing);
}
if (myLogResponseHeaders) {

2
hapi-fhir-igpacks/src/main/java/ca/uhn/fhir/igpacks/parser/IgPackParserDstu3.java
View File

@ -23,7 +23,7 @@ package ca.uhn.fhir.igpacks.parser;
import ca.uhn.fhir.context.FhirContext;
import ca.uhn.fhir.context.FhirVersionEnum;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.Constants;
import ca.uhn.fhir.rest.server.exceptions.InternalErrorException;
import org.apache.commons.lang3.Validate;

70
hapi-fhir-jaxrsserver-base/src/main/java/ca/uhn/fhir/jaxrs/client/JaxRsHttpRequest.java
View File

@ -20,18 +20,18 @@ package ca.uhn.fhir.jaxrs.client;
* #L%
*/
import java.util.HashMap;
import java.util.LinkedList;
import java.util.List;
import java.util.Map;
import ca.uhn.fhir.rest.api.RequestTypeEnum;
import ca.uhn.fhir.rest.client.api.IHttpRequest;
import ca.uhn.fhir.rest.client.api.IHttpResponse;
import ca.uhn.fhir.util.StopWatch;
import javax.ws.rs.client.Entity;
import javax.ws.rs.client.Invocation;
import javax.ws.rs.core.Response;
import ca.uhn.fhir.rest.api.RequestTypeEnum;
import ca.uhn.fhir.rest.client.api.IHttpRequest;
import ca.uhn.fhir.rest.client.api.IHttpResponse;
import java.util.HashMap;
import java.util.LinkedList;
import java.util.List;
import java.util.Map;
/**
* A Http Request based on JaxRs. This is an adapter around the class
@ -41,10 +41,10 @@ import ca.uhn.fhir.rest.client.api.IHttpResponse;
*/
public class JaxRsHttpRequest implements IHttpRequest {
private final Map<String, List<String>> myHeaders = new HashMap<String, List<String>>();
private Invocation.Builder myRequest;
private RequestTypeEnum myRequestType;
private Entity<?> myEntity;
private final Map<String, List<String>> myHeaders = new HashMap<String, List<String>>();
public JaxRsHttpRequest(Invocation.Builder theRequest, RequestTypeEnum theRequestType, Entity<?> theEntity) {
this.myRequest = theRequest;
@ -61,24 +61,22 @@ public class JaxRsHttpRequest implements IHttpRequest {
getRequest().header(theName, theValue);
}
/**
* Get the Request
* @return the Request
*/
public Invocation.Builder getRequest() {
return myRequest;
@Override
public IHttpResponse execute() {
StopWatch responseStopWatch = new StopWatch();
Invocation invocation = getRequest().build(getRequestType().name(), getEntity());
Response response = invocation.invoke();
return new JaxRsHttpResponse(response, responseStopWatch);
}
/**
* Get the Request Type
* @return the request type
*/
public RequestTypeEnum getRequestType() {
return myRequestType == null ? RequestTypeEnum.GET : myRequestType;
@Override
public Map<String, List<String>> getAllHeaders() {
return this.myHeaders;
}
/**
* Get the Entity
*
* @return the entity
*/
public Entity<?> getEntity() {
@ -86,15 +84,17 @@ public class JaxRsHttpRequest implements IHttpRequest {
}
@Override
public IHttpResponse execute() {
Invocation invocation = getRequest().build(getRequestType().name(), getEntity());
Response response = invocation.invoke();
return new JaxRsHttpResponse(response);
public String getHttpVerbName() {
return myRequestType.name();
}
@Override
public Map<String, List<String>> getAllHeaders() {
return this.myHeaders;
/**
* Get the Request
*
* @return the Request
*/
public Invocation.Builder getRequest() {
return myRequest;
}
@Override
@ -103,14 +103,18 @@ public class JaxRsHttpRequest implements IHttpRequest {
return null;
}
/**
* Get the Request Type
*
* @return the request type
*/
public RequestTypeEnum getRequestType() {
return myRequestType == null ? RequestTypeEnum.GET : myRequestType;
}
@Override
public String getUri() {
return ""; // TODO: can we get this from somewhere?
}
@Override
public String getHttpVerbName() {
return myRequestType.name();
}
}

9
hapi-fhir-jaxrsserver-base/src/main/java/ca/uhn/fhir/jaxrs/client/JaxRsHttpResponse.java
View File

@ -25,7 +25,6 @@ import java.io.IOException;
import java.io.InputStream;
import java.io.Reader;
import java.io.StringReader;
import java.util.Collections;
import java.util.List;
import java.util.Map;
import java.util.Map.Entry;
@ -34,7 +33,8 @@ import java.util.concurrent.ConcurrentHashMap;
import javax.ws.rs.core.MediaType;
import javax.ws.rs.core.Response;
import org.apache.commons.lang3.ObjectUtils;
import ca.uhn.fhir.rest.client.impl.BaseHttpResponse;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.client.api.IHttpResponse;
@ -42,12 +42,13 @@ import ca.uhn.fhir.rest.client.api.IHttpResponse;
* A Http Response based on JaxRs. This is an adapter around the class {@link javax.ws.rs.core.Response Response}
* @author Peter Van Houte | peter.vanhoute@agfa.com | Agfa Healthcare
*/
public class JaxRsHttpResponse implements IHttpResponse {
public class JaxRsHttpResponse extends BaseHttpResponse implements IHttpResponse {
private boolean myBufferedEntity = false;
private final Response myResponse;
public JaxRsHttpResponse(Response theResponse) {
public JaxRsHttpResponse(Response theResponse, StopWatch theResponseStopWatch) {
super(theResponseStopWatch);
this.myResponse = theResponse;
}

12
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/BaseHapiFhirDao.java
View File

@ -61,6 +61,8 @@ import org.apache.commons.lang3.StringUtils;
import org.apache.commons.lang3.Validate;
import org.apache.http.NameValuePair;
import org.apache.http.client.utils.URLEncodedUtils;
import org.hibernate.Session;
import org.hibernate.internal.SessionImpl;
import org.hl7.fhir.instance.model.api.*;
import org.hl7.fhir.r4.model.BaseResource;
import org.hl7.fhir.r4.model.Bundle.HTTPVerb;
@ -633,6 +635,16 @@ public abstract class BaseHapiFhirDao<T extends IBaseResource> implements IDao {
}
}
protected void flushJpaSession() {
SessionImpl session = (SessionImpl) myEntityManager.unwrap(Session.class);
int insertionCount = session.getActionQueue().numberOfInsertions();
int updateCount = session.getActionQueue().numberOfUpdates();
StopWatch sw = new StopWatch();
myEntityManager.flush();
ourLog.debug("Session flush took {}ms for {} inserts and {} updates", sw.getMillis(), insertionCount, updateCount);
}
private Set<TagDefinition> getAllTagDefinitions(ResourceTable theEntity) {
HashSet<TagDefinition> retVal = Sets.newHashSet();
for (ResourceTag next : theEntity.getTags()) {

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/BaseHapiFhirResourceDao.java
View File

@ -32,7 +32,7 @@ import ca.uhn.fhir.jpa.entity.*;
import ca.uhn.fhir.jpa.search.DatabaseBackedPagingProvider;
import ca.uhn.fhir.jpa.search.PersistedJpaBundleProvider;
import ca.uhn.fhir.jpa.util.DeleteConflict;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.jpa.util.jsonpatch.JsonPatchUtils;
import ca.uhn.fhir.jpa.util.xmlpatch.XmlPatchUtils;
import ca.uhn.fhir.model.api.*;

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/BaseHapiFhirSystemDao.java
View File

@ -6,7 +6,7 @@ import ca.uhn.fhir.jpa.dao.data.ITermConceptDao;
import ca.uhn.fhir.jpa.entity.ForcedId;
import ca.uhn.fhir.jpa.entity.ResourceTable;
import ca.uhn.fhir.jpa.util.ReindexFailureException;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.RestOperationTypeEnum;
import ca.uhn.fhir.rest.api.server.IBundleProvider;
import ca.uhn.fhir.rest.api.server.RequestDetails;

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/BaseSearchParamRegistry.java
View File

@ -24,7 +24,7 @@ import ca.uhn.fhir.context.FhirContext;
import ca.uhn.fhir.context.RuntimeResourceDefinition;
import ca.uhn.fhir.context.RuntimeSearchParam;
import ca.uhn.fhir.jpa.search.JpaRuntimeSearchParam;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.server.IBundleProvider;
import ca.uhn.fhir.util.SearchParameterUtil;
import org.apache.commons.lang3.StringUtils;

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/SearchBuilder.java
View File

@ -28,7 +28,7 @@ import ca.uhn.fhir.jpa.search.JpaRuntimeSearchParam;
import ca.uhn.fhir.jpa.term.IHapiTerminologySvc;
import ca.uhn.fhir.jpa.term.VersionIndependentConcept;
import ca.uhn.fhir.jpa.util.BaseIterator;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.model.api.*;
import ca.uhn.fhir.model.base.composite.BaseCodingDt;
import ca.uhn.fhir.model.base.composite.BaseIdentifierDt;

10
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/dstu3/FhirSystemDaoDstu3.java
View File

@ -28,7 +28,7 @@ import java.util.Map.Entry;
import javax.persistence.TypedQuery;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.param.ParameterUtil;
import org.apache.commons.lang3.Validate;
import org.apache.http.NameValuePair;
@ -538,13 +538,7 @@ public class FhirSystemDaoDstu3 extends BaseHapiFhirSystemDao<Bundle, Meta> {
}
}
SessionImpl session = (SessionImpl) myEntityManager.unwrap(Session.class);
int insertionCount = session.getActionQueue().numberOfInsertions();
int updateCount = session.getActionQueue().numberOfUpdates();
StopWatch sw = new StopWatch();
myEntityManager.flush();
ourLog.debug("Session flush took {}ms for {} inserts and {} updates", sw.getMillis(), insertionCount, updateCount);
flushJpaSession();
/*
* Double check we didn't allow any duplicates we shouldn't have

8
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/dao/r4/FhirSystemDaoR4.java
View File

@ -29,6 +29,7 @@ import ca.uhn.fhir.jpa.entity.ResourceTable;
import ca.uhn.fhir.jpa.entity.TagDefinition;
import ca.uhn.fhir.jpa.provider.ServletSubRequestDetails;
import ca.uhn.fhir.jpa.util.DeleteConflict;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.model.api.ResourceMetadataKeyEnum;
import ca.uhn.fhir.parser.DataFormatException;
import ca.uhn.fhir.parser.IParser;
@ -547,8 +548,7 @@ public class FhirSystemDaoR4 extends BaseHapiFhirSystemDao<Bundle, Meta> {
}
}
myEntityManager.flush();
ourLog.debug("Session flush took {}ms for {} inserts and {} updates", sw.getMillis(), insertionCount, updateCount);
flushJpaSession();
/*
* Double check we didn't allow any duplicates we shouldn't have
@ -619,9 +619,7 @@ public class FhirSystemDaoR4 extends BaseHapiFhirSystemDao<Bundle, Meta> {
TypedQuery<TagDefinition> q = myEntityManager.createQuery(sql, TagDefinition.class);
List<TagDefinition> tagDefinitions = q.getResultList();
Meta retVal = toMeta(tagDefinitions);
return retVal;
return toMeta(tagDefinitions);
}
private String performIdSubstitutionsInMatchUrl(Map<IdType, IdType> theIdSubstitutions, String theMatchUrl) {

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImpl.java
View File

@ -29,7 +29,7 @@ import ca.uhn.fhir.jpa.dao.data.ISearchDao;
import ca.uhn.fhir.jpa.dao.data.ISearchIncludeDao;
import ca.uhn.fhir.jpa.dao.data.ISearchResultDao;
import ca.uhn.fhir.jpa.entity.*;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.model.api.Include;
import ca.uhn.fhir.rest.api.CacheControlDirective;
import ca.uhn.fhir.rest.api.Constants;

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/subscription/BaseSubscriptionInterceptor.java
View File

@ -28,7 +28,7 @@ import ca.uhn.fhir.jpa.dao.IFhirResourceDao;
import ca.uhn.fhir.jpa.dao.SearchParameterMap;
import ca.uhn.fhir.jpa.provider.ServletSubRequestDetails;
import ca.uhn.fhir.jpa.util.JpaConstants;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.RestOperationTypeEnum;
import ca.uhn.fhir.rest.api.server.IBundleProvider;
import ca.uhn.fhir.rest.api.server.RequestDetails;

4
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/subscription/SubscriptionCheckingSubscriber.java
View File

@ -102,13 +102,13 @@ public class SubscriptionCheckingSubscriber extends BaseSubscriptionSubscriber {
IBundleProvider results = performSearch(criteria);
ourLog.info("Subscription check found {} results for query: {}", results.size(), criteria);
ourLog.debug("Subscription check found {} results for query: {}", results.size(), criteria);
if (results.size() == 0) {
continue;
}
ourLog.info("Found match: queueing rest-hook notification for resource: {}", id.toUnqualifiedVersionless().getValue());
ourLog.debug("Found match: queueing rest-hook notification for resource: {}", id.toUnqualifiedVersionless().getValue());
ResourceDeliveryMessage deliveryMsg = new ResourceDeliveryMessage();
deliveryMsg.setPayload(getContext(), msg.getNewPayload(getContext()));

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/subscription/email/JavaMailEmailSender.java
View File

@ -20,7 +20,7 @@ package ca.uhn.fhir.jpa.subscription.email;
* #L%
*/
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.Constants;
import ca.uhn.fhir.rest.server.exceptions.InternalErrorException;
import org.apache.commons.lang3.StringUtils;

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/term/BaseHapiTerminologySvc.java
View File

@ -47,7 +47,7 @@ import ca.uhn.fhir.jpa.dao.DaoConfig;
import ca.uhn.fhir.jpa.dao.data.*;
import ca.uhn.fhir.jpa.entity.*;
import ca.uhn.fhir.jpa.entity.TermConceptParentChildLink.RelationshipTypeEnum;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.server.exceptions.InvalidRequestException;
import ca.uhn.fhir.rest.server.exceptions.UnprocessableEntityException;
import ca.uhn.fhir.util.ObjectUtil;

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/term/HapiTerminologySvcDstu3.java
View File

@ -7,7 +7,7 @@ import ca.uhn.fhir.jpa.entity.ResourceTable;
import ca.uhn.fhir.jpa.entity.TermCodeSystem;
import ca.uhn.fhir.jpa.entity.TermCodeSystemVersion;
import ca.uhn.fhir.jpa.entity.TermConcept;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.server.RequestDetails;
import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
import ca.uhn.fhir.rest.server.exceptions.InternalErrorException;

2
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/term/HapiTerminologySvcR4.java
View File

@ -7,7 +7,7 @@ import ca.uhn.fhir.jpa.entity.ResourceTable;
import ca.uhn.fhir.jpa.entity.TermCodeSystem;
import ca.uhn.fhir.jpa.entity.TermCodeSystemVersion;
import ca.uhn.fhir.jpa.entity.TermConcept;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.server.RequestDetails;
import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
import ca.uhn.fhir.rest.server.exceptions.InternalErrorException;

167
hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/util/StopWatch.java
View File

@ -1,13 +1,5 @@
package ca.uhn.fhir.jpa.util;
import com.google.common.annotations.VisibleForTesting;
import org.apache.commons.lang3.time.DateUtils;
import java.text.DecimalFormat;
import java.text.NumberFormat;
import java.util.Date;
import java.util.concurrent.TimeUnit;
/*
* #%L
* HAPI FHIR JPA Server
@ -28,159 +20,10 @@ import java.util.concurrent.TimeUnit;
* #L%
*/
public class StopWatch {
private static final NumberFormat DAY_FORMAT = new DecimalFormat("0.0");
private static final NumberFormat TEN_DAY_FORMAT = new DecimalFormat("0");
private static Long ourNowForUnitTest;
private long myStarted = now();
/**
* Constructor
/**
* @deprecated Use {@link ca.uhn.fhir.util.StopWatch} instead
*/
public StopWatch() {
super();
}
/**
* Constructor
*
* @param theStart The time to record as the start for this timer
*/
public StopWatch(Date theStart) {
myStarted = theStart.getTime();
}
public String formatThroughput(int theNumOperations, TimeUnit theUnit) {
double throughput = getThroughput(theNumOperations, theUnit);
return new DecimalFormat("0.0").format(throughput);
}
/**
* Given an amount of something completed so far, and a total amount, calculates how long it will take for something to complete
*
* @param theCompleteToDate The amount so far
* @param theTotal The total (must be higher than theCompleteToDate
* @return A formatted amount of time
*/
public String getEstimatedTimeRemaining(double theCompleteToDate, double theTotal) {
double completeSoFar = theCompleteToDate / theTotal;
double remaining;
if (completeSoFar > 0.5) {
remaining = (1.0 - completeSoFar);
} else {
remaining = (1.0 / completeSoFar);
}
double millis = getMillis();
long millisRemaining = (long) (millis * remaining);
return formatMillis(millisRemaining);
}
public long getMillis(Date theNow) {
return theNow.getTime() - myStarted;
}
public long getMillis() {
long now = now();
return now - myStarted;
}
public long getMillisAndRestart() {
long now = now();
long retVal = now - myStarted;
myStarted = now;
return retVal;
}
/**
* @param theNumOperations Ok for this to be 0, it will be treated as 1
*/
public int getMillisPerOperation(int theNumOperations) {
return (int) (((double) getMillis()) / Math.max(1.0, theNumOperations));
}
public Date getStartedDate() {
return new Date(myStarted);
}
public double getThroughput(int theNumOperations, TimeUnit theUnit) {
if (theNumOperations <= 0) {
return 0.0f;
}
long millisElapsed = Math.max(1, getMillis());
long periodMillis = theUnit.toMillis(1);
double numerator = theNumOperations;
double denominator = ((double) millisElapsed) / ((double) periodMillis);
return numerator / denominator;
}
public void restart() {
myStarted = now();
}
/**
* Formats value in the format [DD d ]HH:mm:ss.SSSS
*/
@Override
public String toString() {
return formatMillis(getMillis());
}
/**
* Append a right-aligned and zero-padded numeric value to a `StringBuilder`.
*/
static private void append(StringBuilder tgt, String pfx, int dgt, long val) {
tgt.append(pfx);
if (dgt > 1) {
int pad = (dgt - 1);
for (long xa = val; xa > 9 && pad > 0; xa /= 10) {
pad--;
}
for (int xa = 0; xa < pad; xa++) {
tgt.append('0');
}
}
tgt.append(val);
}
static public String formatMillis(long val) {
StringBuilder buf = new StringBuilder(20);
if (val >= DateUtils.MILLIS_PER_DAY) {
double days = (double) val / DateUtils.MILLIS_PER_DAY;
if (days >= 10) {
buf.append(TEN_DAY_FORMAT.format(days));
buf.append(" days");
} else if (days != 1.0f) {
buf.append(DAY_FORMAT.format(days));
buf.append(" days");
} else {
buf.append(DAY_FORMAT.format(days));
buf.append(" day");
}
} else {
append(buf, "", 2, ((val % DateUtils.MILLIS_PER_DAY) / DateUtils.MILLIS_PER_HOUR));
append(buf, ":", 2, ((val % DateUtils.MILLIS_PER_HOUR) / DateUtils.MILLIS_PER_MINUTE));
append(buf, ":", 2, ((val % DateUtils.MILLIS_PER_MINUTE) / DateUtils.MILLIS_PER_SECOND));
if (val <= DateUtils.MILLIS_PER_MINUTE) {
append(buf, ".", 3, (val % DateUtils.MILLIS_PER_SECOND));
}
}
return buf.toString();
}
private static long now() {
if (ourNowForUnitTest != null) {
return ourNowForUnitTest;
}
return System.currentTimeMillis();
}
@VisibleForTesting
static void setNowForUnitTestForUnitTest(Long theNowForUnitTest) {
ourNowForUnitTest = theNowForUnitTest;
}
@Deprecated
public class StopWatch extends ca.uhn.fhir.util.StopWatch {
// this just exists since existing code may depend on it
}

2
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/BaseJpaTest.java
View File

@ -6,7 +6,7 @@ import ca.uhn.fhir.jpa.provider.SystemProviderDstu2Test;
import ca.uhn.fhir.jpa.search.ISearchCoordinatorSvc;
import ca.uhn.fhir.jpa.sp.ISearchParamPresenceSvc;
import ca.uhn.fhir.jpa.term.VersionIndependentConcept;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.model.dstu2.resource.Bundle;
import ca.uhn.fhir.model.dstu2.resource.Bundle.Entry;
import ca.uhn.fhir.rest.api.server.IBundleProvider;

2
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/dstu3/FhirDaoConcurrencyDstu3Test.java
View File

@ -1,7 +1,7 @@
package ca.uhn.fhir.jpa.dao.dstu3;
import ca.uhn.fhir.jpa.dao.DaoConfig;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.server.IBundleProvider;
import ca.uhn.fhir.util.TestUtil;
import com.phloc.commons.compare.ReverseComparator;

2
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/dstu3/FhirResourceDaoDstu3SearchPageExpiryTest.java
View File

@ -6,7 +6,7 @@ import ca.uhn.fhir.jpa.dao.data.ISearchDao;
import ca.uhn.fhir.jpa.dao.r4.FhirResourceDaoR4SearchPageExpiryTest;
import ca.uhn.fhir.jpa.entity.Search;
import ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.server.IBundleProvider;
import ca.uhn.fhir.rest.param.StringParam;
import org.apache.commons.lang3.Validate;

2
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/dstu3/FhirResourceDaoDstu3ValidateTest.java
View File

@ -15,7 +15,7 @@ import org.hl7.fhir.instance.model.api.IBaseResource;
import org.hl7.fhir.instance.model.api.IIdType;
import org.junit.*;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.*;
import ca.uhn.fhir.rest.server.exceptions.*;
import ca.uhn.fhir.util.TestUtil;

2
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4SearchPageExpiryTest.java
View File

@ -5,7 +5,7 @@ import ca.uhn.fhir.jpa.dao.SearchParameterMap;
import ca.uhn.fhir.jpa.dao.data.ISearchDao;
import ca.uhn.fhir.jpa.entity.Search;
import ca.uhn.fhir.jpa.search.StaleSearchDeletingSvcImpl;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.server.IBundleProvider;
import ca.uhn.fhir.rest.param.StringParam;
import org.apache.commons.lang3.Validate;

2
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4ValidateTest.java
View File

@ -15,7 +15,7 @@ import org.hl7.fhir.instance.model.api.IBaseResource;
import org.hl7.fhir.instance.model.api.IIdType;
import org.junit.*;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.rest.api.*;
import ca.uhn.fhir.rest.server.exceptions.*;
import ca.uhn.fhir.util.TestUtil;

2
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderR4Test.java
View File

@ -5,7 +5,7 @@ import ca.uhn.fhir.jpa.dao.DaoConfig;
import ca.uhn.fhir.jpa.entity.ResourceHistoryTable;
import ca.uhn.fhir.jpa.entity.Search;
import ca.uhn.fhir.jpa.search.SearchCoordinatorSvcImpl;
import ca.uhn.fhir.jpa.util.StopWatch;
import ca.uhn.fhir.util.StopWatch;
import ca.uhn.fhir.model.api.TemporalPrecisionEnum;
import ca.uhn.fhir.model.primitive.InstantDt;
import ca.uhn.fhir.model.primitive.UriDt;

36
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/util/jsonpatch/JsonPatchTest.java
View File

@ -1,36 +0,0 @@
package ca.uhn.fhir.jpa.util.jsonpatch;
import static org.junit.Assert.*;
import org.hl7.fhir.dstu3.model.Patient;
import org.junit.AfterClass;
import org.junit.Test;
import ca.uhn.fhir.context.FhirContext;
import ca.uhn.fhir.util.TestUtil;
public class JsonPatchTest {
@AfterClass
public static void afterClassClearContext() {
TestUtil.clearAllStaticFieldsForUnitTest();
}
private static FhirContext ourCtx = FhirContext.forDstu3();
@Test
public void testPatchReplace() {
Patient p = new Patient();
p.setActive(true);
//@formatter:off
String patchBody = "[\n" +
" { \"op\":\"replace\", \"path\":\"/active\", \"value\":false }\n" +
"]";
//@formatter:on
Patient dest = JsonPatchUtils.apply(ourCtx, p, patchBody);
assertEquals(false, dest.getActive());
}
}

35
hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/util/xmlpatch/XmlPatchTest.java
View File

@ -1,35 +0,0 @@
package ca.uhn.fhir.jpa.util.xmlpatch;
import static org.junit.Assert.assertEquals;
import org.hl7.fhir.dstu3.model.Patient;
import org.junit.AfterClass;
import org.junit.Test;
import ca.uhn.fhir.context.FhirContext;
import ca.uhn.fhir.jpa.util.xmlpatch.XmlPatchUtils;
import ca.uhn.fhir.util.TestUtil;
public class XmlPatchTest {
@AfterClass
public static void afterClassClearContext() {
TestUtil.clearAllStaticFieldsForUnitTest();
}
private static FhirContext ourCtx = FhirContext.forDstu3();
@Test
public void testPatchReplace() {
Patient p = new Patient();
p.setActive(true);
//@formatter:off
String patchBody = "<?xml version=\"1.0\" encoding=\"UTF-8\"?><diff xmlns:fhir=\"http://hl7.org/fhir\"><replace sel=\"fhir:Patient/fhir:active/@value\">false</replace></diff>";
//@formatter:on
Patient dest = XmlPatchUtils.apply(ourCtx, p, patchBody);
assertEquals(false, dest.getActive());
}
}

103
hapi-fhir-structures-r4/src/test/java/ca/uhn/fhir/rest/client/CapturingInterceptorTest.java
View File

@ -5,29 +5,23 @@ import ca.uhn.fhir.rest.client.api.IHttpRequest;
import ca.uhn.fhir.rest.client.api.IHttpResponse;
import ca.uhn.fhir.rest.client.interceptor.CapturingInterceptor;
import ca.uhn.fhir.rest.server.exceptions.InternalErrorException;
import ca.uhn.fhir.util.StopWatch;
import org.apache.commons.io.IOUtils;
import org.apache.http.HttpRequest;
import org.apache.http.HttpResponse;
import org.apache.http.HttpStatus;
import org.apache.http.HttpVersion;
import org.apache.http.entity.BasicHttpEntity;
import org.apache.http.entity.InputStreamEntity;
import org.apache.http.entity.StringEntity;
import org.apache.http.message.BasicHttpRequest;
import org.apache.http.message.BasicHttpResponse;
import org.junit.After;
import org.junit.Rule;
import org.junit.Test;
import org.junit.rules.ExpectedException;
import org.mockito.Spy;
import java.io.IOException;
import java.nio.charset.Charset;
import static org.hamcrest.CoreMatchers.equalTo;
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertNull;
import static org.junit.Assert.assertThat;
import static org.junit.Assert.*;
import static org.mockito.Mockito.*;
@ -36,6 +30,25 @@ public class CapturingInterceptorTest {
@Rule
public ExpectedException thrown = ExpectedException.none();
@Test
public void testClear() {
IHttpRequest expectedRequest = mock(IHttpRequest.class);
IHttpResponse expectedResponse = mock(IHttpResponse.class);
Object response = mock(Object.class);
when(expectedResponse.getResponse()).thenReturn(response);
CapturingInterceptor interceptor = new CapturingInterceptor();
interceptor.interceptResponse(expectedResponse);
interceptor.interceptRequest(expectedRequest);
assertEquals(expectedRequest, interceptor.getLastRequest());
assertEquals(expectedResponse, interceptor.getLastResponse());
interceptor.clear();
assertNull(interceptor.getLastRequest());
assertNull(interceptor.getLastResponse());
}
@Test
public void testRequest() {
@ -60,24 +73,11 @@ public class CapturingInterceptorTest {
}
@Test
public void testResponseException() throws Exception {
IHttpResponse response = mock(IHttpResponse.class);
IOException expectedCause = new IOException();
doThrow(expectedCause).when(response).bufferEntity();
thrown.expect(InternalErrorException.class);
thrown.expectMessage("Unable to buffer the entity for capturing");
thrown.expectCause(equalTo(expectedCause));
CapturingInterceptor interceptor = new CapturingInterceptor();
interceptor.interceptResponse(response);
}
@Test
public void testResponseBufferApache() throws Exception{
public void testResponseBufferApache() throws Exception {
StopWatch responseStopWatch = new StopWatch();
HttpResponse response = new BasicHttpResponse(HttpVersion.HTTP_1_1, HttpStatus.SC_OK, "OK");
response.setEntity(new InputStreamEntity(IOUtils.toInputStream("Some content", Charset.defaultCharset())));
IHttpResponse expectedResponse = spy(new ApacheHttpResponse(response));
IHttpResponse expectedResponse = spy(new ApacheHttpResponse(response, responseStopWatch));
CapturingInterceptor interceptor = new CapturingInterceptor();
interceptor.interceptResponse(expectedResponse);
@ -91,24 +91,6 @@ public class CapturingInterceptorTest {
IOUtils.toString(actualResponse.createReader());
}
@Test
public void testResponseRepeatable() throws Exception{
HttpResponse response = new BasicHttpResponse(HttpVersion.HTTP_1_1, HttpStatus.SC_OK, "OK");
response.setEntity(new StringEntity("Some content"));
IHttpResponse expectedResponse = spy(new ApacheHttpResponse(response));
CapturingInterceptor interceptor = new CapturingInterceptor();
interceptor.interceptResponse(expectedResponse);
IHttpResponse actualResponse = interceptor.getLastResponse();
assertEquals(expectedResponse, actualResponse);
assertThat("Some content", equalTo(IOUtils.toString(actualResponse.createReader())));
verify(expectedResponse, times(0)).bufferEntity();
//A second call should not throw an exception (StringEntity is repeatable)
IOUtils.toString(actualResponse.createReader());
}
@Test
public void testResponseBufferOther() throws Exception {
Object response = mock(Object.class);
@ -125,23 +107,36 @@ public class CapturingInterceptorTest {
}
@Test
public void testClear(){
IHttpRequest expectedRequest = mock(IHttpRequest.class);
IHttpResponse expectedResponse = mock(IHttpResponse.class);
Object response = mock(Object.class);
when(expectedResponse.getResponse()).thenReturn(response);
public void testResponseException() throws Exception {
IHttpResponse response = mock(IHttpResponse.class);
IOException expectedCause = new IOException();
doThrow(expectedCause).when(response).bufferEntity();
thrown.expect(InternalErrorException.class);
thrown.expectMessage("Unable to buffer the entity for capturing");
thrown.expectCause(equalTo(expectedCause));
CapturingInterceptor interceptor = new CapturingInterceptor();
interceptor.interceptResponse(response);
}
@Test
public void testResponseRepeatable() throws Exception {
StopWatch responseStopWatch = new StopWatch();
HttpResponse response = new BasicHttpResponse(HttpVersion.HTTP_1_1, HttpStatus.SC_OK, "OK");
response.setEntity(new StringEntity("Some content"));
IHttpResponse expectedResponse = spy(new ApacheHttpResponse(response, responseStopWatch));
CapturingInterceptor interceptor = new CapturingInterceptor();
interceptor.interceptResponse(expectedResponse);
interceptor.interceptRequest(expectedRequest);
IHttpResponse actualResponse = interceptor.getLastResponse();
assertEquals(expectedRequest, interceptor.getLastRequest());
assertEquals(expectedResponse, interceptor.getLastResponse());
assertEquals(expectedResponse, actualResponse);
assertThat("Some content", equalTo(IOUtils.toString(actualResponse.createReader())));
verify(expectedResponse, times(0)).bufferEntity();
interceptor.clear();
assertNull(interceptor.getLastRequest());
assertNull(interceptor.getLastResponse());
//A second call should not throw an exception (StringEntity is repeatable)
IOUtils.toString(actualResponse.createReader());
}
}

6
hapi-fhir-structures-r4/src/test/java/ca/uhn/fhir/rest/client/LoggingInterceptorTest.java
View File

@ -66,7 +66,7 @@ public class LoggingInterceptorTest {
}
@Test
public void testLoggerNonVerbose() throws Exception {
public void testLoggerNonVerbose() {
System.out.println("Starting testLogger");
IGenericClient client = ourCtx.newRestfulGenericClient("http://localhost:" + ourPort);
ourCtx.getRestfulClientFactory().setServerValidationMode(ServerValidationModeEnum.NEVER);
@ -85,13 +85,13 @@ public class LoggingInterceptorTest {
System.out.flush();
return
formattedMessage.contains("Client request: GET http://localhost:" + ourPort + "/Patient/1 HTTP/1.1") ||
formattedMessage.contains("Client response: HTTP 200 OK (Patient/1/_history/1)");
formattedMessage.contains("Client response: HTTP 200 OK (Patient/1/_history/1) in ");
}
}));
}
@Test
public void testLoggerVerbose() throws Exception {
public void testLoggerVerbose() {
System.out.println("Starting testLogger");
IGenericClient client = ourCtx.newRestfulGenericClient("http://localhost:" + ourPort);
ourCtx.getRestfulClientFactory().setServerValidationMode(ServerValidationModeEnum.NEVER);

8
src/changes/changes.xml
View File

@ -156,7 +156,9 @@
</action>
<action type="remove">
A number of info level log lines have been reduced to debug level in the JPA server, in
order to reduce contention during heavy loads.
order to reduce contention during heavy loads and reduce the amount of noise
in log files overall. A typical server should now see far less logging coming
from HAPI, at least at the INFO level.
</action>
<action type="fix" issue="863">
JPA server now correctly indexes custom search parameters which
@ -194,6 +196,10 @@
could be output by the parser's encode methods. Thanks to
Frank Tao for supplying a test case!
</action>
<action type="add">
The client LoggingInterceptor now includes the number of
milliseconds spent performing each call that is logged.
</action>
</release>
<release version="3.2.0" date="2018-01-13">
<action type="add">