HHH-9518 : Exception handling around collection session access needs to be improved

Author: gbadner

hibernate-core/src/main/java/org/hibernate/collection/internal/AbstractPersistentCollection.java

@@ -30,6 +30,8 @@
 import org.hibernate.engine.spi.SessionImplementor;
 import org.hibernate.engine.spi.Status;
 import org.hibernate.engine.spi.TypedValue;
+import org.hibernate.internal.CoreLogging;
+import org.hibernate.internal.CoreMessageLogger;
 import org.hibernate.internal.SessionFactoryRegistry;
 import org.hibernate.internal.util.MarkerObject;
 import org.hibernate.internal.util.collections.EmptyIterator;
@@ -45,15 +47,14 @@
 import org.hibernate.type.Type;
 import org.hibernate.type.UUIDBinaryType;
 import org.hibernate.type.UUIDCharType;
-import org.jboss.logging.Logger;
 
 /**
  * Base class implementing {@link org.hibernate.collection.spi.PersistentCollection}
  *
  * @author Gavin King
  */
 public abstract class AbstractPersistentCollection implements Serializable, PersistentCollection {
-	private static final Logger log = Logger.getLogger( AbstractPersistentCollection.class );
+	private static final CoreMessageLogger LOG = CoreLogging.messageLogger( AbstractPersistentCollection.class );
 
 	private transient SessionImplementor session;
 	private boolean initialized;
@@ -255,7 +256,7 @@ else if ( !session.isConnected() ) {
 					( (Session) session ).close();
 				}
 				catch (Exception e) {
-					log.warn( "Unable to close temporary session used to load lazy collection associated to no session" );
+					LOG.warn( "Unable to close temporary session used to load lazy collection associated to no session" );
 				}
 				session = originalSession;
 			}
@@ -587,6 +588,9 @@ public final boolean unsetSession(SessionImplementor currentSession) {
 			return true;
 		}
 		else {
+			if ( this.session != null ) {
+				LOG.logCannotUnsetUnexpectedSessionInCollection( generateUnexpectedSessionStateMessage( currentSession ) );
+			}
 			return false;
 		}
 	}
@@ -606,28 +610,23 @@ protected void prepareForPossibleLoadingOutsideTransaction() {
 		}
 	}
 
-
 	@Override
 	public final boolean setCurrentSession(SessionImplementor session) throws HibernateException {
 		if ( session == this.session ) {
 			return false;
 		}
 		else {
-			if ( isConnectedToSession() ) {
-				final CollectionEntry ce = session.getPersistenceContext().getCollectionEntry( this );
-				if ( ce == null ) {
+			if ( this.session != null ) {
+				final String msg = generateUnexpectedSessionStateMessage( session );
+				if ( isConnectedToSession() ) {
 					throw new HibernateException(
-							"Illegal attempt to associate a collection with two open sessions"
+							"Illegal attempt to associate a collection with two open sessions. " + msg
 					);
 				}
 				else {
-					throw new HibernateException(
-							"Illegal attempt to associate a collection with two open sessions: " +
-									MessageHelper.collectionInfoString(
-											ce.getLoadedPersister(), this,
-											ce.getLoadedKey(), session
-									)
-					);
+					LOG.logUnexpectedSessionInCollectionNotConnected( msg );
+					this.session = session;
+					return true;
 				}
 			}
 			else {
@@ -637,6 +636,46 @@ public final boolean setCurrentSession(SessionImplementor session) throws Hibern
 		}
 	}
 
+	private String generateUnexpectedSessionStateMessage(SessionImplementor session) {
+		// NOTE: If this.session != null, this.session may be operating on this collection
+		// (e.g., by changing this.role, this.key, or even this.session) in a different thread.
+
+		// Grab the current role and key (it can still get changed by this.session...)
+		// If this collection is connected to this.session, then this.role and this.key should
+		// be consistent with the CollectionEntry in this.session (as long as this.session doesn't
+		// change it). Don't access the CollectionEntry in this.session because that could result
+		// in multi-threaded access to this.session.
+		final String roleCurrent = role;
+		final Serializable keyCurrent = key;
+
+		final StringBuilder sb = new StringBuilder( "Collection : " );
+		if ( roleCurrent != null ) {
+			sb.append( MessageHelper.collectionInfoString( roleCurrent, keyCurrent ) );
+		}
+		else {
+			final CollectionEntry ce = session.getPersistenceContext().getCollectionEntry( this );
+			if ( ce != null ) {
+				sb.append(
+						MessageHelper.collectionInfoString(
+								ce.getLoadedPersister(),
+								this,
+								ce.getLoadedKey(),
+								session
+						)
+				);
+			}
+			else {
+				sb.append( "<unknown>" );
+			}
+		}
+		// only include the collection contents if debug logging
+		if ( LOG.isDebugEnabled() ) {
+			final String collectionContents = wasInitialized() ? toString() : "<uninitialized>";
+			sb.append( "\nCollection contents: [" ).append( collectionContents ).append( "]" );
+		}
+		return sb.toString();
+	}
+
 	@Override
 	public boolean needsRecreate(CollectionPersister persister) {
 		// Workaround for situations like HHH-7072.  If the collection element is a component that consists entirely

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

@@ -1734,4 +1734,12 @@ void cannotResolveNonNullableTransientDependencies(
 
 	@Message(value = "The ClassLoaderService can not be reused. This instance was stopped already.", id = 469)
 	HibernateException usingStoppedClassLoaderService();
+
+	@LogMessage(level = WARN)
+	@Message(value = "An unexpected session is defined for a collection, but the collection is not connected to that session. A persistent collection may only be associated with one session at a time. Overwriting session. %s", id = 470)
+	void logUnexpectedSessionInCollectionNotConnected(String msg);
+
+	@LogMessage(level = WARN)
+	@Message(value = "Cannot unset session in a collection because an unexpected session is defined. A persistent collection may only be associated with one session at a time. %s", id = 471 )
+	void logCannotUnsetUnexpectedSessionInCollection(String msg);
 }