Excessive Hibernate warnings when processing conditional create and delete operations on referenced resources in a transaction bundle (#6477)

* Excessive Hibernate warnings when processing conditional create and delete operations on referenced resources in a transaction bundle - failing test

* Excessive Hibernate warnings when processing conditional create and delete operations on referenced resources in a transaction bundle - fix

* Excessive Hibernate warnings when processing conditional create and delete operations on referenced resources in a transaction bundle - changelog

hapi-fhir-docs/src/main/resources/ca/uhn/hapi/fhir/changelog/7_8_0/6475-fix-excessive-hibernate-warnings.yaml

@@ -0,0 +1,7 @@
+---
+type: fix
+issue: 6475
+jira: SMILE-8490
+title: "Previously, submitting a transaction bundle containing a conditional delete, a conditional create, and a 
+resource which relied on this conditional create as a reference would lead to excessive Hibernate warnings in the logs. 
+This has been fixed."

hapi-fhir-jpaserver-model/src/main/java/ca/uhn/fhir/jpa/model/entity/ResourceLink.java

@@ -31,6 +31,7 @@ import jakarta.persistence.Id;
 import jakarta.persistence.Index;
 import jakarta.persistence.JoinColumn;
 import jakarta.persistence.ManyToOne;
+import jakarta.persistence.PostLoad;
 import jakarta.persistence.Table;
 import jakarta.persistence.Temporal;
 import jakarta.persistence.TemporalType;
@@ -97,6 +98,9 @@ public class ResourceLink extends BaseResourceIndex {
 			foreignKey = @ForeignKey(name = "FK_RESLINK_TARGET"))
 	private ResourceTable myTargetResource;
 
+	@Transient
+	private ResourceTable myTransientTargetResource;
+
 	@Column(name = "TARGET_RESOURCE_ID", insertable = true, updatable = true, nullable = true)
 	@FullTextField
 	private Long myTargetResourcePid;
@@ -141,7 +145,7 @@ public class ResourceLink extends BaseResourceIndex {
 	}
 
 	public String getTargetResourceId() {
-		if (myTargetResourceId == null && myTargetResource != null) {
+		if (myTargetResourceId == null && getTargetResource() != null) {
 			myTargetResourceId = getTargetResource().getIdDt().getIdPart();
 		}
 		return myTargetResourceId;
@@ -184,11 +188,21 @@ public class ResourceLink extends BaseResourceIndex {
 		return b.isEquals();
 	}
 
+	/**
+	 * ResourceLink.myTargetResource field is immutable.Transient ResourceLink.myTransientTargetResource property
+	 * is used instead, allowing it to be updated via the ResourceLink#copyMutableValuesFrom method
+	 * when ResourceLink table row is reused.
+	 */
+	@PostLoad
+	public void postLoad() {
+		myTransientTargetResource = myTargetResource;
+	}
+
 	@Override
 	public <T extends BaseResourceIndex> void copyMutableValuesFrom(T theSource) {
 		ResourceLink source = (ResourceLink) theSource;
 		mySourcePath = source.getSourcePath();
-		myTargetResource = source.getTargetResource();
+		myTransientTargetResource = source.getTargetResource();
 		myTargetResourceId = source.getTargetResourceId();
 		myTargetResourcePid = source.getTargetResourcePid();
 		myTargetResourceType = source.getTargetResourceType();
@@ -331,7 +345,7 @@ public class ResourceLink extends BaseResourceIndex {
 	}
 
 	public ResourceTable getTargetResource() {
-		return myTargetResource;
+		return myTransientTargetResource;
 	}
 
 	/**
@@ -348,8 +362,8 @@ public class ResourceLink extends BaseResourceIndex {
 		retVal.myTargetResourceType = myTargetResourceType;
 		if (myTargetResourceId != null) {
 			retVal.myTargetResourceId = myTargetResourceId;
-		} else if (myTargetResource != null) {
+		} else if (getTargetResource() != null) {
-			retVal.myTargetResourceId = myTargetResource.getIdDt().getIdPart();
+			retVal.myTargetResourceId = getTargetResource().getIdDt().getIdPart();
 		}
 		retVal.myTargetResourceUrl = myTargetResourceUrl;
 		retVal.myTargetResourceVersion = myTargetResourceVersion;

hapi-fhir-jpaserver-test-r4/src/test/java/ca/uhn/fhir/jpa/dao/r4/FhirSystemDaoR4Test.java

@@ -39,7 +39,11 @@ import ca.uhn.fhir.rest.server.interceptor.auth.PolicyEnum;
 import ca.uhn.fhir.rest.server.interceptor.auth.RuleBuilder;
 import ca.uhn.fhir.util.BundleBuilder;
 import ca.uhn.fhir.util.ClasspathUtil;
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.Appender;
 import org.apache.commons.io.IOUtils;
+import org.hibernate.persister.entity.AbstractEntityPersister;
 import org.hl7.fhir.instance.model.api.IBaseResource;
 import org.hl7.fhir.instance.model.api.IIdType;
 import org.hl7.fhir.r4.model.AllergyIntolerance;
@@ -85,6 +89,9 @@ import org.junit.jupiter.api.Disabled;
 import org.junit.jupiter.api.Test;
 import org.junit.jupiter.params.ParameterizedTest;
 import org.junit.jupiter.params.provider.CsvSource;
+import org.mockito.ArgumentCaptor;
+import org.mockito.Mock;
+import org.slf4j.LoggerFactory;
 import org.springframework.dao.DataIntegrityViolationException;
 import org.springframework.transaction.TransactionDefinition;
 import org.springframework.transaction.TransactionStatus;
@@ -113,6 +120,8 @@ import static org.junit.jupiter.api.Assertions.fail;
 import static org.assertj.core.api.AssertionsForClassTypes.assertThatExceptionOfType;
 import static org.junit.jupiter.api.Assertions.assertEquals;
 import static org.junit.jupiter.api.Assertions.assertNotNull;
+import static org.mockito.Mockito.times;
+import static org.mockito.Mockito.verify;
 import static org.mockito.Mockito.when;
 
 public class FhirSystemDaoR4Test extends BaseJpaR4SystemTest {
@@ -120,6 +129,9 @@ public class FhirSystemDaoR4Test extends BaseJpaR4SystemTest {
 	private static final org.slf4j.Logger ourLog = org.slf4j.LoggerFactory.getLogger(FhirSystemDaoR4Test.class);
 	private static final String TEST_IDENTIFIER_SYSTEM = "http://some-system.com";
 
+	@Mock
+	private Appender<ILoggingEvent> myAppender;
+
 	@AfterEach
 	public void after() {
 		JpaStorageSettings defaults = new JpaStorageSettings();
@@ -2956,7 +2968,7 @@ public class FhirSystemDaoR4Test extends BaseJpaR4SystemTest {
 		 * these four operations in the reverse order and verifies
 		 * that they are invoked correctly.
 		 */
-		//@formatter:off
+		//@formatter:on
 
 		int pass = 0;
 		IdType patientPlaceholderId = IdType.newRandomUuid();
@@ -3023,22 +3035,38 @@ public class FhirSystemDaoR4Test extends BaseJpaR4SystemTest {
 
 	@Test
 	public void testTransactionOruBundle() throws IOException {
+		// setup
 		myStorageSettings.setAllowMultipleDelete(true);
+		Logger logger = (Logger) LoggerFactory.getLogger(AbstractEntityPersister.class);
+		logger.addAppender(myAppender);
 
-		String input = IOUtils.toString(getClass().getResourceAsStream("/r4/oruBundle.json"), StandardCharsets.UTF_8);
+		try {
+			String input = IOUtils.toString(getClass().getResourceAsStream("/r4/oruBundle.json"), StandardCharsets.UTF_8);
 
-		Bundle inputBundle;
+			Bundle inputBundle;
-		Bundle outputBundle;
+			Bundle outputBundle;
-		inputBundle = myFhirContext.newJsonParser().parseResource(Bundle.class, input);
-		outputBundle = mySystemDao.transaction(mySrd, inputBundle);
-		ourLog.debug(myFhirContext.newJsonParser().setPrettyPrint(true).encodeResourceToString(outputBundle));
 
-		inputBundle = myFhirContext.newJsonParser().parseResource(Bundle.class, input);
+			// execute transaction
-		outputBundle = mySystemDao.transaction(mySrd, inputBundle);
+			inputBundle = myFhirContext.newJsonParser().parseResource(Bundle.class, input);
-		ourLog.debug(myFhirContext.newJsonParser().setPrettyPrint(true).encodeResourceToString(outputBundle));
+			outputBundle = mySystemDao.transaction(mySrd, inputBundle);
+			ourLog.debug(myFhirContext.newJsonParser().setPrettyPrint(true).encodeResourceToString(outputBundle));
 
-		IBundleProvider allPatients = myPatientDao.search(new SearchParameterMap());
+			// execute same transaction again
-		assertEquals(1, allPatients.size().intValue());
+			inputBundle = myFhirContext.newJsonParser().parseResource(Bundle.class, input);
+			outputBundle = mySystemDao.transaction(mySrd, inputBundle);
+			ourLog.debug(myFhirContext.newJsonParser().setPrettyPrint(true).encodeResourceToString(outputBundle));
+
+			// validate
+			IBundleProvider allPatients = myPatientDao.search(new SearchParameterMap());
+			assertEquals(1, allPatients.size().intValue());
+
+			// validate that AbstractEntityPersister does not produce log messages
+			// see https://github.com/hapifhir/hapi-fhir/issues/6475 for details
+			ArgumentCaptor<ILoggingEvent> logCaptor = ArgumentCaptor.forClass(ILoggingEvent.class);
+			verify(myAppender, times(0)).doAppend(logCaptor.capture());
+		} finally {
+			logger.detachAppender(myAppender);
+		}
 	}
 
 	@Test