HHH-13741 - LOG_SLOW_QUERY parameter doesn't always log SQL

hibernate-core/src/main/java/org/hibernate/dialect/lock/PessimisticReadSelectLockingStrategy.java

@@ -72,7 +72,7 @@ public class PessimisticReadSelectLockingStrategy extends AbstractSelectLockingS
 						);
 					}
 
-					final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st );
+					final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st, sql );
 					if ( !rs.next() ) {
 						final StatisticsImplementor statistics = factory.getStatistics();
 						if ( statistics.isStatisticsEnabled() ) {

hibernate-core/src/main/java/org/hibernate/dialect/lock/PessimisticWriteSelectLockingStrategy.java

@@ -71,7 +71,7 @@ public class PessimisticWriteSelectLockingStrategy extends AbstractSelectLocking
 						);
 					}
 
-					final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st );
+					final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st, sql );
 					try {
 						if ( !rs.next() ) {
 							final StatisticsImplementor statistics = factory.getStatistics();

hibernate-core/src/main/java/org/hibernate/dialect/lock/SelectLockingStrategy.java

@@ -69,7 +69,7 @@ public class SelectLockingStrategy extends AbstractSelectLockingStrategy {
 					);
 				}
 
-				final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st );
+				final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st, sql );
 				try {
 					if ( !rs.next() ) {
 						final StatisticsImplementor statistics = factory.getStatistics();

hibernate-core/src/main/java/org/hibernate/engine/jdbc/spi/ResultSetReturn.java

@@ -22,7 +22,6 @@ import java.sql.Statement;
  *
  * @see JdbcCoordinator#getResultSetReturn()
  */
-//TODO: This could eventually utilize the new Return interface. It would be great to have a common API.
 public interface ResultSetReturn {
 
 	/**
@@ -34,7 +33,10 @@ public interface ResultSetReturn {
 	 * @param statement The {@link PreparedStatement} from which to extract the {@link ResultSet}
 	 *
 	 * @return The extracted ResultSet
+	 *
+	 * @deprecated Use {@link #extract(PreparedStatement, String)} instead
 	 */
+	@Deprecated(forRemoval = true)
 	ResultSet extract(PreparedStatement statement);
 
 	/**
@@ -57,7 +59,10 @@ public interface ResultSetReturn {
 	 * @param callableStatement The {@link CallableStatement} from which to extract the {@link ResultSet}
 	 *
 	 * @return The extracted {@link ResultSet}
+	 *
+	 * @deprecated Use {@link #extract(PreparedStatement, String)} instead
 	 */
+	@Deprecated(forRemoval = true)
 	ResultSet extract(CallableStatement callableStatement);
 	
 	/**
@@ -77,7 +82,10 @@ public interface ResultSetReturn {
 	 * @param statement The {@link PreparedStatement} to execute
 	 *
 	 * @return The extracted {@link ResultSet}, or {@code null}
+	 *
+	 * @deprecated Use {@link #execute(PreparedStatement, String)} instead
 	 */
+	@Deprecated(forRemoval = true)
 	ResultSet execute(PreparedStatement statement);
 
 	/**
@@ -108,7 +116,10 @@ public interface ResultSetReturn {
 	 * @param statement The {@link PreparedStatement} to execute
 	 *
 	 * @return The {@link PreparedStatement#executeUpdate()} result
+	 *
+	 * @deprecated Use {@link #executeUpdate(PreparedStatement, String)} instead
 	 */
+	@Deprecated(forRemoval = true)
 	int executeUpdate(PreparedStatement statement);
 
 	/**

hibernate-core/src/main/java/org/hibernate/id/GUIDGenerator.java

@@ -43,7 +43,7 @@ public class GUIDGenerator implements IdentifierGenerator, StandardGenerator {
 		try {
 			final PreparedStatement st = session.getJdbcCoordinator().getStatementPreparer().prepareStatement( sql );
 			try {
-				final ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st );
+				final ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st, sql );
 				try {
 					if ( !rs.next() ) {
 						throw new HibernateException( "The database returned no GUID identity value" );

hibernate-core/src/main/java/org/hibernate/id/IncrementGenerator.java

@@ -152,7 +152,7 @@ public class IncrementGenerator implements IdentifierGenerator, StandardGenerato
 		try {
 			PreparedStatement st = session.getJdbcCoordinator().getStatementPreparer().prepareStatement( sql );
 			try {
-				ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st );
+				ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st, sql );
 				try {
 					if ( rs.next() ) {
 						previousValueHolder.initialize( rs, 0L ).increment();

hibernate-core/src/main/java/org/hibernate/id/enhanced/SequenceStructure.java

@@ -99,7 +99,7 @@ public class SequenceStructure implements DatabaseStructure {
 				try {
 					final PreparedStatement st = session.getJdbcCoordinator().getStatementPreparer().prepareStatement( sql );
 					try {
-						final ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st );
+						final ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st, sql );
 						try {
 							rs.next();
 							final IntegralDataTypeHolder value = IdentifierGeneratorHelper.getIntegralDataTypeHolder( numberType );

hibernate-core/src/main/java/org/hibernate/id/insert/AbstractSelectingDelegate.java

@@ -82,7 +82,7 @@ public abstract class AbstractSelectingDelegate implements InsertGeneratedIdenti
 		try {
 			bindParameters( entity, idSelect, session );
 
-			final ResultSet resultSet = session.getJdbcCoordinator().getResultSetReturn().extract( idSelect );
+			final ResultSet resultSet = session.getJdbcCoordinator().getResultSetReturn().extract( idSelect, idSelectSql );
 			try {
 				return extractGeneratedValue( resultSet, session );
 			}
@@ -138,7 +138,7 @@ public abstract class AbstractSelectingDelegate implements InsertGeneratedIdenti
 			PreparedStatement idSelect = statementPreparer.prepareStatement( selectSQL, false );
 			try {
 				bindParameters( binder.getEntity(), idSelect, session );
-				ResultSet resultSet = jdbcCoordinator.getResultSetReturn().extract( idSelect );
+				ResultSet resultSet = jdbcCoordinator.getResultSetReturn().extract( idSelect, selectSQL );
 				try {
 					return extractGeneratedValue( resultSet, session );
 				}

hibernate-core/src/main/java/org/hibernate/persister/collection/AbstractCollectionPersister.java

@@ -1430,7 +1430,7 @@ public abstract class AbstractCollectionPersister
 					.prepareStatement( sqlSelectSizeString );
 			try {
 				getKeyType().nullSafeSet( st, key, 1, session );
-				ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st );
+				ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st, sqlSelectSizeString );
 				try {
 					final int baseIndex = Math.max( attributeMapping.getIndexMetadata().getListIndexBase(), 0 );
 					return rs.next() ? rs.getInt( 1 ) - baseIndex : 0;
@@ -1473,7 +1473,7 @@ public abstract class AbstractCollectionPersister
 			try {
 				getKeyType().nullSafeSet( st, key, 1, session );
 				indexOrElementType.nullSafeSet( st, indexOrElement, keyColumnNames.length + 1, session );
-				ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st );
+				ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st, sql );
 				try {
 					return rs.next();
 				}

hibernate-core/src/main/java/org/hibernate/persister/entity/AbstractEntityPersister.java

@@ -2075,15 +2075,13 @@ public abstract class AbstractEntityPersister
 		if ( LOG.isTraceEnabled() ) {
 			LOG.tracev( "Getting version: {0}", infoString( this, id, getFactory() ) );
 		}
-
+		final String versionSelectString = getVersionSelectString();
 		try {
 			final JdbcCoordinator jdbcCoordinator = session.getJdbcCoordinator();
-			final PreparedStatement st =
+			final PreparedStatement st = jdbcCoordinator.getStatementPreparer().prepareStatement( versionSelectString );
-					jdbcCoordinator.getStatementPreparer()
-							.prepareStatement( getVersionSelectString() );
 			try {
 				getIdentifierType().nullSafeSet( st, id, 1, session );
-				final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st );
+				final ResultSet rs = jdbcCoordinator.getResultSetReturn().extract( st, versionSelectString );
 				try {
 					if ( !rs.next() ) {
 						return null;
@@ -2106,7 +2104,7 @@ public abstract class AbstractEntityPersister
 			throw session.getJdbcServices().getSqlExceptionHelper().convert(
 					e,
 					"could not retrieve version: " + infoString( this, id, getFactory() ),
-					getVersionSelectString()
+					versionSelectString
 			);
 		}
 	}

hibernate-core/src/test/java/org/hibernate/orm/test/annotations/onetomany/OrderByTest.java

@@ -301,9 +301,10 @@ public class OrderByTest extends BaseCoreFunctionalTestCase {
 					.setTableName( queryableCollection.getTableName() )
 					.addColumn( "code" )
 					.addColumn( "transactions_index" );
-			PreparedStatement preparedStatement = ((SessionImplementor)s).getJdbcCoordinator().getStatementPreparer().prepareStatement( select.toStatementString() );
+			final String sql = select.toStatementString();
-			ResultSet resultSet = ((SessionImplementor)s).getJdbcCoordinator().getResultSetReturn().extract( preparedStatement );
+			PreparedStatement preparedStatement = ((SessionImplementor)s).getJdbcCoordinator().getStatementPreparer().prepareStatement( sql );
-			Map<Integer, String> valueMap = new HashMap<Integer, String>();
+			ResultSet resultSet = ((SessionImplementor)s).getJdbcCoordinator().getResultSetReturn().extract( preparedStatement, sql );
+			Map<Integer, String> valueMap = new HashMap<>();
 			while ( resultSet.next() ) {
 				final String code = resultSet.getString( 1 );
 				assertFalse( "code column was null", resultSet.wasNull() );

hibernate-core/src/test/java/org/hibernate/orm/test/collection/list/PersistentListTest.java

@@ -78,13 +78,13 @@ public class PersistentListTest {
 										.addColumn( "NAME" )
 										.addColumn( "LIST_INDEX" )
 										.addRestriction( "NAME", ComparisonRestriction.Operator.NE, "?" );
-								PreparedStatement preparedStatement = ( (SessionImplementor) session2 ).getJdbcCoordinator()
+								final String sql = select.toStatementString();
-										.getStatementPreparer()
+								PreparedStatement preparedStatement = session2.getJdbcCoordinator()										.getStatementPreparer()
-										.prepareStatement( select.toStatementString() );
+										.prepareStatement( sql );
 								preparedStatement.setString( 1, "root" );
-								ResultSet resultSet = ( (SessionImplementor) session2 ).getJdbcCoordinator()
+								ResultSet resultSet = session2.getJdbcCoordinator()
 										.getResultSetReturn()
-										.extract( preparedStatement );
+										.extract( preparedStatement, sql );
 								Map<String, Integer> valueMap = new HashMap<String, Integer>();
 								while ( resultSet.next() ) {
 									final String name = resultSet.getString( 1 );
@@ -139,13 +139,14 @@ public class PersistentListTest {
 										.addColumn( "order_id" )
 										.addColumn( "INDX" )
 										.addColumn( "PRD_CODE" );
+								final String sql = select.toStatementString();
 								PreparedStatement preparedStatement = ( (SessionImplementor) session2 ).getJdbcCoordinator()
 										.getStatementPreparer()
-										.prepareStatement( select.toStatementString() );
+										.prepareStatement( sql );
-								ResultSet resultSet = ( (SessionImplementor) session2 ).getJdbcCoordinator()
+								ResultSet resultSet = session2.getJdbcCoordinator()
 										.getResultSetReturn()
-										.extract( preparedStatement );
+										.extract( preparedStatement, sql );
-								Map<String, Integer> valueMap = new HashMap<String, Integer>();
+								Map<String, Integer> valueMap = new HashMap<>();
 								while ( resultSet.next() ) {
 									final int fk = resultSet.getInt( 1 );
 									assertFalse( "Collection key (FK) column was null", resultSet.wasNull() );

hibernate-core/src/test/java/org/hibernate/orm/test/exception/SQLExceptionConversionTest.java

@@ -58,10 +58,13 @@ public class SQLExceptionConversionTest extends BaseCoreFunctionalTestCase {
 					// result in a constraint violation
 					PreparedStatement ps = null;
 					try {
-						ps = ((SessionImplementor)session).getJdbcCoordinator().getStatementPreparer().prepareStatement( "INSERT INTO T_MEMBERSHIP (user_id, group_id) VALUES (?, ?)" );
+						final String sql = "INSERT INTO T_MEMBERSHIP (user_id, group_id) VALUES (?, ?)";
+						ps = ((SessionImplementor)session).getJdbcCoordinator()
+								.getStatementPreparer()
+								.prepareStatement( sql );
 						ps.setLong(1, 52134241);    // Non-existent user_id
 						ps.setLong(2, 5342);        // Non-existent group_id
-						((SessionImplementor)session).getJdbcCoordinator().getResultSetReturn().executeUpdate( ps );
+						((SessionImplementor)session).getJdbcCoordinator().getResultSetReturn().executeUpdate( ps, sql );
 
 						fail("INSERT should have failed");
 					}
@@ -88,8 +91,9 @@ public class SQLExceptionConversionTest extends BaseCoreFunctionalTestCase {
 					// prepare/execute a query against a non-existent table
 					PreparedStatement ps = null;
 					try {
-						ps = ((SessionImplementor)session).getJdbcCoordinator().getStatementPreparer().prepareStatement( "SELECT user_id, user_name FROM tbl_no_there" );
+						final String sql = "SELECT user_id, user_name FROM tbl_no_there";
-						((SessionImplementor)session).getJdbcCoordinator().getResultSetReturn().extract( ps );
+						ps = ((SessionImplementor)session).getJdbcCoordinator().getStatementPreparer().prepareStatement( sql );
+						((SessionImplementor)session).getJdbcCoordinator().getResultSetReturn().extract( ps, sql );
 
 						fail("SQL compilation should have failed");
 					}
@@ -124,10 +128,12 @@ public class SQLExceptionConversionTest extends BaseCoreFunctionalTestCase {
 					final ResultSetReturn resultSetReturn = jdbcCoordinator.getResultSetReturn();
 					PreparedStatement ps = null;
 					try {
-						ps = statementPreparer.prepareStatement( "UPDATE T_USER SET user_name = ? WHERE user_id = ?" );
+						final String sql = "UPDATE T_USER SET user_name = ? WHERE user_id = ?";
-						ps.setNull( 1, Types.VARCHAR ); // Attempt to update user name to NULL (NOT NULL constraint defined).
+						ps = statementPreparer.prepareStatement( sql );
+						// Attempt to update username to NULL (NOT NULL constraint defined).
+						ps.setNull( 1, Types.VARCHAR );
 						ps.setLong( 2, user.getId() );
-						resultSetReturn.executeUpdate( ps );
+						resultSetReturn.executeUpdate( ps, sql );
 
 						fail( "UPDATE should have failed because of not NULL constraint." );
 					}

hibernate-core/src/test/java/org/hibernate/orm/test/id/SequenceValueExtractor.java

@@ -32,7 +32,7 @@ public class SequenceValueExtractor {
 		final PreparedStatement query = sessionImpl.getJdbcCoordinator()
 				.getStatementPreparer()
 				.prepareStatement( queryString );
-		try ( final ResultSet resultSet = sessionImpl.getJdbcCoordinator().getResultSetReturn().extract( query ) ) {
+		try ( final ResultSet resultSet = sessionImpl.getJdbcCoordinator().getResultSetReturn().extract( query, queryString ) ) {
 			resultSet.next();
 			long value = resultSet.getLong( 1 );
 			if ( dialect instanceof DerbyDialect ) {

hibernate-core/src/test/java/org/hibernate/orm/test/id/custom/CustomSequenceGenerator.java

@@ -75,7 +75,7 @@ public class CustomSequenceGenerator implements IdentifierGenerator {
 		try {
 			final PreparedStatement st = session.getJdbcCoordinator().getStatementPreparer().prepareStatement( sqlSelectFrag );
 			try {
-				final ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st );
+				final ResultSet rs = session.getJdbcCoordinator().getResultSetReturn().extract( st, sqlSelectFrag );
 				try {
 					rs.next();
 					return rs.getInt( 1 );

hibernate-core/src/test/java/org/hibernate/orm/test/jdbc/internal/AggressiveReleaseTest.java

@@ -177,16 +177,16 @@ public class AggressiveReleaseTest extends BaseSessionFactoryFunctionalTest {
 						assertEquals( 1, connectionProvider.getReleasedConnections().size() );
 
 						// open a result set and hold it open...
-						ps = jdbcCoord.getStatementPreparer().prepareStatement( "select * from SANDBOX_JDBC_TST" );
+						final String sql = "select * from SANDBOX_JDBC_TST";
-						jdbcCoord.getResultSetReturn().extract( ps );
+						ps = jdbcCoord.getStatementPreparer().prepareStatement( sql );
+						jdbcCoord.getResultSetReturn().extract( ps, sql );
 						assertTrue( resourceRegistry.hasRegisteredResources() );
 						assertEquals( 1, connectionProvider.getAcquiredConnections().size() );
 						assertEquals( 1, connectionProvider.getReleasedConnections().size() );
 
 						// open a second result set
-						PreparedStatement ps2 = jdbcCoord.getStatementPreparer()
+						PreparedStatement ps2 = jdbcCoord.getStatementPreparer().prepareStatement( sql );
-								.prepareStatement( "select * from SANDBOX_JDBC_TST" );
+						jdbcCoord.getResultSetReturn().execute( ps, sql );
-						jdbcCoord.getResultSetReturn().execute( ps );
 						assertTrue( resourceRegistry.hasRegisteredResources() );
 						assertEquals( 1, connectionProvider.getAcquiredConnections().size() );
 						assertEquals( 1, connectionProvider.getReleasedConnections().size() );
@@ -243,8 +243,9 @@ public class AggressiveReleaseTest extends BaseSessionFactoryFunctionalTest {
 						jdbcCoord.disableReleases();
 
 						// open a result set...
-						ps = jdbcCoord.getStatementPreparer().prepareStatement( "select * from SANDBOX_JDBC_TST" );
+						final String sql = "select * from SANDBOX_JDBC_TST";
-						jdbcCoord.getResultSetReturn().extract( ps );
+						ps = jdbcCoord.getStatementPreparer().prepareStatement( sql );
+						jdbcCoord.getResultSetReturn().extract( ps, sql );
 						assertTrue( resourceRegistry.hasRegisteredResources() );
 						assertEquals( 1, connectionProvider.getAcquiredConnections().size() );
 						assertEquals( 1, connectionProvider.getReleasedConnections().size() );

hibernate-core/src/test/java/org/hibernate/orm/test/jdbc/internal/BasicConnectionTest.java

@@ -79,14 +79,15 @@ public class BasicConnectionTest extends BaseCoreFunctionalTestCase {
 			ddlTxn.commit();
 
 			Transaction dmlTxn = session.beginTransaction();
-			PreparedStatement ps = jdbcCoord.getStatementPreparer().prepareStatement(
+			final String insertSql = "insert into SANDBOX_JDBC_TST( ID, NAME ) values ( ?, ? )";
-					"insert into SANDBOX_JDBC_TST( ID, NAME ) values ( ?, ? )" );
+			PreparedStatement ps = jdbcCoord.getStatementPreparer().prepareStatement( insertSql );
 			ps.setLong( 1, 1 );
 			ps.setString( 2, "name" );
-			jdbcCoord.getResultSetReturn().execute( ps );
+			jdbcCoord.getResultSetReturn().execute( ps, insertSql );
 
-			ps = jdbcCoord.getStatementPreparer().prepareStatement( "select * from SANDBOX_JDBC_TST" );
+			final String selectSql = "select * from SANDBOX_JDBC_TST";
-			jdbcCoord.getResultSetReturn().extract( ps );
+			ps = jdbcCoord.getStatementPreparer().prepareStatement( selectSql );
+			jdbcCoord.getResultSetReturn().extract( ps, selectSql );
 			assertTrue( getResourceRegistry( jdbcCoord ).hasRegisteredResources() );
 			dmlTxn.commit();
 		}

hibernate-core/src/test/java/org/hibernate/orm/test/sql/autodiscovery/AutoDiscoveryTest.java

@@ -122,7 +122,7 @@ public class AutoDiscoveryTest extends BaseCoreFunctionalTestCase {
 					@Override
 					public void execute(Connection connection) throws SQLException {
 						PreparedStatement ps = sessionImplementor.getJdbcCoordinator().getStatementPreparer().prepareStatement( QUERY_STRING );
-						ResultSet rs = sessionImplementor.getJdbcCoordinator().getResultSetReturn().extract( ps );
+						ResultSet rs = sessionImplementor.getJdbcCoordinator().getResultSetReturn().extract( ps, QUERY_STRING );
 						try {
 							ResultSetMetaData metadata = rs.getMetaData();
 							String column1Alias = getDialect().getColumnAliasExtractor().extractColumnAlias( metadata, 1 );

hibernate-core/src/test/java/org/hibernate/orm/test/typeparameters/TypeParameterTest.java

@@ -68,13 +68,14 @@ public class TypeParameterTest {
 				new Work() {
 					@Override
 					public void execute(Connection connection) throws SQLException {
+						final String sql = "SELECT * FROM STRANGE_TYPED_OBJECT WHERE ID=?";
 						PreparedStatement statement = ( (SessionImplementor) s ).getJdbcCoordinator()
 								.getStatementPreparer()
-								.prepareStatement( "SELECT * FROM STRANGE_TYPED_OBJECT WHERE ID=?" );
+								.prepareStatement( sql );
 						statement.setInt( 1, id.intValue() );
 						ResultSet resultSet = ( (SessionImplementor) s ).getJdbcCoordinator()
 								.getResultSetReturn()
-								.extract( statement );
+								.extract( statement, sql );
 
 						assertTrue( "A row should have been returned", resultSet.next() );
 						assertTrue(

hibernate-envers/src/main/java/org/hibernate/envers/strategy/internal/ValidityAuditStrategy.java

@@ -477,7 +477,7 @@ public class ValidityAuditStrategy implements AuditStrategy {
 						for ( QueryParameterBinding binding : context.getBindings() ) {
 							index += binding.bind( index, statement, session );
 						}
-						int result = jdbcCoordinator.getResultSetReturn().executeUpdate( statement );
+						int result = jdbcCoordinator.getResultSetReturn().executeUpdate( statement, sql );
 						return result;
 					}
 					finally {