diff --git a/hibernate-core/src/main/java/org/hibernate/context/internal/CurrentSessionLogging.java b/hibernate-core/src/main/java/org/hibernate/context/internal/CurrentSessionLogging.java new file mode 100644 index 000000000000..acff2c2c57c3 --- /dev/null +++ b/hibernate-core/src/main/java/org/hibernate/context/internal/CurrentSessionLogging.java @@ -0,0 +1,66 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * Copyright Red Hat Inc. and Hibernate Authors + */ +package org.hibernate.context.internal; + +import org.hibernate.Internal; +import org.hibernate.internal.log.SubSystemLogging; + +import org.jboss.logging.BasicLogger; +import org.jboss.logging.Logger; +import org.jboss.logging.annotations.Cause; +import org.jboss.logging.annotations.LogMessage; +import org.jboss.logging.annotations.Message; +import org.jboss.logging.annotations.MessageLogger; +import org.jboss.logging.annotations.ValidIdRange; + +import java.lang.invoke.MethodHandles; + +import static org.jboss.logging.Logger.Level.DEBUG; +import static org.jboss.logging.Logger.Level.TRACE; +import static org.jboss.logging.Logger.Level.WARN; + +/** + * Sub-system logging related to CurrentSessionContext implementations + */ +@SubSystemLogging( + name = CurrentSessionLogging.NAME, + description = "Logging related to current session context" +) +@MessageLogger(projectCode = "HHH") +@ValidIdRange(min = 90070001, max = 90080000) +@Internal +public interface CurrentSessionLogging extends BasicLogger { + String NAME = SubSystemLogging.BASE + ".current_session"; + + CurrentSessionLogging CURRENT_SESSION_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), CurrentSessionLogging.class, NAME ); + + @LogMessage(level = WARN) + @Message(id = 90070001, value = "Session already bound on call to bind(); make sure you clean up your sessions") + void alreadySessionBound(); + + @LogMessage(level = TRACE) + @Message("Allowing invocation [%s] to proceed to real session") + void allowingInvocationToProceed(String methodName); + + @LogMessage(level = TRACE) + @Message("Allowing invocation [%s] to proceed to real (closed) session") + void allowingInvocationToProceedToClosedSession(String methodName); + + @LogMessage(level = TRACE) + @Message("Allowing invocation [%s] to proceed to real (non-transacted) session") + void allowingInvocationToProceedToNonTransactedSession(String methodName); + + @LogMessage(level = DEBUG) + @Message(id = 90070011, value = "Unable to rollback transaction for orphaned session") + void unableToRollbackTransactionForOrphanedSession(@Cause Throwable t); + + @LogMessage(level = DEBUG) + @Message(id = 90070012, value = "Unable to close orphaned session") + void unableToCloseOrphanedSession(@Cause Throwable t); + + @LogMessage(level = DEBUG) + @Message(id = 90070013, value = "Unable to release generated current session on failed synchronization registration") + void unableToReleaseGeneratedCurrentSessionOnFailedSynchronizationRegistration(@Cause Throwable t); +} diff --git a/hibernate-core/src/main/java/org/hibernate/context/internal/JTASessionContext.java b/hibernate-core/src/main/java/org/hibernate/context/internal/JTASessionContext.java index 4842bf36aaba..142692241536 100644 --- a/hibernate-core/src/main/java/org/hibernate/context/internal/JTASessionContext.java +++ b/hibernate-core/src/main/java/org/hibernate/context/internal/JTASessionContext.java @@ -15,8 +15,7 @@ import org.hibernate.context.spi.AbstractCurrentSessionContext; import org.hibernate.engine.spi.SessionFactoryImplementor; import org.hibernate.engine.transaction.jta.platform.spi.JtaPlatform; -import org.hibernate.internal.CoreLogging; -import org.hibernate.internal.CoreMessageLogger; +import static org.hibernate.context.internal.CurrentSessionLogging.CURRENT_SESSION_LOGGER; import org.hibernate.resource.jdbc.spi.PhysicalConnectionHandlingMode; @@ -44,8 +43,6 @@ */ public class JTASessionContext extends AbstractCurrentSessionContext { - private static final CoreMessageLogger LOG = CoreLogging.messageLogger( JTASessionContext.class ); - private transient final Map currentSessionMap = new ConcurrentHashMap<>(); /** @@ -100,7 +97,7 @@ public Session currentSession() throws HibernateException { currentSession.close(); } catch ( Throwable e ) { - LOG.debug( "Unable to release generated current-session on failed synchronization registration", e ); + CURRENT_SESSION_LOGGER.unableToReleaseGeneratedCurrentSessionOnFailedSynchronizationRegistration(e); } throw new HibernateException( "Unable to register cleanup Synchronization with TransactionManager" ); } diff --git a/hibernate-core/src/main/java/org/hibernate/context/internal/ManagedSessionContext.java b/hibernate-core/src/main/java/org/hibernate/context/internal/ManagedSessionContext.java index 41df33ce2112..af39ff5b883f 100644 --- a/hibernate-core/src/main/java/org/hibernate/context/internal/ManagedSessionContext.java +++ b/hibernate-core/src/main/java/org/hibernate/context/internal/ManagedSessionContext.java @@ -52,14 +52,14 @@ public ManagedSessionContext(SessionFactoryImplementor factory) { @Override public Session currentSession() { - final Session current = existingSession( factory() ); + final var current = existingSession( factory() ); if ( current == null ) { throw new HibernateException( "No session currently bound to execution context" ); } else { validateExistingSession( current ); + return current; } - return current; } /** @@ -92,7 +92,7 @@ public static Session bind(Session session) { * @return The bound session if one, else null. */ public static Session unbind(SessionFactory factory) { - final Map sessionMap = sessionMap(); + final var sessionMap = sessionMap(); Session existing = null; if ( sessionMap != null ) { existing = sessionMap.remove( factory ); @@ -102,13 +102,8 @@ public static Session unbind(SessionFactory factory) { } private static Session existingSession(SessionFactory factory) { - final Map sessionMap = sessionMap(); - if ( sessionMap == null ) { - return null; - } - else { - return sessionMap.get( factory ); - } + final var sessionMap = sessionMap(); + return sessionMap == null ? null : sessionMap.get( factory ); } protected static Map sessionMap() { @@ -116,7 +111,7 @@ protected static Map sessionMap() { } private static Map sessionMap(boolean createMap) { - Map sessionMap = CONTEXT_TL.get(); + var sessionMap = CONTEXT_TL.get(); if ( sessionMap == null && createMap ) { sessionMap = new HashMap<>(); CONTEXT_TL.set( sessionMap ); @@ -125,7 +120,7 @@ private static Map sessionMap(boolean createMap) { } private static void doCleanup() { - final Map sessionMap = sessionMap( false ); + final var sessionMap = sessionMap( false ); if ( sessionMap != null ) { if ( sessionMap.isEmpty() ) { CONTEXT_TL.remove(); diff --git a/hibernate-core/src/main/java/org/hibernate/context/internal/ThreadLocalSessionContext.java b/hibernate-core/src/main/java/org/hibernate/context/internal/ThreadLocalSessionContext.java index 2be5a0dd37a2..4b3f780569c8 100644 --- a/hibernate-core/src/main/java/org/hibernate/context/internal/ThreadLocalSessionContext.java +++ b/hibernate-core/src/main/java/org/hibernate/context/internal/ThreadLocalSessionContext.java @@ -28,8 +28,7 @@ import org.hibernate.engine.spi.SessionFactoryImplementor; import org.hibernate.engine.spi.SessionImplementor; import org.hibernate.event.spi.EventSource; -import org.hibernate.internal.CoreLogging; -import org.hibernate.internal.CoreMessageLogger; +import static org.hibernate.context.internal.CurrentSessionLogging.CURRENT_SESSION_LOGGER; import org.hibernate.resource.jdbc.spi.PhysicalConnectionHandlingMode; import org.hibernate.resource.transaction.spi.TransactionStatus; @@ -58,8 +57,6 @@ */ public class ThreadLocalSessionContext extends AbstractCurrentSessionContext { - private static final CoreMessageLogger LOG = CoreLogging.messageLogger( ThreadLocalSessionContext.class ); - private static final Class[] SESSION_PROXY_INTERFACES = new Class[] { Session.class, SessionImplementor.class, @@ -167,8 +164,8 @@ protected PhysicalConnectionHandlingMode getConnectionHandlingMode() { } protected Session wrap(Session session) { - final TransactionProtectionWrapper wrapper = new TransactionProtectionWrapper( session ); - final Session wrapped = (Session) Proxy.newProxyInstance( + final var wrapper = new TransactionProtectionWrapper( session ); + final var wrapped = (Session) Proxy.newProxyInstance( Session.class.getClassLoader(), SESSION_PROXY_INTERFACES, wrapper @@ -189,25 +186,20 @@ public static void bind(Session session) { private static void terminateOrphanedSession(Session orphan) { if ( orphan != null ) { - LOG.alreadySessionBound(); - try { - final Transaction orphanTransaction = orphan.getTransaction(); + CURRENT_SESSION_LOGGER.alreadySessionBound(); + try ( orphan ) { + final var orphanTransaction = orphan.getTransaction(); if ( orphanTransaction != null && orphanTransaction.getStatus() == TransactionStatus.ACTIVE ) { try { orphanTransaction.rollback(); } - catch( Throwable t ) { - LOG.debug( "Unable to rollback transaction for orphaned session", t ); + catch (Throwable t) { + CURRENT_SESSION_LOGGER.unableToRollbackTransactionForOrphanedSession( t ); } } } - finally { - try { - orphan.close(); - } - catch( Throwable t ) { - LOG.debug( "Unable to close orphaned session", t ); - } + catch (Throwable t) { + CURRENT_SESSION_LOGGER.unableToCloseOrphanedSession( t ); } } @@ -232,13 +224,13 @@ protected static Map sessionMap() { } private static void doBind(Session session, SessionFactory factory) { - Session orphanedPreviousSession = sessionMap().put( factory, session ); + final var orphanedPreviousSession = sessionMap().put( factory, session ); terminateOrphanedSession( orphanedPreviousSession ); } private static Session doUnbind(SessionFactory factory) { - final Map sessionMap = sessionMap(); - final Session session = sessionMap.remove( factory ); + final var sessionMap = sessionMap(); + final var session = sessionMap.remove( factory ); if ( sessionMap.isEmpty() ) { //Do not use set(null) as it would prevent the initialValue to be invoked again in case of need. CONTEXT_TL.remove(); @@ -288,10 +280,12 @@ public Object invoke(Object proxy, Method method, Object[] args) throws Throwabl return this.equals( Proxy.getInvocationHandler( args[0] ) ); } else if ( "hashCode".equals( methodName ) && method.getParameterCount() == 0 ) { - return this.hashCode(); + return hashCode(); } else if ( "toString".equals( methodName ) && method.getParameterCount() == 0 ) { - return String.format( Locale.ROOT, "ThreadLocalSessionContext.TransactionProtectionWrapper[%s]", realSession ); + return String.format( Locale.ROOT, + "ThreadLocalSessionContext.TransactionProtectionWrapper[%s]", + realSession ); } @@ -300,20 +294,21 @@ else if ( "toString".equals( methodName ) && method.getParameterCount() == 0 ) { // If close() is called, guarantee unbind() if ( "close".equals( methodName ) ) { unbind( realSession.getSessionFactory() ); + CURRENT_SESSION_LOGGER.allowingInvocationToProceed(methodName); } else if ( "getStatistics".equals( methodName ) || "isOpen".equals( methodName ) || "getListeners".equals( methodName ) ) { // allow these to go through the real session no matter what - LOG.tracef( "Allowing invocation [%s] to proceed to real session", methodName ); + CURRENT_SESSION_LOGGER.allowingInvocationToProceed(methodName); } else if ( !realSession.isOpen() ) { - // essentially, if the real session is closed allow any - // method call to pass through since the real session - // will complain by throwing an appropriate exception; - // NOTE that allowing close() above has the same basic effect, - // but we capture that there simply to doAfterTransactionCompletion the unbind... - LOG.tracef( "Allowing invocation [%s] to proceed to real (closed) session", methodName ); + // essentially, if the real session is closed, allow any method + // call to pass through since the real session will complain by + // throwing an appropriate exception; note that allowing close() + // above has the same basic effect, but we capture that there + // just to unbind(). + CURRENT_SESSION_LOGGER.allowingInvocationToProceedToClosedSession(methodName); } else if ( realSession.getTransaction().getStatus() != TransactionStatus.ACTIVE ) { // limit the methods available if no transaction is active @@ -326,14 +321,14 @@ else if ( realSession.getTransaction().getStatus() != TransactionStatus.ACTIVE ) || "getSessionFactory".equals( methodName ) || "getJdbcCoordinator".equals( methodName ) || "getTenantIdentifier".equals( methodName ) ) { - LOG.tracef( "Allowing invocation [%s] to proceed to real (non-transacted) session", methodName ); + CURRENT_SESSION_LOGGER.allowingInvocationToProceedToNonTransactedSession(methodName); } else { - throw new HibernateException( "Calling method '" + methodName + "' is not valid without an active transaction (Current status: " + throw new HibernateException( "Calling method '" + methodName + + "' is not valid without an active transaction (Current status: " + realSession.getTransaction().getStatus() + ")" ); } } - LOG.tracef( "Allowing proxy invocation [%s] to proceed to real session", methodName ); return method.invoke( realSession, args ); } catch ( InvocationTargetException e ) { @@ -370,7 +365,7 @@ private void writeObject(ObjectOutputStream oos) throws IOException { @Serial private void readObject(ObjectInputStream ois) throws IOException, ClassNotFoundException { // on the inverse, it makes sense that if a ThreadLocalSessionContext- - // bound session then gets deserialized to go ahead and re-bind it to + // bound session then gets deserialized to go ahead and rebind it to // the ThreadLocalSessionContext session map. ois.defaultReadObject(); realSession.getTransaction().registerSynchronization( buildCleanupSynch() ); diff --git a/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java b/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java index ff7878d729ff..24fced457a7f 100644 --- a/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java +++ b/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java @@ -45,10 +45,6 @@ @Internal public interface CoreMessageLogger extends BasicLogger { - @LogMessage(level = WARN) - @Message(value = "Already session bound on call to bind(); make sure you clean up your sessions", id = 2) - void alreadySessionBound(); - @LogMessage(level = WARN) @Message(value = "Configuration settings with for connection provider '%s' are set, but the connection provider is not on the classpath; these properties will be ignored", id = 22)