diff --git a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/StaleSearchDeletingSvcImpl.java b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/StaleSearchDeletingSvcImpl.java index 623fd1e4831..4f22d98f8f9 100644 --- a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/StaleSearchDeletingSvcImpl.java +++ b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/StaleSearchDeletingSvcImpl.java @@ -32,7 +32,7 @@ import org.springframework.transaction.annotation.Transactional; import javax.annotation.PostConstruct; -import static ca.uhn.fhir.jpa.search.cache.DatabaseSearchCacheSvcImpl.DEFAULT_CUTOFF_SLACK; +import static ca.uhn.fhir.jpa.search.cache.DatabaseSearchCacheSvcImpl.SEARCH_CLEANUP_JOB_INTERVAL_MILLIS; /** * Deletes old searches @@ -62,7 +62,7 @@ public class StaleSearchDeletingSvcImpl implements IStaleSearchDeletingSvc { ScheduledJobDefinition jobDetail = new ScheduledJobDefinition(); jobDetail.setId(getClass().getName()); jobDetail.setJobClass(Job.class); - mySchedulerService.scheduleClusteredJob(DEFAULT_CUTOFF_SLACK, jobDetail); + mySchedulerService.scheduleClusteredJob(SEARCH_CLEANUP_JOB_INTERVAL_MILLIS, jobDetail); } public static class Job implements HapiJob { diff --git a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/cache/DatabaseSearchCacheSvcImpl.java b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/cache/DatabaseSearchCacheSvcImpl.java index ed699f817a0..dd319a635b1 100644 --- a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/cache/DatabaseSearchCacheSvcImpl.java +++ b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/cache/DatabaseSearchCacheSvcImpl.java @@ -55,7 +55,7 @@ public class DatabaseSearchCacheSvcImpl implements ISearchCacheSvc { */ public static final int DEFAULT_MAX_RESULTS_TO_DELETE_IN_ONE_STMT = 500; public static final int DEFAULT_MAX_RESULTS_TO_DELETE_IN_ONE_PAS = 20000; - public static final long DEFAULT_CUTOFF_SLACK = 10 * DateUtils.MILLIS_PER_SECOND; + public static final long SEARCH_CLEANUP_JOB_INTERVAL_MILLIS = 10 * DateUtils.MILLIS_PER_SECOND; private static final Logger ourLog = LoggerFactory.getLogger(DatabaseSearchCacheSvcImpl.class); private static int ourMaximumResultsToDeleteInOneStatement = DEFAULT_MAX_RESULTS_TO_DELETE_IN_ONE_STMT; private static int ourMaximumResultsToDeleteInOnePass = DEFAULT_MAX_RESULTS_TO_DELETE_IN_ONE_PAS; @@ -65,7 +65,7 @@ public class DatabaseSearchCacheSvcImpl implements ISearchCacheSvc { * is being reused (because a new client request came in with the same params) right before * the result is to be deleted */ - private long myCutoffSlack = DEFAULT_CUTOFF_SLACK; + private long myCutoffSlack = SEARCH_CLEANUP_JOB_INTERVAL_MILLIS; @Autowired private ISearchDao mySearchDao; @@ -163,7 +163,8 @@ public class DatabaseSearchCacheSvcImpl implements ISearchCacheSvc { ourLog.info("Searching for searches which are before {} - now is {}", new InstantType(cutoff), new InstantType(new Date(now()))); } - ourLog.debug("Searching for searches which are before {}", cutoff); + // FIXME KHS + ourLog.info("Searching for searches which are before {}", cutoff); TransactionTemplate tt = new TransactionTemplate(myTxManager); final Slice toDelete = tt.execute(theStatus -> @@ -172,7 +173,9 @@ public class DatabaseSearchCacheSvcImpl implements ISearchCacheSvc { assert toDelete != null; for (final Long nextSearchToDelete : toDelete) { - ourLog.debug("Deleting search with PID {}", nextSearchToDelete); + // FIXME KHS + ourLog.info("Deleting search with PID {}", nextSearchToDelete); + // FIXME KHS do this outside of loop. Make a "deleteWhereCreatedBefore" tt.execute(t -> { mySearchDao.updateDeleted(nextSearchToDelete, true); return null; @@ -186,9 +189,12 @@ public class DatabaseSearchCacheSvcImpl implements ISearchCacheSvc { int count = toDelete.getContent().size(); if (count > 0) { - if (ourLog.isDebugEnabled() || "true".equalsIgnoreCase(System.getProperty("test"))) { + // FIXME KHS +// if (ourLog.isDebugEnabled() || "true".equalsIgnoreCase(System.getProperty("test"))) { + if ( "true".equalsIgnoreCase(System.getProperty("test"))) { Long total = tt.execute(t -> mySearchDao.count()); - ourLog.debug("Deleted {} searches, {} remaining", count, total); + // FIXME KHS + ourLog.info("Deleted {} searches, {} remaining", count, total); } } } diff --git a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/BaseJpaR4Test.java b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/BaseJpaR4Test.java index 7dfffc7dfb9..a3f8a136228 100644 --- a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/BaseJpaR4Test.java +++ b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/BaseJpaR4Test.java @@ -64,7 +64,6 @@ import org.springframework.test.context.ContextConfiguration; import org.springframework.test.context.junit4.SpringJUnit4ClassRunner; import org.springframework.test.util.AopTestUtils; import org.springframework.transaction.PlatformTransactionManager; -import org.springframework.transaction.annotation.Transactional; import javax.persistence.EntityManager; import java.io.IOException; @@ -409,7 +408,6 @@ public abstract class BaseJpaR4Test extends BaseJpaTest { } @Before - @Transactional() public void beforePurgeDatabase() { purgeDatabase(myDaoConfig, mySystemDao, myResourceReindexingSvc, mySearchCoordinatorSvc, mySearchParamRegistry, myBulkDataExportSvc); } diff --git a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4SearchPageExpiryTest.java b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4SearchPageExpiryTest.java index e08affabf86..c81ca66f935 100644 --- a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4SearchPageExpiryTest.java +++ b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4SearchPageExpiryTest.java @@ -32,7 +32,7 @@ import javax.annotation.Nullable; import java.util.Date; import java.util.concurrent.atomic.AtomicLong; -import static ca.uhn.fhir.jpa.search.cache.DatabaseSearchCacheSvcImpl.DEFAULT_CUTOFF_SLACK; +import static ca.uhn.fhir.jpa.search.cache.DatabaseSearchCacheSvcImpl.SEARCH_CLEANUP_JOB_INTERVAL_MILLIS; import static org.awaitility.Awaitility.await; import static org.hamcrest.Matchers.containsInAnyOrder; import static org.junit.Assert.*; @@ -47,7 +47,7 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { @After() public void after() { DatabaseSearchCacheSvcImpl staleSearchDeletingSvc = AopTestUtils.getTargetObject(mySearchCacheSvc); - staleSearchDeletingSvc.setCutoffSlackForUnitTest(DEFAULT_CUTOFF_SLACK); + staleSearchDeletingSvc.setCutoffSlackForUnitTest(SEARCH_CLEANUP_JOB_INTERVAL_MILLIS); DatabaseSearchCacheSvcImpl.setNowForUnitTests(null); } @@ -81,8 +81,11 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } Thread.sleep(10); - myDaoConfig.setExpireSearchResultsAfterMillis(1000L); - myDaoConfig.setReuseCachedSearchResultsForMillis(500L); + long reuseCachedSearchResultsForMillis = 500L; + myDaoConfig.setReuseCachedSearchResultsForMillis(reuseCachedSearchResultsForMillis); + long millisBetweenReuseAndExpire = 800L; + long expireSearchResultsAfterMillis = 1000L; + myDaoConfig.setExpireSearchResultsAfterMillis(expireSearchResultsAfterMillis); long start = System.currentTimeMillis(); DatabaseSearchCacheSvcImpl.setNowForUnitTests(start); @@ -107,9 +110,9 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } assertEquals(searchUuid1, searchUuid2); - TestUtil.sleepAtLeast(501); + TestUtil.sleepAtLeast(reuseCachedSearchResultsForMillis + 1); - // We're now past 500ms so we shouldn't reuse the search + // We're now past reuseCachedSearchResultsForMillis so we shouldn't reuse the search final String searchUuid3; { @@ -124,35 +127,36 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { // Search just got used so it shouldn't be deleted - DatabaseSearchCacheSvcImpl.setNowForUnitTests(start + 500); + DatabaseSearchCacheSvcImpl.setNowForUnitTests(start + reuseCachedSearchResultsForMillis); + final AtomicLong search1timestamp = new AtomicLong(); + final AtomicLong search2timestamp = new AtomicLong(); final AtomicLong search3timestamp = new AtomicLong(); newTxTemplate().execute(new TransactionCallbackWithoutResult() { @Override protected void doInTransactionWithoutResult(TransactionStatus theArg0) { - Search search3 = mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3).orElseThrow(()->new InternalErrorException("Search doesn't exist")); - assertNotNull(search3); + Search search1 = mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid1).orElseThrow(()->new InternalErrorException("Search doesn't exist")); + assertNotNull(search1); + search1timestamp.set(search1.getCreated().getTime()); Search search2 = mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid2).orElseThrow(()->new InternalErrorException("Search doesn't exist")); assertNotNull(search2); - search3timestamp.set(search2.getCreated().getTime()); + search2timestamp.set(search2.getCreated().getTime()); + Search search3 = mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3).orElseThrow(()->new InternalErrorException("Search doesn't exist")); + assertNotNull(search3); + search3timestamp.set(search3.getCreated().getTime()); } }); - DatabaseSearchCacheSvcImpl.setNowForUnitTests(search3timestamp.get() + 800); + DatabaseSearchCacheSvcImpl.setNowForUnitTests(search1timestamp.get() + millisBetweenReuseAndExpire); myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); newTxTemplate().execute(new TransactionCallbackWithoutResult() { @Override protected void doInTransactionWithoutResult(TransactionStatus theArg0) { - assertNotNull(mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3)); - } - }); - newTxTemplate().execute(new TransactionCallbackWithoutResult() { - @Override - protected void doInTransactionWithoutResult(TransactionStatus theArg0) { - assertNotNull(mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid1)); + assertTrue(mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3).isPresent()); + assertTrue(mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid1).isPresent()); } }); - DatabaseSearchCacheSvcImpl.setNowForUnitTests(search3timestamp.get() + 1100); + DatabaseSearchCacheSvcImpl.setNowForUnitTests(search1timestamp.get() + reuseCachedSearchResultsForMillis + expireSearchResultsAfterMillis + 1); myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); newTxTemplate().execute(new TransactionCallbackWithoutResult() { @@ -163,14 +167,12 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } }); - DatabaseSearchCacheSvcImpl.setNowForUnitTests(search3timestamp.get() + 2100); + DatabaseSearchCacheSvcImpl.setNowForUnitTests(search3timestamp.get() + reuseCachedSearchResultsForMillis + expireSearchResultsAfterMillis + 1); myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); await().until(()-> newTxTemplate().execute(t -> !mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid1).isPresent())); await().until(()-> newTxTemplate().execute(t -> !mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3).isPresent())); - - } @Test @@ -197,7 +199,6 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { params.add(Patient.SP_FAMILY, new StringParam("EXPIRE")); final IBundleProvider bundleProvider = myPatientDao.search(params); assertThat(toUnqualifiedVersionlessIds(bundleProvider), containsInAnyOrder(pid1, pid2)); - assertThat(toUnqualifiedVersionlessIds(bundleProvider), containsInAnyOrder(pid1, pid2)); waitForSearchToSave(bundleProvider.getUuid()); final AtomicLong start = new AtomicLong(); @@ -213,9 +214,11 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } }); - myDaoConfig.setExpireSearchResultsAfterMillis(500); - myDaoConfig.setReuseCachedSearchResultsForMillis(500L); - DatabaseSearchCacheSvcImpl.setNowForUnitTests(start.get() + 499); + int expireSearchResultsAfterMillis = 700; + myDaoConfig.setExpireSearchResultsAfterMillis(expireSearchResultsAfterMillis); + long reuseCachedSearchResultsForMillis = 400L; + myDaoConfig.setReuseCachedSearchResultsForMillis(reuseCachedSearchResultsForMillis); + DatabaseSearchCacheSvcImpl.setNowForUnitTests(start.get() + expireSearchResultsAfterMillis - 1); myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); txTemplate.execute(new TransactionCallbackWithoutResult() { @Override @@ -224,7 +227,7 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } }); - DatabaseSearchCacheSvcImpl.setNowForUnitTests(start.get() + 600); + DatabaseSearchCacheSvcImpl.setNowForUnitTests(start.get() + expireSearchResultsAfterMillis + reuseCachedSearchResultsForMillis + 1); myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); txTemplate.execute(new TransactionCallbackWithoutResult() { @Override @@ -251,8 +254,12 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } Thread.sleep(10); - myDaoConfig.setExpireSearchResultsAfterMillis(1000L); - myDaoConfig.setReuseCachedSearchResultsForMillis(500L); + long expireSearchResultsAfterMillis = 1000L; + myDaoConfig.setExpireSearchResultsAfterMillis(expireSearchResultsAfterMillis); + + long reuseCachedSearchResultsForMillis = 500L; + myDaoConfig.setReuseCachedSearchResultsForMillis(reuseCachedSearchResultsForMillis); + long start = System.currentTimeMillis(); final String searchUuid1; @@ -278,9 +285,10 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } assertEquals(searchUuid1, searchUuid2); - TestUtil.sleepAtLeast(501); + TestUtil.sleepAtLeast(reuseCachedSearchResultsForMillis + 1); + myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); - // We're now past 500ms so we shouldn't reuse the search + // We're now past reuseCachedSearchResultsForMillis so we shouldn't reuse the search final String searchUuid3; { @@ -293,37 +301,35 @@ public class FhirResourceDaoR4SearchPageExpiryTest extends BaseJpaR4Test { } assertNotEquals(searchUuid1, searchUuid3); - // Search just got used so it shouldn't be deleted + waitForSearchToSave(searchUuid3); + + // Search hasn't expired yet so it shouldn't be deleted myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); + final AtomicLong search1timestamp = new AtomicLong(); final AtomicLong search3timestamp = new AtomicLong(); newTxTemplate().execute(new TransactionCallbackWithoutResult() { @Override protected void doInTransactionWithoutResult(TransactionStatus theArg0) { + Search search1 = mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid1).orElseThrow(()->new InternalErrorException("Search doesn't exist")); Search search3 = mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3).orElseThrow(()->new InternalErrorException("Search doesn't exist")); assertNotNull(search3); + search1timestamp.set(search1.getCreated().getTime()); search3timestamp.set(search3.getCreated().getTime()); } }); - DatabaseSearchCacheSvcImpl.setNowForUnitTests(search3timestamp.get() + 800); - + DatabaseSearchCacheSvcImpl.setNowForUnitTests(search1timestamp.get() + expireSearchResultsAfterMillis + reuseCachedSearchResultsForMillis + 1); myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); - newTxTemplate().execute(new TransactionCallbackWithoutResult() { - @Override - protected void doInTransactionWithoutResult(TransactionStatus theArg0) { - assertNotNull(mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3)); - } - }); newTxTemplate().execute(new TransactionCallbackWithoutResult() { @Override protected void doInTransactionWithoutResult(TransactionStatus theArg0) { assertFalse(mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid1).isPresent()); + assertTrue(mySearchEntityDao.findByUuidAndFetchIncludes(searchUuid3).isPresent()); } }); - DatabaseSearchCacheSvcImpl.setNowForUnitTests(search3timestamp.get() + 2100); - + DatabaseSearchCacheSvcImpl.setNowForUnitTests(search3timestamp.get() + expireSearchResultsAfterMillis + reuseCachedSearchResultsForMillis + 1); myStaleSearchDeletingSvc.pollForStaleSearchesAndDeleteThem(); newTxTemplate().execute(new TransactionCallbackWithoutResult() { @Override diff --git a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/provider/r4/StaleSearchDeletingSvcR4Test.java b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/provider/r4/StaleSearchDeletingSvcR4Test.java index 6ed219e0f9e..c66c824022c 100644 --- a/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/provider/r4/StaleSearchDeletingSvcR4Test.java +++ b/hapi-fhir-jpaserver-base/src/test/java/ca/uhn/fhir/jpa/provider/r4/StaleSearchDeletingSvcR4Test.java @@ -47,7 +47,7 @@ public class StaleSearchDeletingSvcR4Test extends BaseResourceProviderR4Test { public void after() throws Exception { super.after(); DatabaseSearchCacheSvcImpl staleSearchDeletingSvc = AopTestUtils.getTargetObject(mySearchCacheSvc); - staleSearchDeletingSvc.setCutoffSlackForUnitTest(DatabaseSearchCacheSvcImpl.DEFAULT_CUTOFF_SLACK); + staleSearchDeletingSvc.setCutoffSlackForUnitTest(DatabaseSearchCacheSvcImpl.SEARCH_CLEANUP_JOB_INTERVAL_MILLIS); DatabaseSearchCacheSvcImpl.setMaximumResultsToDeleteForUnitTest(DatabaseSearchCacheSvcImpl.DEFAULT_MAX_RESULTS_TO_DELETE_IN_ONE_STMT); DatabaseSearchCacheSvcImpl.setMaximumResultsToDeleteInOnePassForUnitTest(DatabaseSearchCacheSvcImpl.DEFAULT_MAX_RESULTS_TO_DELETE_IN_ONE_PAS); }