From a544a546ecbd0497bd79c9be5aa8eb381faf8e40 Mon Sep 17 00:00:00 2001 From: Tadgh Date: Sat, 17 Jun 2023 05:52:10 -0400 Subject: [PATCH] Raw sql revincludes (#5001) * start building tests * add test * Basic test and fix bug * remove tests, fix existing test * fix up tests * fix up tests --------- Co-authored-by: Ken Stevens --- ...evincludes-not-tracked-in-sql-tracing.yaml | 4 + .../jpa/search/builder/SearchBuilder.java | 30 +++-- .../r4/FhirResourceDaoR4QueryCountTest.java | 1 + .../dao/r4/SearchWithInterceptorR4Test.java | 1 + .../provider/r4/ResourceProviderR4Test.java | 2 - .../r4/ResourceProviderRevIncludeTest.java | 115 ++++++++++++++++++ 6 files changed, 143 insertions(+), 10 deletions(-) create mode 100644 hapi-fhir-docs/src/main/resources/ca/uhn/hapi/fhir/changelog/6_8_0/5000-revincludes-not-tracked-in-sql-tracing.yaml create mode 100644 hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderRevIncludeTest.java diff --git a/hapi-fhir-docs/src/main/resources/ca/uhn/hapi/fhir/changelog/6_8_0/5000-revincludes-not-tracked-in-sql-tracing.yaml b/hapi-fhir-docs/src/main/resources/ca/uhn/hapi/fhir/changelog/6_8_0/5000-revincludes-not-tracked-in-sql-tracing.yaml new file mode 100644 index 00000000000..f9c3d5276bb --- /dev/null +++ b/hapi-fhir-docs/src/main/resources/ca/uhn/hapi/fhir/changelog/6_8_0/5000-revincludes-not-tracked-in-sql-tracing.yaml @@ -0,0 +1,4 @@ +--- +type: fix +issue: 5000 +title: "Previously, the JPA_PERFTRACE_RAW_SQL was not firing for raw sql that occurred during a `revinclude` or `include`. This has been corrected." diff --git a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/builder/SearchBuilder.java b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/builder/SearchBuilder.java index 59c475d7f62..0dc6f9e6ea6 100644 --- a/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/builder/SearchBuilder.java +++ b/hapi-fhir-jpaserver-base/src/main/java/ca/uhn/fhir/jpa/search/builder/SearchBuilder.java @@ -67,7 +67,6 @@ import ca.uhn.fhir.jpa.searchparam.util.LastNParameterHelper; import ca.uhn.fhir.jpa.util.BaseIterator; import ca.uhn.fhir.jpa.util.CurrentThreadCaptureQueriesListener; import ca.uhn.fhir.jpa.util.QueryChunker; -import ca.uhn.fhir.jpa.util.QueryParameterUtils; import ca.uhn.fhir.jpa.util.SqlQueryList; import ca.uhn.fhir.model.api.IQueryParameterType; import ca.uhn.fhir.model.api.Include; @@ -1149,7 +1148,9 @@ public class SearchBuilder implements ISearchBuilder { String searchIdOrDescription = theParameters.getSearchIdOrDescription(); List desiredResourceTypes = theParameters.getDesiredResourceTypes(); boolean hasDesiredResourceTypes = desiredResourceTypes != null && !desiredResourceTypes.isEmpty(); - + if (CompositeInterceptorBroadcaster.hasHooks(Pointcut.JPA_PERFTRACE_RAW_SQL, myInterceptorBroadcaster, theParameters.getRequestDetails())) { + CurrentThreadCaptureQueriesListener.startCapturing(); + } if (matches.size() == 0) { return new HashSet<>(); } @@ -1395,6 +1396,11 @@ public class SearchBuilder implements ISearchBuilder { ourLog.info("Loaded {} {} in {} rounds and {} ms for search {}", allAdded.size(), reverseMode ? "_revincludes" : "_includes", roundCounts, w.getMillisAndRestart(), searchIdOrDescription); + + + if (CompositeInterceptorBroadcaster.hasHooks(Pointcut.JPA_PERFTRACE_RAW_SQL, myInterceptorBroadcaster, request)) { + callRawSqlHookWithCurrentThreadQueries(request); + } // Interceptor call: STORAGE_PREACCESS_RESOURCES // This can be used to remove results from the search result details before // the user has a chance to know that they were in the results @@ -1423,6 +1429,19 @@ public class SearchBuilder implements ISearchBuilder { return allAdded; } + /** + * Given a + * @param request + */ + private void callRawSqlHookWithCurrentThreadQueries(RequestDetails request) { + SqlQueryList capturedQueries = CurrentThreadCaptureQueriesListener.getCurrentQueueAndStopCapturing(); + HookParams params = new HookParams() + .add(RequestDetails.class, request) + .addIfMatchesType(ServletRequestDetails.class, request) + .add(SqlQueryList.class, capturedQueries); + CompositeInterceptorBroadcaster.doCallHooks(myInterceptorBroadcaster, request, Pointcut.JPA_PERFTRACE_RAW_SQL, params); + } + @Nullable private static Set computeTargetResourceTypes(Include nextInclude, RuntimeSearchParam param) { String targetResourceType = defaultString(nextInclude.getParamTargetType(), null); @@ -1865,12 +1884,7 @@ public class SearchBuilder implements ISearchBuilder { } finally { // search finished - fire hooks if (myHaveRawSqlHooks) { - SqlQueryList capturedQueries = CurrentThreadCaptureQueriesListener.getCurrentQueueAndStopCapturing(); - HookParams params = new HookParams() - .add(RequestDetails.class, myRequest) - .addIfMatchesType(ServletRequestDetails.class, myRequest) - .add(SqlQueryList.class, capturedQueries); - CompositeInterceptorBroadcaster.doCallHooks(myInterceptorBroadcaster, myRequest, Pointcut.JPA_PERFTRACE_RAW_SQL, params); + callRawSqlHookWithCurrentThreadQueries(myRequest); } } diff --git a/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4QueryCountTest.java b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4QueryCountTest.java index 6edc5425edd..573e755fc70 100644 --- a/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4QueryCountTest.java +++ b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirResourceDaoR4QueryCountTest.java @@ -258,6 +258,7 @@ public class FhirResourceDaoR4QueryCountTest extends BaseResourceProviderR4Test assertEquals(0, myCaptureQueriesListener.getDeleteQueriesForCurrentThread().size()); } + /** * See the class javadoc before changing the counts in this test! */ diff --git a/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/SearchWithInterceptorR4Test.java b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/SearchWithInterceptorR4Test.java index 09a0d4cafb5..a87cd0b0bba 100644 --- a/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/SearchWithInterceptorR4Test.java +++ b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/SearchWithInterceptorR4Test.java @@ -24,6 +24,7 @@ public class SearchWithInterceptorR4Test extends BaseJpaR4Test { private static final org.slf4j.Logger ourLog = org.slf4j.LoggerFactory.getLogger(SearchWithInterceptorR4Test.class); + @Test public void testRawSql_Search() { myStorageSettings.setAdvancedHSearchIndexing(false); diff --git a/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderR4Test.java b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderR4Test.java index 0ba95e8d4fa..ff6d9752175 100644 --- a/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderR4Test.java +++ b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderR4Test.java @@ -8,7 +8,6 @@ import ca.uhn.fhir.jpa.dao.data.ISearchDao; import ca.uhn.fhir.jpa.entity.Search; import ca.uhn.fhir.jpa.model.entity.NormalizedQuantitySearchLevel; import ca.uhn.fhir.jpa.model.entity.ResourceHistoryTable; -import ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamToken; import ca.uhn.fhir.jpa.model.entity.ResourceIndexedSearchParamUri; import ca.uhn.fhir.jpa.model.entity.StorageSettings; import ca.uhn.fhir.jpa.model.util.JpaConstants; @@ -279,7 +278,6 @@ public class ResourceProviderR4Test extends BaseResourceProviderR4Test { searchParameter.setXpathUsage(SearchParameter.XPathUsageType.NORMAL); searchParameter.setStatus(Enumerations.PublicationStatus.ACTIVE); myClient.create().resource(searchParameter).execute(); - mySearchParamRegistry.forceRefresh(); HttpGet get = new HttpGet(myServerBase + "/Procedure?focalAccess.a%20ne%20e"); diff --git a/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderRevIncludeTest.java b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderRevIncludeTest.java new file mode 100644 index 00000000000..e2ddcc436ef --- /dev/null +++ b/hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/provider/r4/ResourceProviderRevIncludeTest.java @@ -0,0 +1,115 @@ +package ca.uhn.fhir.jpa.provider.r4; + +import ca.uhn.fhir.interceptor.api.Hook; +import ca.uhn.fhir.interceptor.api.Pointcut; +import ca.uhn.fhir.jpa.provider.BaseResourceProviderR4Test; +import ca.uhn.fhir.jpa.util.SqlQuery; +import ca.uhn.fhir.jpa.util.SqlQueryList; +import ca.uhn.fhir.model.api.Include; +import ca.uhn.fhir.rest.api.CacheControlDirective; +import ca.uhn.fhir.rest.api.server.RequestDetails; +import ca.uhn.fhir.util.BundleUtil; +import org.hl7.fhir.instance.model.api.IBaseResource; +import org.hl7.fhir.instance.model.api.IIdType; +import org.hl7.fhir.r4.model.Bundle; +import org.hl7.fhir.r4.model.CareTeam; +import org.hl7.fhir.r4.model.Condition; +import org.hl7.fhir.r4.model.DetectedIssue; +import org.hl7.fhir.r4.model.Group; +import org.hl7.fhir.r4.model.Patient; +import org.hl7.fhir.r4.model.Reference; +import org.junit.jupiter.api.Test; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import org.springframework.test.context.jdbc.Sql; + +import java.util.ArrayList; +import java.util.List; +import java.util.regex.Pattern; + +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.hasSize; +import static org.hamcrest.Matchers.matchesPattern; +import static org.junit.jupiter.api.Assertions.assertEquals; + +public class ResourceProviderRevIncludeTest extends BaseResourceProviderR4Test { + + private static final Logger ourLog = LoggerFactory.getLogger(ResourceProviderRevIncludeTest.class); + + + + class SqlCapturingInterceptor { + SqlQueryList queryList = null; + @Hook(Pointcut.JPA_PERFTRACE_RAW_SQL) + public void trackRequest(RequestDetails theRequestDetails, SqlQueryList theQueryList) { + if (queryList == null) { + queryList = theQueryList; + } else { + queryList.addAll(theQueryList); + } + } + + public SqlQueryList getQueryList() { + return queryList; + } + } + + @Test + public void testRevincludeIterate() { + // /Patient?_id=123&_revinclude:iterate=CareTeam:subject:Group&_revinclude=Group:member:Patient&_revinclude=DetectedIssue:patient + + Patient p = new Patient(); + String methodName = "testRevincludeIterate"; + p.addName().setFamily(methodName); + IIdType pid = myClient.create().resource(p).execute().getId().toUnqualifiedVersionless(); + ourLog.info("Created patient: {}", pid.getValue()); // 1 + + Group g = new Group(); + g.addMember().setEntity(new Reference(pid)); + IIdType gid = myClient.create().resource(g).execute().getId().toUnqualifiedVersionless(); + ourLog.info("Created group: {}", gid.getValue()); // 2 + + CareTeam ct = new CareTeam(); + ct.getSubject().setReferenceElement(gid); + IIdType ctid = myClient.create().resource(ct).execute().getId().toUnqualifiedVersionless(); + ourLog.info("Created care team: {}", ctid.getValue()); // 3 + + List dids = new ArrayList<>(); + for (int i = 0; i < 100; ++i){ + DetectedIssue di = new DetectedIssue(); + di.getPatient().setReferenceElement(pid); + IIdType diid = myClient.create().resource(di).execute().getId().toUnqualifiedVersionless(); + ourLog.info("Created detected issue: {}", diid.getValue()); // 4...103 + dids.add(diid); + } + SqlCapturingInterceptor sqlCapturingInterceptor = new SqlCapturingInterceptor(); + myCaptureQueriesListener.clear(); + myInterceptorRegistry.registerInterceptor(sqlCapturingInterceptor); + Bundle bundle = myClient.search() + .forResource(Patient.class) + .count(200) + .where(Patient.RES_ID.exactly().codes(pid.getIdPart())) + .revInclude(new Include("CareTeam:subject:Group").setRecurse(true)) +// .revInclude(new Include("CareTeam:subject:Group")) + .revInclude(new Include("Group:member:Patient")) + .revInclude(DetectedIssue.INCLUDE_PATIENT) + .returnBundle(Bundle.class) + .execute(); + + List foundResources = BundleUtil.toListOfResources(myFhirContext, bundle); + Patient patient = (Patient) foundResources.get(0); + Group group = (Group) foundResources.get(1); + CareTeam careTeam = (CareTeam) foundResources.get(2); + DetectedIssue detectedIssue = (DetectedIssue) foundResources.get(3); + assertEquals(pid.getIdPart(), patient.getIdElement().getIdPart()); + assertEquals(gid.getIdPart(), group.getIdElement().getIdPart()); + assertEquals(ctid.getIdPart(), careTeam.getIdElement().getIdPart()); + assertEquals(methodName, patient.getName().get(0).getFamily()); + + //Ensure that the revincludes are included in the query list of the sql trace. + //TODO GGG/KHS reduce this to something less than 6 by smarter iterating and getting the resource types earlier when needed. + assertEquals(6, sqlCapturingInterceptor.getQueryList().size()); + myInterceptorRegistry.unregisterInterceptor(sqlCapturingInterceptor); + } + +}