diff --git a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImpl.java b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImpl.java index 94493d87e9a..44ac751ae71 100644 --- a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImpl.java +++ b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImpl.java @@ -168,7 +168,7 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { verifySearchHasntFailedOrThrowInternalErrorException(search); if (search.getStatus() == SearchStatusEnum.FINISHED) { - ourLog.info("Search entity marked as finished"); + ourLog.info("Search entity marked as finished with {} results", search.getNumFound()); break; } if (search.getNumFound() >= theTo) { @@ -189,7 +189,8 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { search = newSearch.get(); String resourceType = search.getResourceType(); SearchParameterMap params = search.getSearchParameterMap(); - SearchContinuationTask task = new SearchContinuationTask(search, myDaoRegistry.getResourceDao(resourceType), params, resourceType); + IFhirResourceDao resourceDao = myDaoRegistry.getResourceDao(resourceType); + SearchContinuationTask task = new SearchContinuationTask(search, resourceDao, params, resourceType); myIdToSearchTask.put(search.getUuid(), task); myExecutor.submit(task); } @@ -228,10 +229,9 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { txTemplate.setPropagationBehavior(TransactionDefinition.PROPAGATION_REQUIRES_NEW); txTemplate.afterPropertiesSet(); return txTemplate.execute(t -> { - Optional searchOpt = mySearchDao.findById(theSearch.getId()); - Search search = searchOpt.orElseThrow(IllegalStateException::new); - if (search.getStatus() != SearchStatusEnum.PASSCMPLET) { - throw new IllegalStateException("Can't change to LOADING because state is " + search.getStatus()); + myEntityManager.refresh(theSearch); + if (theSearch.getStatus() != SearchStatusEnum.PASSCMPLET) { + throw new IllegalStateException("Can't change to LOADING because state is " + theSearch.getStatus()); } theSearch.setStatus(SearchStatusEnum.LOADING); Search newSearch = mySearchDao.save(theSearch); @@ -239,6 +239,7 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { }); } catch (Exception e) { ourLog.warn("Failed to activate search: {}", e.toString()); + ourLog.trace("Failed to activate search", e); return Optional.empty(); } } @@ -438,6 +439,11 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { myManagedTxManager = theTxManager; } + @VisibleForTesting + public void setDaoRegistryForUnitTest(DaoRegistry theDaoRegistry) { + myDaoRegistry = theDaoRegistry; + } + public abstract class BaseTask implements Callable { private final SearchParameterMap myParams; private final IDao myCallingDao; @@ -486,7 +492,7 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { } public List getResourcePids(int theFromIndex, int theToIndex) { - ourLog.info("Requesting search PIDs from {}-{}", theFromIndex, theToIndex); + ourLog.debug("Requesting search PIDs from {}-{}", theFromIndex, theToIndex); boolean keepWaiting; do { @@ -506,6 +512,7 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { * coordinator would then stop searching.SearchCoordinatorSvcImplTest */ List remainingResources = SearchCoordinatorSvcImpl.this.getResources(mySearch.getUuid(), mySyncedPids.size(), theToIndex); + ourLog.debug("Adding {} resources to the existing {} synced resource IDs", remainingResources.size(), mySyncedPids.size()); mySyncedPids.addAll(remainingResources); keepWaiting = false; break; @@ -834,6 +841,7 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { * Construct the SQL query we'll be sending to the database */ IResultIterator theResultIterator = sb.createQuery(myParams, mySearch.getUuid()); + assert (theResultIterator != null); /* * The following loop actually loads the PIDs of the resources @@ -895,6 +903,7 @@ public class SearchCoordinatorSvcImpl implements ISearchCoordinatorSvc { txTemplate.afterPropertiesSet(); txTemplate.execute(t -> { List previouslyAddedResourcePids = mySearchResultDao.findWithSearchUuid(getSearch()); + ourLog.debug("Have {} previously added IDs in search: {}", previouslyAddedResourcePids.size(), getSearch().getUuid()); setPreviouslyAddedResourcePids(previouslyAddedResourcePids); return null; }); diff --git a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImplTest.java b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImplTest.java index cf2ce1bf577..bdfa14b4ee2 100644 --- a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImplTest.java +++ b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/search/SearchCoordinatorSvcImplTest.java @@ -18,7 +18,10 @@ import ca.uhn.fhir.rest.server.exceptions.InternalErrorException; import ca.uhn.fhir.util.TestUtil; import com.google.common.collect.Lists; import org.hl7.fhir.instance.model.api.IBaseResource; -import org.junit.*; +import org.junit.After; +import org.junit.AfterClass; +import org.junit.Before; +import org.junit.Test; import org.junit.runner.RunWith; import org.mockito.ArgumentCaptor; import org.mockito.Captor; @@ -27,8 +30,11 @@ import org.mockito.Mockito; import org.mockito.invocation.InvocationOnMock; import org.mockito.junit.MockitoJUnitRunner; import org.mockito.stubbing.Answer; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.data.domain.Page; import org.springframework.data.domain.PageImpl; +import org.springframework.data.domain.PageRequest; import org.springframework.data.domain.Pageable; import org.springframework.transaction.PlatformTransactionManager; @@ -50,7 +56,7 @@ public class SearchCoordinatorSvcImplTest { @Captor ArgumentCaptor> mySearchResultIterCaptor; @Mock - private IDao myCallingDao; + private IFhirResourceDao myCallingDao; @Mock private EntityManager myEntityManager; private int myExpectedNumberOfSearchBuildersCreated = 2; @@ -67,6 +73,9 @@ public class SearchCoordinatorSvcImplTest { @Mock private PlatformTransactionManager myTxManager; private DaoConfig myDaoConfig; + private Search myCurrentSearch; + @Mock + private DaoRegistry myDaoRegistry; @After public void after() { @@ -75,6 +84,7 @@ public class SearchCoordinatorSvcImplTest { @Before public void before() { + myCurrentSearch = null; mySvc = new SearchCoordinatorSvcImpl(); mySvc.setEntityManagerForUnitTest(myEntityManager); @@ -83,6 +93,7 @@ public class SearchCoordinatorSvcImplTest { mySvc.setSearchDaoForUnitTest(mySearchDao); mySvc.setSearchDaoIncludeForUnitTest(mySearchIncludeDao); mySvc.setSearchDaoResultForUnitTest(mySearchResultDao); + mySvc.setDaoRegistryForUnitTest(myDaoRegistry); myDaoConfig = new DaoConfig(); mySvc.setDaoConfigForUnitTest(myDaoConfig); @@ -148,25 +159,43 @@ public class SearchCoordinatorSvcImplTest { } } - +private static final Logger ourLog = LoggerFactory.getLogger(SearchCoordinatorSvcImplTest.class); @Test - @Ignore // FIXME: activate public void testAsyncSearchLargeResultSetBigCountSameCoordinator() { SearchParameterMap params = new SearchParameterMap(); params.add("name", new StringParam("ANAME")); List pids = createPidSequence(10, 800); - IResultIterator iter = new SlowIterator(pids.iterator(), 1); - when(mySearchBuider.createQuery(Mockito.same(params), any(String.class))).thenReturn(iter); - + SlowIterator iter = new SlowIterator(pids.iterator(), 1); + when(mySearchBuider.createQuery(any(), any(String.class))).thenReturn(iter); doAnswer(loadPids()).when(mySearchBuider).loadResourcesByPid(any(List.class), any(List.class), any(Set.class), anyBoolean(), any(EntityManager.class), any(FhirContext.class), same(myCallingDao)); + when(mySearchResultDao.findWithSearchUuid(any(), any())).thenAnswer(t -> { + List returnedValues = iter.getReturnedValues(); + Pageable page = (Pageable) t.getArguments()[1]; + int offset = (int) page.getOffset(); + int end = (int)(page.getOffset() + page.getPageSize()); + end = Math.min(end, returnedValues.size()); + offset = Math.min(offset, returnedValues.size()); + ourLog.info("findWithSearchUuid {} - {} out of {} values", offset, end, returnedValues.size()); + return new PageImpl<>(returnedValues.subList(offset, end)); + }); + IBundleProvider result = mySvc.registerSearch(myCallingDao, params, "Patient", new CacheControlDirective()); assertNotNull(result.getUuid()); assertEquals(null, result.size()); List resources; + when(mySearchDao.save(any())).thenAnswer(t -> { + Search search = (Search) t.getArguments()[0]; + myCurrentSearch = search; + return search; + }); + when(mySearchDao.findByUuid(any())).thenAnswer(t -> myCurrentSearch); + IFhirResourceDao dao = myCallingDao; + when(myDaoRegistry.getResourceDao(any())).thenReturn(dao); + resources = result.getResources(0, 100000); assertEquals(790, resources.size()); assertEquals("10", resources.get(0).getIdElement().getValueAsString()); @@ -176,7 +205,7 @@ public class SearchCoordinatorSvcImplTest { verify(mySearchDao, atLeastOnce()).save(searchCaptor.capture()); verify(mySearchResultDao, atLeastOnce()).saveAll(mySearchResultIterCaptor.capture()); - List allResults = new ArrayList(); + List allResults = new ArrayList<>(); for (Iterable next : mySearchResultIterCaptor.getAllValues()) { allResults.addAll(Lists.newArrayList(next)); } @@ -184,6 +213,8 @@ public class SearchCoordinatorSvcImplTest { assertEquals(790, allResults.size()); assertEquals(10, allResults.get(0).getResourcePid().longValue()); assertEquals(799, allResults.get(789).getResourcePid().longValue()); + + myExpectedNumberOfSearchBuildersCreated = 3; } @Test @@ -215,7 +246,6 @@ public class SearchCoordinatorSvcImplTest { * page) within the same JVM will not use the original bundle provider */ @Test - @Ignore // FIXME: activate public void testAsyncSearchLargeResultSetSecondRequestSameCoordinator() { SearchParameterMap params = new SearchParameterMap(); params.add("name", new StringParam("ANAME")); @@ -223,7 +253,7 @@ public class SearchCoordinatorSvcImplTest { List pids = createPidSequence(10, 800); IResultIterator iter = new SlowIterator(pids.iterator(), 2); when(mySearchBuider.createQuery(Mockito.same(params), any(String.class))).thenReturn(iter); - + when(mySearchDao.save(any())).thenAnswer(t -> t.getArguments()[0]); doAnswer(loadPids()).when(mySearchBuider).loadResourcesByPid(any(List.class), any(List.class), any(Set.class), anyBoolean(), any(EntityManager.class), any(FhirContext.class), same(myCallingDao)); IBundleProvider result = mySvc.registerSearch(myCallingDao, params, "Patient", new CacheControlDirective()); @@ -256,12 +286,6 @@ public class SearchCoordinatorSvcImplTest { assertEquals("20", resources.get(0).getIdElement().getValueAsString()); assertEquals("29", resources.get(9).getIdElement().getValueAsString()); - provider = new PersistedJpaBundleProvider(result.getUuid(), myCallingDao); - resources = provider.getResources(20, 99999); - assertEquals(770, resources.size()); - assertEquals("30", resources.get(0).getIdElement().getValueAsString()); - assertEquals("799", resources.get(769).getIdElement().getValueAsString()); - myExpectedNumberOfSearchBuildersCreated = 4; } @@ -451,11 +475,19 @@ public class SearchCoordinatorSvcImplTest { } } + /** + * THIS CLASS IS FOR UNIT TESTS ONLY - It is delioberately inefficient + * and keeps things in memory. + *

+ * Don't use it in real code! + */ public static class SlowIterator extends BaseIterator implements IResultIterator { + private static final Logger ourLog = LoggerFactory.getLogger(SlowIterator.class); private final IResultIterator myResultIteratorWrap; private int myDelay; private Iterator myWrap; + private List myReturnedValues = new ArrayList<>(); public SlowIterator(Iterator theWrap, int theDelay) { myWrap = theWrap; @@ -469,9 +501,17 @@ public class SearchCoordinatorSvcImplTest { myDelay = theDelay; } + public List getReturnedValues() { + return myReturnedValues; + } + @Override public boolean hasNext() { - return myWrap.hasNext(); + boolean retVal = myWrap.hasNext(); + if (!retVal) { + ourLog.info("No more results remaining"); + } + return retVal; } @Override @@ -481,7 +521,9 @@ public class SearchCoordinatorSvcImplTest { } catch (InterruptedException e) { // ignore } - return myWrap.next(); + Long retVal = myWrap.next(); + myReturnedValues.add(retVal); + return retVal; } @Override