HHH-18692 Hibernate attempts to close batched statements multiple times

hibernate-core/src/main/java/org/hibernate/engine/jdbc/batch/internal/BatchImpl.java

@@ -162,26 +162,11 @@ public void addToBatch(JdbcValueBindings jdbcValueBindings, TableInclusionChecke
 		if ( batchPosition == batchSizeToUse ) {
 			notifyObserversImplicitExecution();
 			performExecution();
-			batchPosition = 0;
-			batchExecuted = true;
 		}
 	}
 
 	protected void releaseStatements() {
-		statementGroup.forEachStatement( (tableName, statementDetails) -> {
-			if ( statementDetails.getStatement() == null ) {
-				BATCH_LOGGER.debugf(
-						"PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : %s",
-						statementDetails.getSqlString()
-				);
-			}
-			else {
-				clearBatch( statementDetails );
-			}
-		} );
-
 		statementGroup.release();
-		jdbcCoordinator.afterStatementExecution();
 	}
 
 	protected void clearBatch(PreparedStatementDetails statementDetails) {
@@ -299,8 +284,10 @@ protected void performExecution() {
 					}
 				}
 			} );
+			batchExecuted = true;
 		}
 		finally {
+			jdbcCoordinator.afterStatementExecution();
 			batchPosition = 0;
 		}
 	}

hibernate-core/src/main/java/org/hibernate/engine/jdbc/internal/JdbcCoordinatorImpl.java

@@ -167,8 +167,12 @@ public Batch getBatch(BatchKey key, Integer batchSize, Supplier<PreparedStatemen
 				return currentBatch;
 			}
 			else {
-				currentBatch.execute();
-				currentBatch.release();
+				try {
+					currentBatch.execute();
+				}
+				finally {
+					currentBatch.release();
+				}
 			}
 		}
 
@@ -194,7 +198,12 @@ public void executeBatch() {
 	public void conditionallyExecuteBatch(BatchKey key) {
 		if ( currentBatch != null && !currentBatch.getKey().equals( key ) ) {
 			JdbcBatchLogging.BATCH_LOGGER.debugf( "Conditionally executing batch - %s", currentBatch.getKey() );
-			currentBatch.execute();
+			try {
+				currentBatch.execute();
+			}
+			finally {
+				currentBatch.release();
+			}
 		}
 	}
 

hibernate-core/src/main/java/org/hibernate/engine/jdbc/mutation/group/PreparedStatementDetails.java

@@ -56,4 +56,8 @@ default boolean isCallable() {
 	}
 
 	void releaseStatement(SharedSessionContractImplementor session);
+
+	default boolean toRelease(){
+		return false;
+	}
 }

hibernate-core/src/main/java/org/hibernate/engine/jdbc/mutation/internal/AbstractPreparedStatementGroup.java

@@ -0,0 +1,58 @@
+/*
+ * SPDX-License-Identifier: LGPL-2.1-or-later
+ * Copyright Red Hat Inc. and Hibernate Authors
+ */
+package org.hibernate.engine.jdbc.mutation.internal;
+
+import org.hibernate.engine.jdbc.mutation.group.PreparedStatementDetails;
+import org.hibernate.engine.jdbc.mutation.group.PreparedStatementGroup;
+import org.hibernate.engine.spi.SharedSessionContractImplementor;
+
+import java.sql.PreparedStatement;
+import java.sql.SQLException;
+
+import static org.hibernate.engine.jdbc.batch.JdbcBatchLogging.BATCH_LOGGER;
+import static org.hibernate.engine.jdbc.batch.JdbcBatchLogging.BATCH_MESSAGE_LOGGER;
+
+public abstract class AbstractPreparedStatementGroup implements PreparedStatementGroup {
+	private final SharedSessionContractImplementor session;
+
+	public AbstractPreparedStatementGroup(SharedSessionContractImplementor session) {
+		this.session = session;
+	}
+
+	protected void clearBatch(PreparedStatementDetails statementDetails) {
+		final PreparedStatement statement = statementDetails.getStatement();
+		assert statement != null;
+
+		try {
+			// This code can be called after the connection is released
+			// and the statement is closed. If the statement is closed,
+			// then SQLException will be thrown when PreparedStatement#clearBatch
+			// is called.
+			// Ensure the statement is not closed before
+			// calling PreparedStatement#clearBatch.
+			if ( !statement.isClosed() ) {
+				statement.clearBatch();
+			}
+		}
+		catch ( SQLException e ) {
+			BATCH_MESSAGE_LOGGER.unableToReleaseBatchStatement();
+		}
+	}
+
+	protected void release(PreparedStatementDetails statementDetails) {
+		if ( statementDetails.toRelease() ) {
+			if ( statementDetails.getStatement() == null ) {
+				BATCH_LOGGER.debugf(
+						"PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : %s",
+						statementDetails.getSqlString()
+				);
+			}
+			else {
+				clearBatch( statementDetails );
+			}
+			statementDetails.releaseStatement( session );
+		}
+	}
+}

hibernate-core/src/main/java/org/hibernate/engine/jdbc/mutation/internal/PreparedStatementDetailsStandard.java

@@ -30,6 +30,8 @@ public class PreparedStatementDetailsStandard implements PreparedStatementDetail
 
 	private PreparedStatement statement;
 
+	private boolean toRelease;
+
 	public PreparedStatementDetailsStandard(
 			PreparableMutationOperation tableMutation,
 			Supplier<PreparedStatement> jdbcStatementCreator,
@@ -66,6 +68,7 @@ public void releaseStatement(SharedSessionContractImplementor session) {
 		if ( statement != null ) {
 			session.getJdbcCoordinator().getLogicalConnection().getResourceRegistry().release( statement );
 			statement = null;
+			toRelease = false;
 		}
 	}
 
@@ -82,6 +85,7 @@ public PreparedStatement getStatement() {
 	@Override
 	public PreparedStatement resolveStatement() {
 		if ( statement == null ) {
+			toRelease = true;
 			statement = jdbcStatementCreator.get();
 			try {
 				expectation.prepare( statement );
@@ -102,6 +106,11 @@ public Expectation getExpectation() {
 		return expectation;
 	}
 
+	@Override
+	public boolean toRelease() {
+		return toRelease;
+	}
+
 	@Override
 	public String toString() {
 		return "PreparedStatementDetails(" + sql + ")";

hibernate-core/src/main/java/org/hibernate/engine/jdbc/mutation/internal/PreparedStatementGroupSingleTable.java

@@ -8,7 +8,6 @@
 import java.util.function.Predicate;
 
 import org.hibernate.engine.jdbc.mutation.group.PreparedStatementDetails;
-import org.hibernate.engine.jdbc.mutation.group.PreparedStatementGroup;
 import org.hibernate.engine.spi.SharedSessionContractImplementor;
 import org.hibernate.generator.values.GeneratedValuesMutationDelegate;
 import org.hibernate.sql.model.PreparableMutationOperation;
@@ -20,9 +19,8 @@
  *
  * @author Steve Ebersole
  */
-public class PreparedStatementGroupSingleTable implements PreparedStatementGroup {
+public class PreparedStatementGroupSingleTable extends AbstractPreparedStatementGroup {
 	private final PreparableMutationOperation jdbcMutation;
-	private final SharedSessionContractImplementor session;
 
 	private final PreparedStatementDetails statementDetails;
 
@@ -36,9 +34,9 @@ public PreparedStatementGroupSingleTable(
 			PreparableMutationOperation jdbcMutation,
 			GeneratedValuesMutationDelegate delegate,
 			SharedSessionContractImplementor session) {
+		super(session);
 		this.jdbcMutation = jdbcMutation;
 		this.statementDetails = ModelMutationHelper.standardPreparation( jdbcMutation, delegate, session );
-		this.session = session;
 	}
 
 	protected TableMapping getMutatingTableDetails() {
@@ -89,7 +87,7 @@ public boolean hasMatching(Predicate<PreparedStatementDetails> filter) {
 	@Override
 	public void release() {
 		if ( statementDetails != null ) {
-			statementDetails.releaseStatement( session );
+			release( statementDetails );
 		}
 	}
 }

hibernate-core/src/main/java/org/hibernate/engine/jdbc/mutation/internal/PreparedStatementGroupStandard.java

@@ -16,7 +16,6 @@
 import java.util.function.Supplier;
 
 import org.hibernate.engine.jdbc.mutation.group.PreparedStatementDetails;
-import org.hibernate.engine.jdbc.mutation.group.PreparedStatementGroup;
 import org.hibernate.engine.jdbc.spi.JdbcCoordinator;
 import org.hibernate.engine.jdbc.spi.MutationStatementPreparer;
 import org.hibernate.engine.spi.SharedSessionContractImplementor;
@@ -32,11 +31,10 @@
  *
  * @author Steve Ebersole
  */
-public class PreparedStatementGroupStandard implements PreparedStatementGroup {
+public class PreparedStatementGroupStandard extends AbstractPreparedStatementGroup {
 	private final MutationType mutationType;
 	private final MutationTarget<?> mutationTarget;
 	private final List<PreparableMutationOperation> jdbcMutations;
-	private final SharedSessionContractImplementor session;
 
 	private final SortedMap<String, PreparedStatementDetails> statementMap;
 
@@ -47,11 +45,11 @@ public PreparedStatementGroupStandard(
 			GeneratedValuesMutationDelegate generatedValuesDelegate,
 			List<PreparableMutationOperation> jdbcMutations,
 			SharedSessionContractImplementor session) {
+		super( session );
 		this.mutationType = mutationType;
 		this.mutationTarget = mutationTarget;
 		this.jdbcMutations = jdbcMutations;
 
-		this.session = session;
 
 		this.statementMap = createStatementDetailsMap( jdbcMutations, mutationType, generatedValuesDelegate, session );
 	}
@@ -143,10 +141,11 @@ private static PreparedStatementDetails createPreparedStatementDetails(
 
 	@Override
 	public void release() {
-		statementMap.forEach( (tableName, statementDetails) -> statementDetails.releaseStatement( session ) );
+		statementMap.forEach( (tableName, statementDetails) -> {
+			release( statementDetails );
+		} );
 	}
 
-
 	private static SortedMap<String, PreparedStatementDetails> createStatementDetailsMap(
 			List<PreparableMutationOperation> jdbcMutations,
 			MutationType mutationType,

hibernate-core/src/test/java/org/hibernate/orm/test/batch/BatchReleaseStatementDebugMessageTest.java

@@ -0,0 +1,104 @@
+/*
+ * SPDX-License-Identifier: LGPL-2.1-or-later
+ * Copyright Red Hat Inc. and Hibernate Authors
+ */
+package org.hibernate.orm.test.batch;
+
+import jakarta.persistence.Entity;
+import jakarta.persistence.Id;
+import org.hibernate.cfg.AvailableSettings;
+import org.hibernate.engine.jdbc.batch.JdbcBatchLogging;
+import org.hibernate.testing.logger.LogInspectionHelper;
+import org.hibernate.testing.logger.LogListener;
+import org.hibernate.testing.logger.Triggerable;
+import org.hibernate.testing.orm.junit.DomainModel;
+import org.hibernate.testing.orm.junit.JiraKey;
+import org.hibernate.testing.orm.junit.ServiceRegistry;
+import org.hibernate.testing.orm.junit.SessionFactory;
+import org.hibernate.testing.orm.junit.SessionFactoryScope;
+import org.hibernate.testing.orm.junit.Setting;
+import org.jboss.logging.Logger;
+import org.junit.jupiter.api.BeforeAll;
+import org.junit.jupiter.api.Test;
+
+import java.util.List;
+import java.util.Locale;
+import java.util.concurrent.CopyOnWriteArrayList;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+@SessionFactory
+@DomainModel(annotatedClasses = {
+		BatchReleaseStatementDebugMessageTest.TestEntity.class
+})
+@ServiceRegistry(settings = @Setting(name = AvailableSettings.STATEMENT_BATCH_SIZE, value = "3"))
+@JiraKey("HHH-13615")
+public class BatchReleaseStatementDebugMessageTest {
+	private TriggerOnDebugMessageListener trigger;
+
+	@BeforeAll
+	public void setUp(SessionFactoryScope scope) {
+		trigger = new TriggerOnDebugMessageListener();
+		LogInspectionHelper.registerListener( trigger, JdbcBatchLogging.BATCH_LOGGER );
+	}
+
+	@Test
+	public void testLogIsNotGenerated(SessionFactoryScope scope) {
+
+		scope.inTransaction(
+				session -> {
+					session.persist( new TestEntity( 1L ) );
+				}
+		);
+		assertThat( trigger.wasTriggered() ).as( "Debug message was triggered" ).isFalse();
+
+	}
+
+	private static class TriggerOnDebugMessageListener implements LogListener, Triggerable {
+		private final List<String> triggerMessages = new CopyOnWriteArrayList<>();
+
+		@Override
+		public void loggedEvent(Logger.Level level, String renderedMessage, Throwable thrown) {
+			if ( renderedMessage.toLowerCase( Locale.ROOT )
+					.contains( "preparedstatementdetails did not contain preparedstatement" ) ) {
+				triggerMessages.add( renderedMessage );
+			}
+		}
+
+		@Override
+		public String triggerMessage() {
+			return !triggerMessages.isEmpty() ? triggerMessages.get( 0 ) : null;
+		}
+
+		@Override
+		public List<String> triggerMessages() {
+			return triggerMessages;
+		}
+
+		@Override
+		public boolean wasTriggered() {
+			return !triggerMessages.isEmpty();
+		}
+
+		@Override
+		public void reset() {
+			triggerMessages.clear();
+		}
+
+	}
+
+	@Entity(name = "TestEntity")
+	public static class TestEntity {
+		@Id
+		private Long id;
+
+		private String name;
+
+		public TestEntity() {
+		}
+
+		public TestEntity(Long id) {
+			this.id = id;
+		}
+	}
+}