Skip to content

Commit e719661

Browse files
gavinkinggavinking
committed
typesafe logging and cleanups in the (current session) context package
1 parent 0140bad commit e719661

File tree

5 files changed

+104
-55
lines changed

5 files changed

+104
-55
lines changed

‎hibernate-core/src/main/java/org/hibernate/context/internal/CurrentSessionLogging.java‎

Lines changed: 66 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,66 @@
1+
/*
2+
* SPDX-License-Identifier: Apache-2.0
3+
* Copyright Red Hat Inc. and Hibernate Authors
4+
*/
5+
package org.hibernate.context.internal;
6+
7+
import org.hibernate.Internal;
8+
import org.hibernate.internal.log.SubSystemLogging;
9+
10+
import org.jboss.logging.BasicLogger;
11+
import org.jboss.logging.Logger;
12+
import org.jboss.logging.annotations.Cause;
13+
import org.jboss.logging.annotations.LogMessage;
14+
import org.jboss.logging.annotations.Message;
15+
import org.jboss.logging.annotations.MessageLogger;
16+
import org.jboss.logging.annotations.ValidIdRange;
17+
18+
import java.lang.invoke.MethodHandles;
19+
20+
import static org.jboss.logging.Logger.Level.DEBUG;
21+
import static org.jboss.logging.Logger.Level.TRACE;
22+
import static org.jboss.logging.Logger.Level.WARN;
23+
24+
/**
25+
* Sub-system logging related to CurrentSessionContext implementations
26+
*/
27+
@SubSystemLogging(
28+
name = CurrentSessionLogging.NAME,
29+
description = "Logging related to current session context"
30+
)
31+
@MessageLogger(projectCode = "HHH")
32+
@ValidIdRange(min = 90070001, max = 90080000)
33+
@Internal
34+
public interface CurrentSessionLogging extends BasicLogger {
35+
String NAME = SubSystemLogging.BASE + ".current_session";
36+
37+
CurrentSessionLogging CURRENT_SESSION_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), CurrentSessionLogging.class, NAME );
38+
39+
@LogMessage(level = WARN)
40+
@Message(id = 90070001, value = "Session already bound on call to bind(); make sure you clean up your sessions")
41+
void alreadySessionBound();
42+
43+
@LogMessage(level = TRACE)
44+
@Message("Allowing invocation [%s] to proceed to real session")
45+
void allowingInvocationToProceed(String methodName);
46+
47+
@LogMessage(level = TRACE)
48+
@Message("Allowing invocation [%s] to proceed to real (closed) session")
49+
void allowingInvocationToProceedToClosedSession(String methodName);
50+
51+
@LogMessage(level = TRACE)
52+
@Message("Allowing invocation [%s] to proceed to real (non-transacted) session")
53+
void allowingInvocationToProceedToNonTransactedSession(String methodName);
54+
55+
@LogMessage(level = DEBUG)
56+
@Message(id = 90070011, value = "Unable to rollback transaction for orphaned session")
57+
void unableToRollbackTransactionForOrphanedSession(@Cause Throwable t);
58+
59+
@LogMessage(level = DEBUG)
60+
@Message(id = 90070012, value = "Unable to close orphaned session")
61+
void unableToCloseOrphanedSession(@Cause Throwable t);
62+
63+
@LogMessage(level = DEBUG)
64+
@Message(id = 90070013, value = "Unable to release generated current session on failed synchronization registration")
65+
void unableToReleaseGeneratedCurrentSessionOnFailedSynchronizationRegistration(@Cause Throwable t);
66+
}

‎hibernate-core/src/main/java/org/hibernate/context/internal/JTASessionContext.java‎

Lines changed: 2 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -15,8 +15,7 @@
1515
import org.hibernate.context.spi.AbstractCurrentSessionContext;
1616
import org.hibernate.engine.spi.SessionFactoryImplementor;
1717
import org.hibernate.engine.transaction.jta.platform.spi.JtaPlatform;
18-
import org.hibernate.internal.CoreLogging;
19-
import org.hibernate.internal.CoreMessageLogger;
18+
import static org.hibernate.context.internal.CurrentSessionLogging.CURRENT_SESSION_LOGGER;
2019

2120
import org.hibernate.resource.jdbc.spi.PhysicalConnectionHandlingMode;
2221

@@ -44,8 +43,6 @@
4443
*/
4544
public class JTASessionContext extends AbstractCurrentSessionContext {
4645

47-
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( JTASessionContext.class );
48-
4946
private transient final Map<Object, Session> currentSessionMap = new ConcurrentHashMap<>();
5047

5148
/**
@@ -100,7 +97,7 @@ public Session currentSession() throws HibernateException {
10097
currentSession.close();
10198
}
10299
catch ( Throwable e ) {
103-
LOG.debug( "Unable to release generated current-session on failed synchronization registration", e );
100+
CURRENT_SESSION_LOGGER.unableToReleaseGeneratedCurrentSessionOnFailedSynchronizationRegistration(e);
104101
}
105102
throw new HibernateException( "Unable to register cleanup Synchronization with TransactionManager" );
106103
}

‎hibernate-core/src/main/java/org/hibernate/context/internal/ManagedSessionContext.java‎

Lines changed: 7 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -52,14 +52,14 @@ public ManagedSessionContext(SessionFactoryImplementor factory) {
5252

5353
@Override
5454
public Session currentSession() {
55-
final Session current = existingSession( factory() );
55+
final var current = existingSession( factory() );
5656
if ( current == null ) {
5757
throw new HibernateException( "No session currently bound to execution context" );
5858
}
5959
else {
6060
validateExistingSession( current );
61+
return current;
6162
}
62-
return current;
6363
}
6464

6565
/**
@@ -92,7 +92,7 @@ public static Session bind(Session session) {
9292
* @return The bound session if one, else null.
9393
*/
9494
public static Session unbind(SessionFactory factory) {
95-
final Map<SessionFactory,Session> sessionMap = sessionMap();
95+
final var sessionMap = sessionMap();
9696
Session existing = null;
9797
if ( sessionMap != null ) {
9898
existing = sessionMap.remove( factory );
@@ -102,21 +102,16 @@ public static Session unbind(SessionFactory factory) {
102102
}
103103

104104
private static Session existingSession(SessionFactory factory) {
105-
final Map<SessionFactory,Session> sessionMap = sessionMap();
106-
if ( sessionMap == null ) {
107-
return null;
108-
}
109-
else {
110-
return sessionMap.get( factory );
111-
}
105+
final var sessionMap = sessionMap();
106+
return sessionMap == null ? null : sessionMap.get( factory );
112107
}
113108

114109
protected static Map<SessionFactory,Session> sessionMap() {
115110
return sessionMap( false );
116111
}
117112

118113
private static Map<SessionFactory,Session> sessionMap(boolean createMap) {
119-
Map<SessionFactory,Session> sessionMap = CONTEXT_TL.get();
114+
var sessionMap = CONTEXT_TL.get();
120115
if ( sessionMap == null && createMap ) {
121116
sessionMap = new HashMap<>();
122117
CONTEXT_TL.set( sessionMap );
@@ -125,7 +120,7 @@ private static Map<SessionFactory,Session> sessionMap(boolean createMap) {
125120
}
126121

127122
private static void doCleanup() {
128-
final Map<SessionFactory,Session> sessionMap = sessionMap( false );
123+
final var sessionMap = sessionMap( false );
129124
if ( sessionMap != null ) {
130125
if ( sessionMap.isEmpty() ) {
131126
CONTEXT_TL.remove();

‎hibernate-core/src/main/java/org/hibernate/context/internal/ThreadLocalSessionContext.java‎

Lines changed: 29 additions & 34 deletions
Original file line numberDiff line numberDiff line change
@@ -28,8 +28,7 @@
2828
import org.hibernate.engine.spi.SessionFactoryImplementor;
2929
import org.hibernate.engine.spi.SessionImplementor;
3030
import org.hibernate.event.spi.EventSource;
31-
import org.hibernate.internal.CoreLogging;
32-
import org.hibernate.internal.CoreMessageLogger;
31+
import static org.hibernate.context.internal.CurrentSessionLogging.CURRENT_SESSION_LOGGER;
3332
import org.hibernate.resource.jdbc.spi.PhysicalConnectionHandlingMode;
3433
import org.hibernate.resource.transaction.spi.TransactionStatus;
3534

@@ -58,8 +57,6 @@
5857
*/
5958
public class ThreadLocalSessionContext extends AbstractCurrentSessionContext {
6059

61-
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( ThreadLocalSessionContext.class );
62-
6360
private static final Class<?>[] SESSION_PROXY_INTERFACES = new Class<?>[] {
6461
Session.class,
6562
SessionImplementor.class,
@@ -167,8 +164,8 @@ protected PhysicalConnectionHandlingMode getConnectionHandlingMode() {
167164
}
168165

169166
protected Session wrap(Session session) {
170-
final TransactionProtectionWrapper wrapper = new TransactionProtectionWrapper( session );
171-
final Session wrapped = (Session) Proxy.newProxyInstance(
167+
final var wrapper = new TransactionProtectionWrapper( session );
168+
final var wrapped = (Session) Proxy.newProxyInstance(
172169
Session.class.getClassLoader(),
173170
SESSION_PROXY_INTERFACES,
174171
wrapper
@@ -189,25 +186,20 @@ public static void bind(Session session) {
189186

190187
private static void terminateOrphanedSession(Session orphan) {
191188
if ( orphan != null ) {
192-
LOG.alreadySessionBound();
193-
try {
194-
final Transaction orphanTransaction = orphan.getTransaction();
189+
CURRENT_SESSION_LOGGER.alreadySessionBound();
190+
try ( orphan ) {
191+
final var orphanTransaction = orphan.getTransaction();
195192
if ( orphanTransaction != null && orphanTransaction.getStatus() == TransactionStatus.ACTIVE ) {
196193
try {
197194
orphanTransaction.rollback();
198195
}
199-
catch( Throwable t ) {
200-
LOG.debug( "Unable to rollback transaction for orphaned session", t );
196+
catch (Throwable t) {
197+
CURRENT_SESSION_LOGGER.unableToRollbackTransactionForOrphanedSession( t );
201198
}
202199
}
203200
}
204-
finally {
205-
try {
206-
orphan.close();
207-
}
208-
catch( Throwable t ) {
209-
LOG.debug( "Unable to close orphaned session", t );
210-
}
201+
catch (Throwable t) {
202+
CURRENT_SESSION_LOGGER.unableToCloseOrphanedSession( t );
211203
}
212204

213205
}
@@ -232,13 +224,13 @@ protected static Map<SessionFactory,Session> sessionMap() {
232224
}
233225

234226
private static void doBind(Session session, SessionFactory factory) {
235-
Session orphanedPreviousSession = sessionMap().put( factory, session );
227+
final var orphanedPreviousSession = sessionMap().put( factory, session );
236228
terminateOrphanedSession( orphanedPreviousSession );
237229
}
238230

239231
private static Session doUnbind(SessionFactory factory) {
240-
final Map<SessionFactory, Session> sessionMap = sessionMap();
241-
final Session session = sessionMap.remove( factory );
232+
final var sessionMap = sessionMap();
233+
final var session = sessionMap.remove( factory );
242234
if ( sessionMap.isEmpty() ) {
243235
//Do not use set(null) as it would prevent the initialValue to be invoked again in case of need.
244236
CONTEXT_TL.remove();
@@ -288,10 +280,12 @@ public Object invoke(Object proxy, Method method, Object[] args) throws Throwabl
288280
return this.equals( Proxy.getInvocationHandler( args[0] ) );
289281
}
290282
else if ( "hashCode".equals( methodName ) && method.getParameterCount() == 0 ) {
291-
return this.hashCode();
283+
return hashCode();
292284
}
293285
else if ( "toString".equals( methodName ) && method.getParameterCount() == 0 ) {
294-
return String.format( Locale.ROOT, "ThreadLocalSessionContext.TransactionProtectionWrapper[%s]", realSession );
286+
return String.format( Locale.ROOT,
287+
"ThreadLocalSessionContext.TransactionProtectionWrapper[%s]",
288+
realSession );
295289
}
296290

297291

@@ -300,20 +294,21 @@ else if ( "toString".equals( methodName ) && method.getParameterCount() == 0 ) {
300294
// If close() is called, guarantee unbind()
301295
if ( "close".equals( methodName ) ) {
302296
unbind( realSession.getSessionFactory() );
297+
CURRENT_SESSION_LOGGER.allowingInvocationToProceed(methodName);
303298
}
304299
else if ( "getStatistics".equals( methodName )
305300
|| "isOpen".equals( methodName )
306301
|| "getListeners".equals( methodName ) ) {
307302
// allow these to go through the real session no matter what
308-
LOG.tracef( "Allowing invocation [%s] to proceed to real session", methodName );
303+
CURRENT_SESSION_LOGGER.allowingInvocationToProceed(methodName);
309304
}
310305
else if ( !realSession.isOpen() ) {
311-
// essentially, if the real session is closed allow any
312-
// method call to pass through since the real session
313-
// will complain by throwing an appropriate exception;
314-
// NOTE that allowing close() above has the same basic effect,
315-
// but we capture that there simply to doAfterTransactionCompletion the unbind...
316-
LOG.tracef( "Allowing invocation [%s] to proceed to real (closed) session", methodName );
306+
// essentially, if the real session is closed, allow any method
307+
// call to pass through since the real session will complain by
308+
// throwing an appropriate exception; note that allowing close()
309+
// above has the same basic effect, but we capture that there
310+
// just to unbind().
311+
CURRENT_SESSION_LOGGER.allowingInvocationToProceedToClosedSession(methodName);
317312
}
318313
else if ( realSession.getTransaction().getStatus() != TransactionStatus.ACTIVE ) {
319314
// limit the methods available if no transaction is active
@@ -326,14 +321,14 @@ else if ( realSession.getTransaction().getStatus() != TransactionStatus.ACTIVE )
326321
|| "getSessionFactory".equals( methodName )
327322
|| "getJdbcCoordinator".equals( methodName )
328323
|| "getTenantIdentifier".equals( methodName ) ) {
329-
LOG.tracef( "Allowing invocation [%s] to proceed to real (non-transacted) session", methodName );
324+
CURRENT_SESSION_LOGGER.allowingInvocationToProceedToNonTransactedSession(methodName);
330325
}
331326
else {
332-
throw new HibernateException( "Calling method '" + methodName + "' is not valid without an active transaction (Current status: "
327+
throw new HibernateException( "Calling method '" + methodName
328+
+ "' is not valid without an active transaction (Current status: "
333329
+ realSession.getTransaction().getStatus() + ")" );
334330
}
335331
}
336-
LOG.tracef( "Allowing proxy invocation [%s] to proceed to real session", methodName );
337332
return method.invoke( realSession, args );
338333
}
339334
catch ( InvocationTargetException e ) {
@@ -370,7 +365,7 @@ private void writeObject(ObjectOutputStream oos) throws IOException {
370365
@Serial
371366
private void readObject(ObjectInputStream ois) throws IOException, ClassNotFoundException {
372367
// on the inverse, it makes sense that if a ThreadLocalSessionContext-
373-
// bound session then gets deserialized to go ahead and re-bind it to
368+
// bound session then gets deserialized to go ahead and rebind it to
374369
// the ThreadLocalSessionContext session map.
375370
ois.defaultReadObject();
376371
realSession.getTransaction().registerSynchronization( buildCleanupSynch() );

‎hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java‎

Lines changed: 0 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -45,10 +45,6 @@
4545
@Internal
4646
public interface CoreMessageLogger extends BasicLogger {
4747

48-
@LogMessage(level = WARN)
49-
@Message(value = "Already session bound on call to bind(); make sure you clean up your sessions", id = 2)
50-
void alreadySessionBound();
51-
5248
@LogMessage(level = WARN)
5349
@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",
5450
id = 22)

0 commit comments

Comments
 (0)