Skip to content

Commit

Permalink
HHH-7359 Added a new method to MessageHelper to intelligently handle
Browse files Browse the repository at this point in the history 
property-ref issues in logging.  Rolled it out to as many MessageHelper
users as possible.
  • Loading branch information
brmeyer committed Oct 25, 2012
1 parent 9968ce3 commit 30ea167
Show file tree
Hide file tree
Showing 13 changed files with 110 additions and 51 deletions.
3 changes: 2 additions & 1 deletion hibernate-core/src/main/java/org/hibernate/action/internal/CollectionUpdateAction.java
View file
Expand Up @@ -73,7 +73,8 @@ else if ( collection.needsRecreate(persister) ) {
if (affectedByFilters) {
throw new HibernateException(
"cannot recreate collection while filter is enabled: " +
MessageHelper.collectionInfoString( persister, id, persister.getFactory() )
MessageHelper.collectionInfoString(persister, collection,
id, session )
);
}
if ( !emptySnapshot ) persister.remove( id, session );
Expand Down
5 changes: 2 additions & 3 deletions ...te-core/src/main/java/org/hibernate/collection/internal/AbstractPersistentCollection.java
View file
Expand Up @@ -643,9 +643,8 @@ public final boolean setCurrentSession(SessionImplementor session) throws Hibern
throw new HibernateException(
"Illegal attempt to associate a collection with two open sessions: " +
MessageHelper.collectionInfoString(
ce.getLoadedPersister(),
ce.getLoadedKey(),
session.getFactory()
ce.getLoadedPersister(), this,
ce.getLoadedKey(), session
)
);
}
Expand Down
23 changes: 11 additions & 12 deletions hibernate-core/src/main/java/org/hibernate/engine/internal/Collections.java
View file
Expand Up @@ -25,8 +25,6 @@

import java.io.Serializable;

import org.jboss.logging.Logger;

import org.hibernate.AssertionFailure;
import org.hibernate.HibernateException;
import org.hibernate.collection.spi.PersistentCollection;
Expand All @@ -41,6 +39,7 @@
import org.hibernate.persister.collection.CollectionPersister;
import org.hibernate.pretty.MessageHelper;
import org.hibernate.type.CollectionType;
import org.jboss.logging.Logger;

/**
* Implements book-keeping for the collection persistence by reachability algorithm
Expand Down Expand Up @@ -76,10 +75,8 @@ private static void processDereferencedCollection(PersistentCollection coll, Ses
if ( LOG.isDebugEnabled() && loadedPersister != null ) {
LOG.debugf(
"Collection dereferenced: %s",
MessageHelper.collectionInfoString(
loadedPersister,
entry.getLoadedKey(),
session.getFactory()
MessageHelper.collectionInfoString( loadedPersister,
coll, entry.getLoadedKey(), session
)
);
}
Expand Down Expand Up @@ -135,7 +132,9 @@ private static void processNeverReferencedCollection(PersistentCollection coll,

if ( LOG.isDebugEnabled() ) {
LOG.debugf( "Found collection with unloaded owner: %s",
MessageHelper.collectionInfoString( entry.getLoadedPersister(), entry.getLoadedKey(), session.getFactory() ) );
MessageHelper.collectionInfoString(
entry.getLoadedPersister(), coll,
entry.getLoadedKey(), session ) );
}

entry.setCurrentPersister( entry.getLoadedPersister() );
Expand Down Expand Up @@ -189,13 +188,13 @@ public static void processReachableCollection(

if (LOG.isDebugEnabled()) {
if (collection.wasInitialized()) LOG.debugf("Collection found: %s, was: %s (initialized)",
MessageHelper.collectionInfoString(persister, ce.getCurrentKey(), factory),
MessageHelper.collectionInfoString(ce.getLoadedPersister(),
MessageHelper.collectionInfoString(persister, collection, ce.getCurrentKey(), session),
MessageHelper.collectionInfoString(ce.getLoadedPersister(), collection,
ce.getLoadedKey(),
factory));
session));
else LOG.debugf("Collection found: %s, was: %s (uninitialized)",
MessageHelper.collectionInfoString(persister, ce.getCurrentKey(), factory),
MessageHelper.collectionInfoString(ce.getLoadedPersister(), ce.getLoadedKey(), factory));
MessageHelper.collectionInfoString(persister, collection, ce.getCurrentKey(), session),
MessageHelper.collectionInfoString(ce.getLoadedPersister(), collection, ce.getLoadedKey(), session));
}

prepareCollectionForUpdate( collection, ce, factory );
Expand Down
9 changes: 4 additions & 5 deletions ...rnate-core/src/main/java/org/hibernate/engine/loading/internal/CollectionLoadContext.java
View file
Expand Up @@ -31,8 +31,6 @@
import java.util.List;
import java.util.Set;

import org.jboss.logging.Logger;

import org.hibernate.CacheMode;
import org.hibernate.EntityMode;
import org.hibernate.HibernateException;
Expand All @@ -47,6 +45,7 @@
import org.hibernate.internal.CoreMessageLogger;
import org.hibernate.persister.collection.CollectionPersister;
import org.hibernate.pretty.MessageHelper;
import org.jboss.logging.Logger;

/**
* Represents state associated with the processing of a given {@link ResultSet}
Expand Down Expand Up @@ -265,7 +264,7 @@ private void endLoadingCollection(LoadingCollectionEntry lce, CollectionPersiste
if ( LOG.isDebugEnabled() ) {
LOG.debugf(
"Collection fully initialized: %s",
MessageHelper.collectionInfoString(persister, lce.getKey(), session.getFactory())
MessageHelper.collectionInfoString(persister, lce.getCollection(), lce.getKey(), session)
);
}
if ( session.getFactory().getStatistics().isStatisticsEnabled() ) {
Expand All @@ -284,7 +283,7 @@ private void addCollectionToCache(LoadingCollectionEntry lce, CollectionPersiste
final SessionFactoryImplementor factory = session.getFactory();

if ( LOG.isDebugEnabled() ) {
LOG.debugf( "Caching collection: %s", MessageHelper.collectionInfoString( persister, lce.getKey(), factory ) );
LOG.debugf( "Caching collection: %s", MessageHelper.collectionInfoString( persister, lce.getCollection(), lce.getKey(), session ) );
}

if ( !session.getEnabledFilters().isEmpty() && persister.isAffectedByEnabledFilters( session ) ) {
Expand Down Expand Up @@ -317,7 +316,7 @@ private void addCollectionToCache(LoadingCollectionEntry lce, CollectionPersiste
if ( collectionOwner == null ) {
throw new HibernateException(
"Unable to resolve owner of loading collection [" +
MessageHelper.collectionInfoString( persister, lce.getKey(), factory ) +
MessageHelper.collectionInfoString( persister, lce.getCollection(), lce.getKey(), session ) +
"] for second level caching"
);
}
Expand Down
5 changes: 0 additions & 5 deletions hibernate-core/src/main/java/org/hibernate/engine/loading/internal/LoadContexts.java
View file
Expand Up @@ -201,11 +201,6 @@ public PersistentCollection locateLoadingCollection(CollectionPersister persiste
}
return lce.getCollection();
}
// TODO : should really move this log statement to CollectionType, where this is used from...
if ( LOG.isTraceEnabled() ) {
LOG.tracef( "Creating collection wrapper: %s",
MessageHelper.collectionInfoString( persister, ownerKey, getSession().getFactory() ) );
}
return null;
}

Expand Down
6 changes: 2 additions & 4 deletions .../src/main/java/org/hibernate/event/internal/DefaultInitializeCollectionEventListener.java
View file
Expand Up @@ -25,8 +25,6 @@

import java.io.Serializable;

import org.jboss.logging.Logger;

import org.hibernate.HibernateException;
import org.hibernate.cache.spi.CacheKey;
import org.hibernate.cache.spi.entry.CollectionCacheEntry;
Expand All @@ -40,6 +38,7 @@
import org.hibernate.internal.CoreMessageLogger;
import org.hibernate.persister.collection.CollectionPersister;
import org.hibernate.pretty.MessageHelper;
import org.jboss.logging.Logger;

/**
* @author Gavin King
Expand All @@ -62,8 +61,7 @@ public void onInitializeCollection(InitializeCollectionEvent event)
if ( !collection.wasInitialized() ) {
if ( LOG.isTraceEnabled() ) {
LOG.tracev( "Initializing collection {0}",
MessageHelper.collectionInfoString( ce.getLoadedPersister(), ce.getLoadedKey(),
source.getFactory() ) );
MessageHelper.collectionInfoString( ce.getLoadedPersister(), collection, ce.getLoadedKey(), source ) );
}

LOG.trace( "Checking second-level cache" );
Expand Down
3 changes: 2 additions & 1 deletion hibernate-core/src/main/java/org/hibernate/event/internal/EvictVisitor.java
View file
Expand Up @@ -79,8 +79,9 @@ private void evictCollection(PersistentCollection collection) {
if ( LOG.isDebugEnabled() ) {
LOG.debugf( "Evicting collection: %s",
MessageHelper.collectionInfoString( ce.getLoadedPersister(),
collection,
ce.getLoadedKey(),
getSession().getFactory() ) );
getSession() ) );
}
if ( ce.getLoadedPersister() != null && ce.getLoadedKey() != null ) {
//TODO: is this 100% correct?
Expand Down
12 changes: 6 additions & 6 deletions ...te-core/src/main/java/org/hibernate/persister/collection/AbstractCollectionPersister.java
View file
Expand Up @@ -1203,7 +1203,7 @@ public void recreate(PersistentCollection collection, Serializable id, SessionIm

if ( LOG.isDebugEnabled() ) {
LOG.debugf( "Inserting collection: %s",
MessageHelper.collectionInfoString( this, id, getFactory() ) );
MessageHelper.collectionInfoString( this, collection, id, session ) );
}

try {
Expand Down Expand Up @@ -1296,7 +1296,7 @@ public void recreate(PersistentCollection collection, Serializable id, SessionIm
throw sqlExceptionHelper.convert(
sqle,
"could not insert collection: " +
MessageHelper.collectionInfoString( this, id, getFactory() ),
MessageHelper.collectionInfoString( this, collection, id, session ),
getSQLInsertRowString()
);
}
Expand All @@ -1316,7 +1316,7 @@ public void deleteRows(PersistentCollection collection, Serializable id, Session

if ( LOG.isDebugEnabled() ) {
LOG.debugf( "Deleting rows of collection: %s",
MessageHelper.collectionInfoString( this, id, getFactory() ) );
MessageHelper.collectionInfoString( this, collection, id, session ) );
}

boolean deleteByIndex = !isOneToMany() && hasIndex && !indexContainsFormula;
Expand Down Expand Up @@ -1404,7 +1404,7 @@ public void deleteRows(PersistentCollection collection, Serializable id, Session
throw sqlExceptionHelper.convert(
sqle,
"could not delete collection rows: " +
MessageHelper.collectionInfoString( this, id, getFactory() ),
MessageHelper.collectionInfoString( this, collection, id, session ),
getSQLDeleteRowString()
);
}
Expand All @@ -1423,7 +1423,7 @@ public void insertRows(PersistentCollection collection, Serializable id, Session
if ( !isInverse && isRowInsertEnabled() ) {

if ( LOG.isDebugEnabled() ) LOG.debugf( "Inserting rows of collection: %s",
MessageHelper.collectionInfoString( this, id, getFactory() ) );
MessageHelper.collectionInfoString( this, collection, id, session ) );

try {
// insert all the new entries
Expand Down Expand Up @@ -1503,7 +1503,7 @@ public void insertRows(PersistentCollection collection, Serializable id, Session
throw sqlExceptionHelper.convert(
sqle,
"could not insert collection rows: " +
MessageHelper.collectionInfoString( this, id, getFactory() ),
MessageHelper.collectionInfoString( this, collection, id, session ),
getSQLInsertRowString()
);
}
Expand Down
2 changes: 1 addition & 1 deletion ...rnate-core/src/main/java/org/hibernate/persister/collection/BasicCollectionPersister.java
View file
Expand Up @@ -284,7 +284,7 @@ protected int doUpdateRows(Serializable id, PersistentCollection collection, Ses
catch ( SQLException sqle ) {
throw getSQLExceptionHelper().convert(
sqle,
"could not update collection rows: " + MessageHelper.collectionInfoString( this, id, getFactory() ),
"could not update collection rows: " + MessageHelper.collectionInfoString( this, collection, id, session ),
getSQLUpdateRowString()
);
}
Expand Down
2 changes: 1 addition & 1 deletion hibernate-core/src/main/java/org/hibernate/persister/collection/OneToManyPersister.java
View file
Expand Up @@ -327,7 +327,7 @@ protected int doUpdateRows(Serializable id, PersistentCollection collection, Ses
throw getFactory().getSQLExceptionHelper().convert(
sqle,
"could not update collection rows: " +
MessageHelper.collectionInfoString( this, id, getFactory() ),
MessageHelper.collectionInfoString( this, collection, id, session ),
getSQLInsertRowString()
);
}
Expand Down
58 changes: 54 additions & 4 deletions hibernate-core/src/main/java/org/hibernate/pretty/MessageHelper.java
View file
Expand Up @@ -25,7 +25,9 @@
package org.hibernate.pretty;
import java.io.Serializable;

import org.hibernate.collection.spi.PersistentCollection;
import org.hibernate.engine.spi.SessionFactoryImplementor;
import org.hibernate.engine.spi.SessionImplementor;
import org.hibernate.persister.collection.CollectionPersister;
import org.hibernate.persister.entity.EntityPersister;
import org.hibernate.type.Type;
Expand Down Expand Up @@ -234,7 +236,52 @@ public static String infoString(String entityName, String propertyName, Object k


// collections ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

/**
* Generate an info message string relating to a particular managed
* collection. Attempts to intelligently handle property-refs issues
* where the collection key is not the same as the owner key.
*
* @param persister The persister for the collection
* @param collection The collection itself
* @param collectionKey The collection key
* @param session The session
* @return An info string, in the form [Foo.bars#1]
*/
public static String collectionInfoString(
CollectionPersister persister,
PersistentCollection collection,
Serializable collectionKey,
SessionImplementor session ) {

StringBuilder s = new StringBuilder();
s.append( '[' );
if ( persister == null ) {
s.append( "<unreferenced>" );
}
else {
s.append( persister.getRole() );
s.append( '#' );

Type ownerIdentifierType = persister.getOwnerEntityPersister()
.getIdentifierType();
Serializable ownerKey;
// TODO: Is it redundant to attempt to use the collectionKey,
// or is always using the owner id sufficient?
if ( collectionKey.getClass().isAssignableFrom(
ownerIdentifierType.getReturnedClass() ) ) {
ownerKey = collectionKey;
} else {
ownerKey = session.getPersistenceContext()
.getEntry( collection.getOwner() ).getId();
}
s.append( ownerIdentifierType.toLoggableString(
ownerKey, session.getFactory() ) );
}
s.append( ']' );

return s.toString();
}

/**
* Generate an info message string relating to a series of managed
Expand Down Expand Up @@ -315,13 +362,16 @@ private static void addIdToCollectionInfoString(
// Also need to check that the expected identifier type matches
// the given ID. Due to property-ref keys, the collection key
// may not be the owner key.
Type identifierType = persister.getOwnerEntityPersister()
Type ownerIdentifierType = persister.getOwnerEntityPersister()
.getIdentifierType();
if ( id.getClass().isAssignableFrom(
identifierType.getReturnedClass() ) ) {
s.append( identifierType.toLoggableString( id, factory ) );
ownerIdentifierType.getReturnedClass() ) ) {
s.append( ownerIdentifierType.toLoggableString( id, factory ) );
} else {
// TODO: This is a crappy backup if a property-ref is used.
// If the reference is an object w/o toString(), this isn't going to work.
s.append( id.toString() );
}
// TODO: If the collection key was not the owner key,
}

/**
Expand Down
13 changes: 12 additions & 1 deletion hibernate-core/src/main/java/org/hibernate/type/CollectionType.java
View file
Expand Up @@ -35,7 +35,6 @@

import org.dom4j.Element;
import org.dom4j.Node;

import org.hibernate.EntityMode;
import org.hibernate.Hibernate;
import org.hibernate.HibernateException;
Expand All @@ -47,15 +46,18 @@
import org.hibernate.engine.spi.PersistenceContext;
import org.hibernate.engine.spi.SessionFactoryImplementor;
import org.hibernate.engine.spi.SessionImplementor;
import org.hibernate.internal.CoreMessageLogger;
import org.hibernate.internal.util.MarkerObject;
import org.hibernate.internal.util.collections.ArrayHelper;
import org.hibernate.metamodel.relational.Size;
import org.hibernate.persister.collection.CollectionPersister;
import org.hibernate.persister.collection.QueryableCollection;
import org.hibernate.persister.entity.EntityPersister;
import org.hibernate.persister.entity.Joinable;
import org.hibernate.pretty.MessageHelper;
import org.hibernate.proxy.HibernateProxy;
import org.hibernate.proxy.LazyInitializer;
import org.jboss.logging.Logger;

/**
* A type that handles Hibernate <tt>PersistentCollection</tt>s (including arrays).
Expand All @@ -64,6 +66,8 @@
*/
public abstract class CollectionType extends AbstractType implements AssociationType {

private static final CoreMessageLogger LOG = Logger.getMessageLogger(CoreMessageLogger.class, CollectionType.class.getName());

private static final Object NOT_NULL_COLLECTION = new MarkerObject( "NOT NULL COLLECTION" );
public static final Object UNFETCHED_COLLECTION = new MarkerObject( "UNFETCHED COLLECTION" );

Expand Down Expand Up @@ -622,6 +626,7 @@ public Object getCollection(Serializable key, SessionImplementor session, Object
if ( collection == null ) {
// create a new collection wrapper, to be initialized later
collection = instantiate( session, persister, key );

collection.setOwner(owner);

persistenceContext.addUninitializedCollection( persister, collection, key );
Expand All @@ -640,6 +645,12 @@ else if ( !persister.isLazy() ) {

}

if ( LOG.isTraceEnabled() ) {
LOG.tracef( "Created collection wrapper: %s",
MessageHelper.collectionInfoString( persister, collection,
key, session ) );
}

}

collection.setOwner(owner);
Expand Down

0 comments on commit 30ea167

Please sign in to comment.