Hibernate
/
hibernate-orm
mirror of https://github.com/hibernate/hibernate-orm
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

move some logging in BatchImpl to typed methods 

+ very minor code cleanups in BatchImpl & JdbcCoordinatorImpl
This commit is contained in:
Gavin King 2024-10-04 08:54:40 +02:00
parent a0162f3ee5
commit aa6f88f1b4
3 changed files with 126 additions and 124 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

15
hibernate-core/src/main/java/org/hibernate/engine/jdbc/batch/JdbcBatchLogging.java
View File

@ -16,6 +16,7 @@ import org.jboss.logging.annotations.ValidIdRange;
import java.lang.invoke.MethodHandles;
import static org.jboss.logging.Logger.Level.INFO;
import static org.jboss.logging.Logger.Level.TRACE;
import static org.jboss.logging.Logger.Level.WARN;
/**
@ -36,10 +37,22 @@ public interface JdbcBatchLogging extends BasicLogger {
JdbcBatchLogging BATCH_MESSAGE_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), JdbcBatchLogging.class, NAME );
@LogMessage(level = WARN)
@Message(id = 100502, value = "Unable to release batch statement...")
@Message(id = 100502, value = "Unable to release batch statement")
void unableToReleaseBatchStatement();
@LogMessage(level = INFO)
@Message(id=100503, value = "On release of batch it still contained JDBC statements")
void batchContainedStatementsOnRelease();
@LogMessage(level = TRACE)
@Message("Created JDBC batch (%s) - [%s]")
void createBatch(int batchSize, String string);
@LogMessage(level = TRACE)
@Message("Adding to JDBC batch (%s / %s) - [%s]")
void addToBatch(int batchPosition, int batchSize, String string);
@LogMessage(level = TRACE)
@Message("Executing JDBC batch (%s / %s) - [%s]")
void executeBatch(int batchPosition, int batchSize, String string);
}

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

@ -32,7 +32,7 @@ import static org.hibernate.engine.jdbc.batch.JdbcBatchLogging.BATCH_MESSAGE_LOG
import static org.hibernate.sql.model.ModelMutationLogging.MODEL_MUTATION_LOGGER;
/**
* Standard implementation of Batch
* Standard implementation of {@link Batch}
*
* @author Steve Ebersole
*/
@ -63,6 +63,7 @@ public class BatchImpl implements Batch {
throw new IllegalArgumentException( "JDBC coordinator cannot be null" );
}
this.batchSizeToUse = batchSizeToUse;
this.key = key;
this.jdbcCoordinator = jdbcCoordinator;
this.statementGroup = statementGroup;
@ -71,11 +72,8 @@ public class BatchImpl implements Batch {
this.sqlStatementLogger = jdbcServices.getSqlStatementLogger();
this.sqlExceptionHelper = jdbcServices.getSqlExceptionHelper();
this.batchSizeToUse = batchSizeToUse;
if ( BATCH_LOGGER.isTraceEnabled() ) {
BATCH_LOGGER.tracef(
"Created Batch (%s) - `%s`",
BATCH_MESSAGE_LOGGER.createBatch(
batchSizeToUse,
key.toLoggableString()
);
@ -114,16 +112,17 @@ public class BatchImpl implements Batch {
public void addToBatch(JdbcValueBindings jdbcValueBindings, TableInclusionChecker inclusionChecker) {
final boolean loggerTraceEnabled = BATCH_LOGGER.isTraceEnabled();
if ( loggerTraceEnabled ) {
BATCH_LOGGER.tracef(
"Adding to JDBC batch (%s) - `%s`",
BATCH_MESSAGE_LOGGER.addToBatch(
batchPosition + 1,
batchSizeToUse,
getKey().toLoggableString()
);
}
try {
getStatementGroup().forEachStatement( (tableName, statementDetails) -> {
if ( inclusionChecker != null && !inclusionChecker.include( statementDetails.getMutatingTableDetails() ) ) {
if ( inclusionChecker != null
&& !inclusionChecker.include( statementDetails.getMutatingTableDetails() ) ) {
if ( loggerTraceEnabled ) {
MODEL_MUTATION_LOGGER.tracef(
"Skipping addBatch for table : %s (batch-position=%s)",
@ -131,27 +130,26 @@ public class BatchImpl implements Batch {
batchPosition+1
);
}
return;
}
//noinspection resource
final PreparedStatement statement = statementDetails.resolveStatement();
sqlStatementLogger.logStatement( statementDetails.getSqlString() );
jdbcValueBindings.beforeStatement( statementDetails );
try {
statement.addBatch();
}
catch (SQLException e) {
BATCH_LOGGER.debug( "SQLException escaped proxy", e );
throw sqlExceptionHelper.convert(
e,
"Could not perform addBatch",
statementDetails.getSqlString()
);
}
finally {
jdbcValueBindings.afterStatement( statementDetails.getMutatingTableDetails() );
else {
//noinspection resource
final PreparedStatement statement = statementDetails.resolveStatement();
sqlStatementLogger.logStatement( statementDetails.getSqlString() );
jdbcValueBindings.beforeStatement( statementDetails );
try {
statement.addBatch();
}
catch (SQLException e) {
BATCH_LOGGER.debug( "SQLException escaped proxy", e );
throw sqlExceptionHelper.convert(
e,
"Could not perform addBatch",
statementDetails.getSqlString()
);
}
finally {
jdbcValueBindings.afterStatement( statementDetails.getMutatingTableDetails() );
}
}
} );
}
@ -176,10 +174,10 @@ public class BatchImpl implements Batch {
"PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : %s",
statementDetails.getSqlString()
);
return;
}
clearBatch( statementDetails );
else {
clearBatch( statementDetails );
}
} );
statementGroup.release();
@ -236,34 +234,29 @@ public class BatchImpl implements Batch {
@Override
public void execute() {
notifyObserversExplicitExecution();
if ( getStatementGroup().getNumberOfStatements() == 0 ) {
return;
}
try {
if ( batchPosition == 0 ) {
if( !batchExecuted) {
if ( BATCH_LOGGER.isDebugEnabled() ) {
if ( getStatementGroup().getNumberOfStatements() != 0 ) {
try {
if ( batchPosition == 0 ) {
if ( !batchExecuted && BATCH_LOGGER.isDebugEnabled() ) {
BATCH_LOGGER.debugf(
"No batched statements to execute - %s",
getKey().toLoggableString()
);
}
}
else {
performExecution();
}
}
else {
performExecution();
finally {
releaseStatements();
}
}
finally {
releaseStatements();
}
}
protected void performExecution() {
if ( BATCH_LOGGER.isTraceEnabled() ) {
BATCH_LOGGER.tracef(
"Executing JDBC batch (%s / %s) - `%s`",
BATCH_MESSAGE_LOGGER.executeBatch(
batchPosition,
batchSizeToUse,
getKey().toLoggableString()
@ -276,37 +269,34 @@ public class BatchImpl implements Batch {
getStatementGroup().forEachStatement( (tableName, statementDetails) -> {
final String sql = statementDetails.getSqlString();
final PreparedStatement statement = statementDetails.getStatement();
if ( statement == null ) {
return;
}
try {
if ( statementDetails.getMutatingTableDetails().isIdentifierTable() ) {
final int[] rowCounts;
final EventManager eventManager = jdbcSessionOwner.getEventManager();
final HibernateMonitoringEvent jdbcBatchExecutionEvent = eventManager.beginJdbcBatchExecutionEvent();
try {
eventHandler.jdbcExecuteBatchStart();
rowCounts = statement.executeBatch();
if ( statement != null ) {
try {
if ( statementDetails.getMutatingTableDetails().isIdentifierTable() ) {
final int[] rowCounts;
final EventManager eventManager = jdbcSessionOwner.getEventManager();
final HibernateMonitoringEvent executionEvent = eventManager.beginJdbcBatchExecutionEvent();
try {
eventHandler.jdbcExecuteBatchStart();
rowCounts = statement.executeBatch();
}
finally {
eventManager.completeJdbcBatchExecutionEvent( executionEvent, sql );
eventHandler.jdbcExecuteBatchEnd();
}
checkRowCounts( rowCounts, statementDetails );
}
finally {
eventManager.completeJdbcBatchExecutionEvent( jdbcBatchExecutionEvent, sql );
eventHandler.jdbcExecuteBatchEnd();
else {
statement.executeBatch();
}
checkRowCounts( rowCounts, statementDetails );
}
else {
statement.executeBatch();
catch (SQLException e) {
abortBatch( e );
throw sqlExceptionHelper.convert( e, "could not execute batch", sql );
}
catch (RuntimeException re) {
abortBatch( re );
throw re;
}
}
catch (SQLException e) {
abortBatch( e );
throw sqlExceptionHelper.convert( e, "could not execute batch", sql );
}
catch (RuntimeException re) {
abortBatch( re );
throw re;
}
} );
}
@ -318,14 +308,12 @@ public class BatchImpl implements Batch {
private void checkRowCounts(int[] rowCounts, PreparedStatementDetails statementDetails)
throws SQLException, HibernateException {
final int numberOfRowCounts = rowCounts.length;
if ( batchPosition != 0 ) {
if ( numberOfRowCounts != batchPosition ) {
JDBC_MESSAGE_LOGGER.unexpectedRowCounts(
statementDetails.getMutatingTableDetails().getTableName(),
numberOfRowCounts,
batchPosition
);
}
if ( batchPosition != 0 && numberOfRowCounts != batchPosition ) {
JDBC_MESSAGE_LOGGER.unexpectedRowCounts(
statementDetails.getMutatingTableDetails().getTableName(),
numberOfRowCounts,
batchPosition
);
}
for ( int i = 0; i < numberOfRowCounts; i++ ) {
@ -345,10 +333,9 @@ public class BatchImpl implements Batch {
public void release() {
if ( BATCH_MESSAGE_LOGGER.isInfoEnabled() ) {
final PreparedStatementGroup statementGroup = getStatementGroup();
if ( statementGroup.getNumberOfStatements() != 0 ) {
if ( statementGroup.hasMatching( (statementDetails) -> statementDetails.getStatement() != null ) ) {
BATCH_MESSAGE_LOGGER.batchContainedStatementsOnRelease();
}
if ( statementGroup.getNumberOfStatements() != 0
&& statementGroup.hasMatching( statementDetails -> statementDetails.getStatement() != null ) ) {
BATCH_MESSAGE_LOGGER.batchContainedStatementsOnRelease();
}
}
releaseStatements();

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

@ -80,7 +80,8 @@ public class JdbcCoordinatorImpl implements JdbcCoordinator {
JdbcServices jdbcServices) {
this.isUserSuppliedConnection = userSuppliedConnection != null;
final ResourceRegistry resourceRegistry = new ResourceRegistryStandardImpl( owner.getJdbcSessionContext().getEventHandler() );
final ResourceRegistry resourceRegistry =
new ResourceRegistryStandardImpl( owner.getJdbcSessionContext().getEventHandler() );
if ( isUserSuppliedConnection ) {
this.logicalConnection = new LogicalConnectionProvidedImpl( userSuppliedConnection, resourceRegistry );
}
@ -191,11 +192,7 @@ public class JdbcCoordinatorImpl implements JdbcCoordinator {
@Override
public void conditionallyExecuteBatch(BatchKey key) {
if ( currentBatch == null ) {
return;
}
if ( !currentBatch.getKey().equals( key ) ) {
if ( currentBatch != null && !currentBatch.getKey().equals( key ) ) {
JdbcBatchLogging.BATCH_LOGGER.debugf( "Conditionally executing batch - %s", currentBatch.getKey() );
currentBatch.execute();
}
@ -262,25 +259,25 @@ public class JdbcCoordinatorImpl implements JdbcCoordinator {
@Override
public void afterStatementExecution() {
final ConnectionReleaseMode connectionReleaseMode = getLogicalConnection().getConnectionHandlingMode().getReleaseMode();
final ConnectionReleaseMode connectionReleaseMode = connectionReleaseMode();
LOG.tracev( "Starting after statement execution processing [{0}]", connectionReleaseMode );
if ( connectionReleaseMode == AFTER_STATEMENT ) {
if ( ! releasesEnabled ) {
LOG.debug( "Skipping aggressive release due to manual disabling" );
return;
}
if ( hasRegisteredResources() ) {
else if ( hasRegisteredResources() ) {
LOG.debug( "Skipping aggressive release due to registered resources" );
return;
}
getLogicalConnection().afterStatement();
else {
getLogicalConnection().afterStatement();
}
}
}
@Override
public void afterTransaction() {
transactionTimeOutInstant = -1;
switch ( getLogicalConnection().getConnectionHandlingMode().getReleaseMode() ) {
switch ( connectionReleaseMode() ) {
case AFTER_STATEMENT:
case AFTER_TRANSACTION:
case BEFORE_TRANSACTION_COMPLETION:
@ -288,6 +285,10 @@ public class JdbcCoordinatorImpl implements JdbcCoordinator {
}
}
private ConnectionReleaseMode connectionReleaseMode() {
return getLogicalConnection().getConnectionHandlingMode().getReleaseMode();
}
private boolean hasRegisteredResources() {
return getLogicalConnection().getResourceRegistry().hasRegisteredResources();
}
@ -319,9 +320,10 @@ public class JdbcCoordinatorImpl implements JdbcCoordinator {
if ( statement instanceof JdbcWrapper ) {
final JdbcWrapper<Statement> wrapper = (JdbcWrapper<Statement>) statement;
registerLastQuery( wrapper.getWrappedObject() );
return;
}
lastQuery = statement;
else {
lastQuery = statement;
}
}
@Override
@ -355,7 +357,6 @@ public class JdbcCoordinatorImpl implements JdbcCoordinator {
releasesEnabled = false;
}
@SuppressWarnings("unchecked")
protected void close(Statement statement) {
LOG.tracev( "Closing prepared statement [{0}]", statement );
@ -364,38 +365,39 @@ public class JdbcCoordinatorImpl implements JdbcCoordinator {
sqlExceptionHelper().logAndClearWarnings( statement );
if ( statement instanceof InvalidatableWrapper ) {
@SuppressWarnings("unchecked")
final InvalidatableWrapper<Statement> wrapper = (InvalidatableWrapper<Statement>) statement;
close( wrapper.getWrappedObject() );
wrapper.invalidate();
return;
}
try {
// if we are unable to "clean" the prepared statement,
// we do not close it
else {
try {
if ( statement.getMaxRows() != 0 ) {
statement.setMaxRows( 0 );
// if we are unable to "clean" the prepared statement,
// we do not close it
try {
if ( statement.getMaxRows() != 0 ) {
statement.setMaxRows( 0 );
}
if ( statement.getQueryTimeout() != 0 ) {
statement.setQueryTimeout( 0 );
}
}
if ( statement.getQueryTimeout() != 0 ) {
statement.setQueryTimeout( 0 );
catch( SQLException sqle ) {
// there was a problem "cleaning" the prepared statement
if ( LOG.isDebugEnabled() ) {
LOG.debugf( "Exception clearing maxRows/queryTimeout [%s]", sqle.getMessage() );
}
// EARLY EXIT!!!
return;
}
statement.close();
if ( lastQuery == statement ) {
lastQuery = null;
}
}
catch( SQLException sqle ) {
// there was a problem "cleaning" the prepared statement
if ( LOG.isDebugEnabled() ) {
LOG.debugf( "Exception clearing maxRows/queryTimeout [%s]", sqle.getMessage() );
}
// EARLY EXIT!!!
return;
catch ( Exception e ) {
LOG.debugf( "Unable to release JDBC statement [%s]", e.getMessage() );
}
statement.close();
if ( lastQuery == statement ) {
lastQuery = null;
}
}
catch ( Exception e ) {
LOG.debugf( "Unable to release JDBC statement [%s]", e.getMessage() );
}
}