Skip to content

More logging improvements #10527

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 4 commits into from
Jul 14, 2025
Merged

More logging improvements #10527

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
48f2911
introduce JtaLogging
gavinking Jul 14, 2025
a623601
use JDBC_LOGGER for logging resource-local tx management
gavinking Jul 14, 2025
ca6ce92
misc very minor improvements to log messages
gavinking Jul 14, 2025
463d3f6
remove unnecessary check
gavinking Jul 14, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions hibernate-core/src/main/java/org/hibernate/engine/jdbc/JdbcLogging.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -138,4 +138,8 @@ public interface JdbcLogging extends BasicLogger {
JDBC version: %s.%s""",
id = 100018)
void logDriverInfo(String name, String version, int major, int minor, int jdbcMajor, int jdbcMinor);

@LogMessage(level = WARN)
@Message(value = "Called joinTransaction() on a non-JTA EntityManager (ignoring)", id = 100020)
void callingJoinTransactionOnNonJtaEntityManager();
}
20 changes: 8 additions & 12 deletions hibernate-core/src/main/java/org/hibernate/internal/AbstractSharedSessionContract.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -644,19 +644,15 @@ protected void pulseTransactionCoordinator() {
@Override
public void joinTransaction() {
checkOpen();
if ( !transactionCoordinator.getTransactionCoordinatorBuilder().isJta() ) {
log.callingJoinTransactionOnNonJtaEntityManager();
try {
// For a non-JTA TransactionCoordinator, this just logs a WARNing
transactionCoordinator.explicitJoin();
}
else {
try {
transactionCoordinator.explicitJoin();
}
catch ( TransactionRequiredForJoinException e ) {
throw new TransactionRequiredException( e.getMessage() );
}
catch ( HibernateException he ) {
throw getExceptionConverter().convert( he );
}
catch ( TransactionRequiredForJoinException e ) {
throw new TransactionRequiredException( e.getMessage() );
}
catch ( HibernateException he ) {
throw getExceptionConverter().convert( he );
}
}

Expand Down
12 changes: 0 additions & 12 deletions hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,10 +71,6 @@ public interface CoreMessageLogger extends BasicLogger {
@Message(value = "Second-level cache disabled", id = 26)
void noRegionFactory();

@LogMessage(level = WARN)
@Message(value = "Calling joinTransaction() on a non JTA EntityManager", id = 27)
void callingJoinTransactionOnNonJtaEntityManager();

@LogMessage(level = DEBUG)
@Message(value = "Instantiating factory [%s] with settings: %s", id = 30)
void instantiatingFactory(String uuid, Map<String, Object> settings);
Expand Down Expand Up @@ -557,14 +553,6 @@ void cannotResolveNonNullableTransientDependencies(
)
void nonCompliantMapConversion(String collectionRole);

@LogMessage(level = WARN)
@Message(
id = 451,
value = "Transaction afterCompletion called by a background thread; " +
"delaying afterCompletion processing until the original thread can handle it. [status=%s]"
)
void rollbackFromBackgroundThread(int status);

// 458-466 reserved for use by main branch (ORM 5.0.0)

@LogMessage(level = DEBUG)
Expand Down
2 changes: 1 addition & 1 deletion ...ore/src/main/java/org/hibernate/resource/beans/internal/FallbackBeanInstanceProducer.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ private FallbackBeanInstanceProducer() {

@Override
public <B> B produceBeanInstance(Class<B> beanType) {
log.tracef( "Creating ManagedBean(%s) using direct instantiation", beanType.getName() );
log.tracef( "Creating ManagedBean [%s] using direct instantiation", beanType.getName() );
try {
final Constructor<B> constructor = beanType.getDeclaredConstructor();
constructor.setAccessible( true );
Expand Down
6 changes: 3 additions & 3 deletions .../main/java/org/hibernate/resource/jdbc/internal/AbstractLogicalConnectionImplementor.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -108,7 +108,7 @@ protected void afterCompletion() {
protected void resetConnection(boolean initiallyAutoCommit) {
try {
if ( initiallyAutoCommit ) {
log.trace( "re-enabling auto-commit on JDBC Connection after completion of JDBC-based transaction" );
log.trace( "Re-enabling auto-commit on JDBC Connection after completion of JDBC-based transaction" );
getConnectionForTransactionManagement().setAutoCommit( true );
status = TransactionStatus.NOT_ACTIVE;
}
Expand All @@ -121,7 +121,7 @@ protected void resetConnection(boolean initiallyAutoCommit) {
@Override
public void rollback() {
try {
log.trace( "Preparing to rollback transaction via JDBC Connection.rollback()" );
log.trace( "Preparing to roll back transaction via JDBC Connection.rollback()" );
status = TransactionStatus.ROLLING_BACK;
if ( isPhysicallyConnected() ) {
getConnectionForTransactionManagement().rollback();
Expand All @@ -130,7 +130,7 @@ public void rollback() {
errorIfClosed();
}
status = TransactionStatus.ROLLED_BACK;
log.trace( "Transaction rolled-back via JDBC Connection.rollback()" );
log.trace( "Transaction rolled back via JDBC Connection.rollback()" );
}
catch( SQLException e ) {
status = TransactionStatus.FAILED_ROLLBACK;
Expand Down
13 changes: 5 additions & 8 deletions .../java/org/hibernate/resource/transaction/backend/jdbc/internal/JdbcIsolationDelegate.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@
* @author Andrea Boriero
*/
public class JdbcIsolationDelegate implements IsolationDelegate {
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( JdbcIsolationDelegate.class );
private static final CoreMessageLogger log = CoreLogging.messageLogger( JdbcIsolationDelegate.class );

private final JdbcConnectionAccess connectionAccess;
private final SqlExceptionHelper sqlExceptionHelper;
Expand All @@ -33,10 +33,7 @@ public JdbcIsolationDelegate(TransactionCoordinatorOwner transactionCoordinatorO
}

public JdbcIsolationDelegate(JdbcSessionOwner jdbcSessionOwner) {
this(
jdbcSessionOwner.getJdbcConnectionAccess(),
jdbcSessionOwner.getSqlExceptionHelper()
);
this( jdbcSessionOwner.getJdbcConnectionAccess(), jdbcSessionOwner.getSqlExceptionHelper() );
}

public JdbcIsolationDelegate(JdbcConnectionAccess connectionAccess, SqlExceptionHelper sqlExceptionHelper) {
Expand Down Expand Up @@ -80,7 +77,7 @@ public <T> T delegateWork(WorkExecutorVisitable<T> work, boolean transacted) thr
}
}
catch ( Exception exception ) {
LOG.unableToRollbackConnection( exception );
log.unableToRollbackConnection( exception );
}

if ( e instanceof HibernateException ) {
Expand All @@ -99,14 +96,14 @@ else if ( e instanceof SQLException sqle ) {
connection.setAutoCommit( true );
}
catch ( Exception ignore ) {
LOG.trace( "was unable to reset connection back to auto-commit" );
log.trace( "Unable to reset connection back to auto-commit" );
}
}
try {
jdbcConnectionAccess().releaseConnection( connection );
}
catch ( Exception ignore ) {
LOG.unableToReleaseIsolatedConnection( ignore );
log.unableToReleaseIsolatedConnection( ignore );
}
}
}
Expand Down
6 changes: 3 additions & 3 deletions ...transaction/backend/jdbc/internal/JdbcResourceLocalTransactionCoordinatorBuilderImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,15 +26,15 @@ public class JdbcResourceLocalTransactionCoordinatorBuilderImpl implements Trans
/**
* Singleton access
*/
public static final JdbcResourceLocalTransactionCoordinatorBuilderImpl INSTANCE = new JdbcResourceLocalTransactionCoordinatorBuilderImpl();
public static final TransactionCoordinatorBuilder INSTANCE = new JdbcResourceLocalTransactionCoordinatorBuilderImpl();

@Override
public TransactionCoordinator buildTransactionCoordinator(TransactionCoordinatorOwner owner, Options options) {
if ( owner instanceof JdbcResourceTransactionAccess ) {
if ( owner instanceof JdbcResourceTransactionAccess transactionAccess ) {
return new JdbcResourceLocalTransactionCoordinatorImpl(
this,
owner,
(JdbcResourceTransactionAccess) owner
transactionAccess
);
}

Expand Down
23 changes: 11 additions & 12 deletions ...source/transaction/backend/jdbc/internal/JdbcResourceLocalTransactionCoordinatorImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,6 @@
import jakarta.transaction.Status;

import org.hibernate.resource.transaction.spi.IsolationDelegate;
import org.hibernate.internal.CoreMessageLogger;
import org.hibernate.jpa.spi.JpaCompliance;
import org.hibernate.resource.transaction.backend.jdbc.spi.JdbcResourceTransaction;
import org.hibernate.resource.transaction.backend.jdbc.spi.JdbcResourceTransactionAccess;
Expand All @@ -25,7 +24,8 @@
import org.hibernate.resource.transaction.spi.TransactionStatus;

import static java.util.Collections.emptyList;
import static org.hibernate.internal.CoreLogging.messageLogger;
import static org.hibernate.engine.jdbc.JdbcLogging.JDBC_LOGGER;
import static org.hibernate.engine.jdbc.JdbcLogging.JDBC_MESSAGE_LOGGER;

/**
* An implementation of {@link TransactionCoordinator} based on managing a
Expand All @@ -36,7 +36,6 @@
* @see JdbcResourceTransaction
*/
public class JdbcResourceLocalTransactionCoordinatorImpl implements TransactionCoordinator {
private static final CoreMessageLogger log = messageLogger( JdbcResourceLocalTransactionCoordinatorImpl.class );

private final TransactionCoordinatorBuilder transactionCoordinatorBuilder;
private final JdbcResourceTransactionAccess jdbcResourceTransactionAccess;
Expand Down Expand Up @@ -92,7 +91,7 @@ public TransactionDriver getTransactionDriverControl() {
@Override
public void explicitJoin() {
// nothing to do here, but log a warning
log.callingJoinTransactionOnNonJtaEntityManager();
JDBC_MESSAGE_LOGGER.callingJoinTransactionOnNonJtaEntityManager();
}

@Override
Expand Down Expand Up @@ -151,7 +150,7 @@ private void afterBeginCallback() {
// report entering into a "transactional context"
transactionCoordinatorOwner.startTransactionBoundary();

log.trace( "Notifying resource-local transaction observers after begin" );
JDBC_LOGGER.trace( "Notifying resource-local transaction observers after begin" );

// trigger the Transaction-API-only after-begin callback
transactionCoordinatorOwner.afterTransactionBegin();
Expand All @@ -163,7 +162,7 @@ private void afterBeginCallback() {
}

private void beforeCompletionCallback() {
log.trace( "Notifying resource-local transaction observers before completion" );
JDBC_LOGGER.trace( "Notifying resource-local transaction observers before completion" );
try {
transactionCoordinatorOwner.beforeTransactionCompletion();
synchronizationRegistry.notifySynchronizationsBeforeTransactionCompletion();
Expand All @@ -181,7 +180,7 @@ private void beforeCompletionCallback() {
}

private void afterCompletionCallback(boolean successful) {
log.trace( "Notifying resource-local transaction observers after completion" );
JDBC_LOGGER.trace( "Notifying resource-local transaction observers after completion" );
final int statusToSend = successful ? Status.STATUS_COMMITTED : Status.STATUS_ROLLEDBACK;
synchronizationRegistry.notifySynchronizationsAfterTransactionCompletion( statusToSend );
transactionCoordinatorOwner.afterTransactionCompletion( successful, false );
Expand Down Expand Up @@ -231,7 +230,7 @@ public void begin() {

protected void errorIfInvalid() {
if ( invalid ) {
throw new IllegalStateException( "Physical-transaction delegate is no longer valid" );
throw new IllegalStateException( "Physical transaction delegate is no longer valid" );
}
}

Expand Down Expand Up @@ -263,14 +262,14 @@ private void commitNoRollbackOnly() {
}
catch (RuntimeException e2) {
e.addSuppressed( e2 );
log.debug( "Encountered failure rolling back failed commit", e2 );
JDBC_LOGGER.debug( "Encountered failure rolling back failed commit", e2 );
}
throw e;
}
}

private void commitRollbackOnly() {
log.trace( "On commit, transaction was marked for rollback only, rolling back" );
JDBC_LOGGER.trace( "On commit, transaction was marked for rollback only, rolling back" );
rollback();
if ( jpaCompliance.isJpaTransactionComplianceEnabled() ) {
throw new RollbackException( "Transaction was marked for rollback only" );
Expand Down Expand Up @@ -301,8 +300,8 @@ public TransactionStatus getStatus() {
@Override
public void markRollbackOnly() {
if ( getStatus() != TransactionStatus.ROLLED_BACK ) {
if ( log.isTraceEnabled() ) {
log.trace( "JDBC transaction marked for rollback only (exception provided for stack trace)",
if ( JDBC_LOGGER.isTraceEnabled() ) {
JDBC_LOGGER.trace( "JDBC transaction marked for rollback only (exception provided for stack trace)",
new Exception( "exception just for purpose of providing stack trace" ) );
}
rollbackOnly = true;
Expand Down
13 changes: 6 additions & 7 deletions ...in/java/org/hibernate/resource/transaction/backend/jta/internal/JtaIsolationDelegate.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,20 +21,19 @@
import org.hibernate.exception.internal.SQLStateConversionDelegate;
import org.hibernate.resource.jdbc.spi.JdbcSessionOwner;
import org.hibernate.resource.transaction.spi.IsolationDelegate;
import org.hibernate.internal.CoreLogging;
import org.hibernate.internal.CoreMessageLogger;
import org.hibernate.internal.util.ExceptionHelper;
import org.hibernate.jdbc.WorkExecutor;
import org.hibernate.jdbc.WorkExecutorVisitable;
import org.hibernate.resource.transaction.spi.TransactionCoordinatorOwner;

import static org.hibernate.resource.transaction.backend.jta.internal.JtaLogging.JTA_LOGGER;

/**
* An isolation delegate for JTA environments.
*
* @author Andrea Boriero
*/
public class JtaIsolationDelegate implements IsolationDelegate {
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( JtaIsolationDelegate.class );

private final JdbcConnectionAccess connectionAccess;
private final BiFunction<SQLException, String, JDBCException> sqlExceptionConverter;
Expand Down Expand Up @@ -115,7 +114,7 @@ private <T> T doInSuspendedTransaction(HibernateCallable<T> callable) {
// First we suspend any current JTA transaction
final Transaction surroundingTransaction = transactionManager.suspend();
if ( surroundingTransaction != null ) {
LOG.tracef( "Surrounding JTA transaction suspended [%s]", surroundingTransaction );
JTA_LOGGER.transactionSuspended( surroundingTransaction );
}

try {
Expand All @@ -128,7 +127,7 @@ private <T> T doInSuspendedTransaction(HibernateCallable<T> callable) {
try {
if ( surroundingTransaction != null ) {
transactionManager.resume( surroundingTransaction );
LOG.tracef( "Surrounding JTA transaction resumed [%s]", surroundingTransaction );
JTA_LOGGER.transactionResumed( surroundingTransaction );
}
}
catch ( Throwable t2 ) {
Expand Down Expand Up @@ -165,7 +164,7 @@ private <T> T doInNewTransaction(HibernateCallable<T> callable, TransactionManag
transactionManager.rollback();
}
catch ( Exception exception ) {
LOG.unableToRollbackIsolatedTransaction( e, exception );
JTA_LOGGER.unableToRollbackIsolatedTransaction( e, exception );
}
throw new HibernateException( "Could not apply work", e );
}
Expand Down Expand Up @@ -195,7 +194,7 @@ private <T> T doTheWork(WorkExecutorVisitable<T> work) {
jdbcConnectionAccess().releaseConnection( connection );
}
catch ( Throwable throwable ) {
LOG.unableToReleaseIsolatedConnection( throwable );
JTA_LOGGER.unableToReleaseIsolatedConnection( throwable );
}
}
}
Expand Down
Loading