From aa6e46eb79d0b4346118ccff6b1eda1827d5236a Mon Sep 17 00:00:00 2001 From: Gavin King Date: Fri, 13 Dec 2024 00:48:10 +0100 Subject: [PATCH] get rid of use of tracev() - at most one of these is worse without it - there was even a performance bug due to missing isTraceEnabled() --- .../internal/AbstractSaveEventListener.java | 4 +- .../internal/DefaultDeleteEventListener.java | 10 ++--- .../internal/DefaultEvictEventListener.java | 2 +- .../DefaultFlushEntityEventListener.java | 30 +++++---------- ...aultInitializeCollectionEventListener.java | 6 +-- .../internal/DefaultLoadEventListener.java | 37 +++++++------------ .../internal/DefaultLockEventListener.java | 5 +-- .../internal/DefaultRefreshEventListener.java | 10 +---- .../DefaultReplicateEventListener.java | 10 ++--- .../DefaultResolveNaturalIdEventListener.java | 26 ++++--------- .../hibernate/event/internal/EntityState.java | 8 ++-- .../event/internal/ReattachVisitor.java | 9 ++--- .../hibernate/event/internal/WrapVisitor.java | 2 +- 13 files changed, 54 insertions(+), 105 deletions(-) diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/AbstractSaveEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/AbstractSaveEventListener.java index 0541961b31..5ae62d77bc 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/AbstractSaveEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/AbstractSaveEventListener.java @@ -160,7 +160,7 @@ public abstract class AbstractSaveEventListener implements CallbackRegistryCo if ( LOG.isDebugEnabled() ) { // TODO: define toString()s for generators LOG.debugf( - "Generated identifier: %s, using strategy: %s", + "Generated identifier [%s] using generator '%s'", persister.getIdentifierType().toLoggableString( id, source.getFactory() ), generator.getClass().getName() ); @@ -210,7 +210,7 @@ public abstract class AbstractSaveEventListener implements CallbackRegistryCo } if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Saving {0}", infoString( persister, id, source.getFactory() ) ); + LOG.trace( "Saving " + infoString( persister, id, source.getFactory() ) ); } final EntityKey key = useIdentityColumn ? null : entityKey( id, persister, source ); diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultDeleteEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultDeleteEventListener.java index 59b253f7fa..581e951cf9 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultDeleteEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultDeleteEventListener.java @@ -38,7 +38,6 @@ import org.hibernate.jpa.event.spi.CallbackType; import org.hibernate.metamodel.spi.MappingMetamodelImplementor; import org.hibernate.persister.collection.CollectionPersister; import org.hibernate.persister.entity.EntityPersister; -import org.hibernate.pretty.MessageHelper; import org.hibernate.property.access.internal.PropertyAccessStrategyBackRefImpl; import org.hibernate.proxy.LazyInitializer; import org.hibernate.type.CollectionType; @@ -47,6 +46,7 @@ import org.hibernate.type.Type; import org.hibernate.type.TypeHelper; import static org.hibernate.engine.internal.Collections.skipRemoval; +import static org.hibernate.pretty.MessageHelper.infoString; import static org.hibernate.proxy.HibernateProxy.extractLazyInitializer; /** @@ -134,8 +134,7 @@ public class DefaultDeleteEventListener implements DeleteEventListener, Callback } } else if ( type instanceof ComponentType componentType ) { - final Type[] subtypes = componentType.getSubtypes(); - for ( Type subtype : subtypes ) { + for ( Type subtype : componentType.getSubtypes() ) { deleteOwnedCollections( subtype, key, session ); } } @@ -367,10 +366,7 @@ public class DefaultDeleteEventListener implements DeleteEventListener, Callback final DeleteContext transientEntities) { if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Deleting {0}", - MessageHelper.infoString( persister, entityEntry.getId(), session.getFactory() ) - ); + LOG.trace( "Deleting " + infoString( persister, entityEntry.getId(), session.getFactory() ) ); } final PersistenceContext persistenceContext = session.getPersistenceContextInternal(); diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultEvictEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultEvictEventListener.java index 4416632348..1cf47636bd 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultEvictEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultEvictEventListener.java @@ -109,7 +109,7 @@ public class DefaultEvictEventListener implements EvictEventListener { final EventSource session) throws HibernateException { if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Evicting {0}", infoString( persister ) ); + LOG.trace( "Evicting " + infoString( persister ) ); } final PersistenceContext persistenceContext = session.getPersistenceContextInternal(); diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultFlushEntityEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultFlushEntityEventListener.java index c613d64966..8316663ccc 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultFlushEntityEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultFlushEntityEventListener.java @@ -292,31 +292,20 @@ public class DefaultFlushEntityEventListener implements FlushEntityEventListener private static void logScheduleUpdate(EntityEntry entry, SessionFactoryImplementor factory, Status status, EntityPersister persister) { if ( LOG.isTraceEnabled() ) { + final String info = infoString( persister, entry.getId(), factory ); if ( status == Status.DELETED ) { if ( !persister.isMutable() ) { - LOG.tracev( - "Updating immutable, deleted entity: {0}", - infoString(persister, entry.getId(), factory) - ); + LOG.trace( "Updating immutable, deleted entity: " + info ); } else if ( !entry.isModifiableEntity() ) { - LOG.tracev( - "Updating non-modifiable, deleted entity: {0}", - infoString(persister, entry.getId(), factory) - ); + LOG.trace( "Updating non-modifiable, deleted entity: " + info ); } else { - LOG.tracev( - "Updating deleted entity: {0}", - infoString(persister, entry.getId(), factory) - ); + LOG.trace( "Updating deleted entity: " + info ); } } else { - LOG.tracev( - "Updating entity: {0}", - infoString(persister, entry.getId(), factory) - ); + LOG.trace( "Updating entity: " + info ); } } } @@ -681,11 +670,10 @@ public class DefaultFlushEntityEventListener implements FlushEntityEventListener for ( int i = 0; i < dirtyProperties.length; i++ ) { dirtyPropertyNames[i] = allPropertyNames[dirtyProperties[i]]; } - LOG.tracev( - "Found dirty properties [{0}] : {1}", - infoString( persister.getEntityName(), entry.getId() ), - Arrays.toString( dirtyPropertyNames ) - ); + if ( LOG.isTraceEnabled() ) { + LOG.trace( "Found dirty properties [" + infoString( persister.getEntityName(), entry.getId() ) + + "] : "+ Arrays.toString( dirtyPropertyNames ) ); + } } } diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultInitializeCollectionEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultInitializeCollectionEventListener.java index 3e1d533909..a1bfb92baf 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultInitializeCollectionEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultInitializeCollectionEventListener.java @@ -47,10 +47,8 @@ public class DefaultInitializeCollectionEventListener implements InitializeColle final CollectionPersister loadedPersister = ce.getLoadedPersister(); final Object loadedKey = ce.getLoadedKey(); if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Initializing collection {0}", - collectionInfoString( loadedPersister, collection, loadedKey, source ) - ); + LOG.trace( "Initializing collection " + + collectionInfoString( loadedPersister, collection, loadedKey, source ) ); LOG.trace( "Checking second-level cache" ); } diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLoadEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLoadEventListener.java index bd2695271d..94e1b9b99c 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLoadEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLoadEventListener.java @@ -226,10 +226,7 @@ public class DefaultLoadEventListener implements LoadEventListener { */ private Object proxyOrLoad(LoadEvent event, EntityPersister persister, EntityKey keyToLoad, LoadType options) { if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Loading entity: {0}", - infoString( persister, event.getEntityId(), persister.getFactory() ) - ); + LOG.trace( "Loading entity: " + infoString( persister, event.getEntityId(), persister.getFactory() ) ); } if ( hasBytecodeProxy( persister, options ) ) { return loadWithBytecodeProxy( event, persister, keyToLoad, options ); @@ -515,10 +512,7 @@ public class DefaultLoadEventListener implements LoadEventListener { final EventSource session = event.getSession(); if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Attempting to resolve: {0}", - infoString( persister, event.getEntityId(), event.getFactory() ) - ); + LOG.trace( "Attempting to resolve: " + infoString( persister, event.getEntityId(), event.getFactory() ) ); } if ( session.getPersistenceContextInternal().containsDeletedUnloadedEntityKey( keyToLoad ) ) { @@ -547,8 +541,8 @@ public class DefaultLoadEventListener implements LoadEventListener { if ( isPersistentAttributeInterceptable( entity ) ) { final PersistentAttributeInterceptable interceptable = asPersistentAttributeInterceptable( entity ); final PersistentAttributeInterceptor interceptor = interceptable.$$_hibernate_getInterceptor(); - if ( interceptor instanceof EnhancementAsProxyLazinessInterceptor ) { - ( (EnhancementAsProxyLazinessInterceptor) interceptor ).forceInitialize( entity, null ); + if ( interceptor instanceof EnhancementAsProxyLazinessInterceptor lazinessInterceptor ) { + lazinessInterceptor.forceInitialize( entity, null ); } } } @@ -568,23 +562,15 @@ public class DefaultLoadEventListener implements LoadEventListener { private Object loadFromCacheOrDatasource(LoadEvent event, EntityPersister persister, EntityKey keyToLoad) { final Object entity = CacheEntityLoaderHelper.INSTANCE.loadFromSecondLevelCache( event, persister, keyToLoad ); - if ( entity != null ) { - if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Resolved object in second-level cache: {0}", - infoString( persister, event.getEntityId(), event.getFactory() ) - ); - } - return entity; + if ( entity == null ) { + return loadFromDatasource( event, persister ); } else { if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Object not resolved in any cache: {0}", - infoString( persister, event.getEntityId(), event.getFactory() ) - ); + LOG.trace( "Resolved entity in second-level cache: " + + infoString( persister, event.getEntityId(), event.getFactory() ) ); } - return loadFromDatasource( event, persister ); + return entity; } } @@ -598,6 +584,11 @@ public class DefaultLoadEventListener implements LoadEventListener { * @return The object loaded from the datasource, or null if not found. */ protected Object loadFromDatasource(final LoadEvent event, final EntityPersister persister) { + if ( LOG.isTraceEnabled() ) { + LOG.trace( "Entity not resolved in any cache, loading from datastore: " + + infoString( persister, event.getEntityId(), event.getFactory() ) ); + } + Object entity = persister.load( event.getEntityId(), event.getInstanceToLoad(), diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLockEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLockEventListener.java index f91106da54..5df318297d 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLockEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultLockEventListener.java @@ -120,10 +120,7 @@ public class DefaultLockEventListener implements LockEventListener { protected final EntityEntry reassociate(AbstractEvent event, Object object, Object id, EntityPersister persister) { if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Reassociating transient instance: {0}", - infoString( persister, id, event.getFactory() ) - ); + LOG.trace( "Reassociating transient instance: " + infoString( persister, id, event.getFactory() ) ); } final EventSource source = event.getSession(); diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultRefreshEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultRefreshEventListener.java index 92bbd84de7..f09b9ffb19 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultRefreshEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultRefreshEventListener.java @@ -132,10 +132,7 @@ public class DefaultRefreshEventListener implements RefreshEventListener { + "' because it has a null identifier" ); } if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Refreshing transient {0}", - infoString( persister, id, event.getFactory() ) - ); + LOG.trace( "Refreshing transient " + infoString( persister, id, event.getFactory() ) ); } if ( persistenceContext.getEntry( source.generateEntityKey( id, persister ) ) != null ) { throw new NonUniqueObjectException( id, persister.getEntityName() ); @@ -143,10 +140,7 @@ public class DefaultRefreshEventListener implements RefreshEventListener { } else { if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Refreshing ", - infoString( entry.getPersister(), entry.getId(), event.getFactory() ) - ); + LOG.trace( "Refreshing " + infoString( entry.getPersister(), entry.getId(), event.getFactory() ) ); } if ( !entry.isExistsInDatabase() ) { throw new UnresolvableObjectException( diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultReplicateEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultReplicateEventListener.java index ab60854306..1028171a1c 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultReplicateEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultReplicateEventListener.java @@ -85,8 +85,7 @@ public class DefaultReplicateEventListener if ( oldVersion != null ) { if ( LOG.isTraceEnabled() ) { - LOG.tracev("Found existing row for {0}", - infoString( persister, id, event.getFactory() ) ); + LOG.trace( "Found existing row for " + infoString( persister, id, event.getFactory() ) ); } // If the entity has no version, getCurrentVersion() just returns // a meaningless value to indicate that the row exists (HHH-2378) @@ -107,8 +106,8 @@ public class DefaultReplicateEventListener else { // no existing row - execute a SQL INSERT if ( LOG.isTraceEnabled() ) { - LOG.tracev( "No existing row, replicating new instance {0}", - infoString( persister, id, event.getFactory() ) ); + LOG.trace( "No existing row, replicating new instance " + + infoString( persister, id, event.getFactory() ) ); } final boolean regenerate = persister.isIdentifierAssignedByInsert(); // prefer re-generation of identity! final EntityKey key = regenerate ? null : source.generateEntityKey( id, persister ); @@ -158,8 +157,7 @@ public class DefaultReplicateEventListener EventSource source) throws HibernateException { if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Replicating changes to {0}", - infoString( persister, id, source.getFactory() ) ); + LOG.trace( "Replicating changes to " + infoString( persister, id, source.getFactory() ) ); } new OnReplicateVisitor( source, id, entity, true ).process( entity, persister ); diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultResolveNaturalIdEventListener.java b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultResolveNaturalIdEventListener.java index f5f0d9bcc4..fddcf14f4f 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultResolveNaturalIdEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/DefaultResolveNaturalIdEventListener.java @@ -48,34 +48,22 @@ public class DefaultResolveNaturalIdEventListener implements ResolveNaturalIdEve final EntityPersister persister = event.getEntityPersister(); if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Attempting to resolve: {0}#{1}", - infoString( persister ), - event.getNaturalIdValues() - ); + LOG.trace( "Attempting to resolve: " + infoString( persister ) + "#" + event.getNaturalIdValues() ); } final Object entityId = resolveFromCache( event ); if ( entityId != null ) { if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Resolved object in cache: {0}#{1}", - infoString( persister ), - event.getNaturalIdValues() - ); + LOG.trace( "Resolved object in cache: " + infoString( persister ) + "#" + event.getNaturalIdValues() ); } return entityId; } - - if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Object not resolved in any cache: {0}#{1}", - infoString( persister ), - event.getNaturalIdValues() - ); + else { + if ( LOG.isTraceEnabled() ) { + LOG.trace( "Object not resolved in any cache: "+ infoString( persister ) + "#" + event.getNaturalIdValues() ); + } + return loadFromDatasource( event ); } - - return loadFromDatasource( event ); } /** diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/EntityState.java b/hibernate-core/src/main/java/org/hibernate/event/internal/EntityState.java index e833ac163a..880a126dbb 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/EntityState.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/EntityState.java @@ -44,13 +44,13 @@ public enum EntityState { if ( entry.getStatus() != Status.DELETED ) { // do nothing for persistent instances if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Persistent instance of: {0}", getLoggableName( entityName, entity ) ); + LOG.trace( "Persistent instance of: " + getLoggableName( entityName, entity ) ); } return PERSISTENT; } // ie. e.status==DELETED if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Deleted instance of: {0}", getLoggableName( entityName, entity ) ); + LOG.trace( "Deleted instance of: " + getLoggableName( entityName, entity ) ); } return DELETED; } @@ -61,12 +61,12 @@ public enum EntityState { if ( ForeignKeys.isTransient( entityName, entity, assumedUnsaved, source ) ) { if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Transient instance of: {0}", getLoggableName( entityName, entity ) ); + LOG.trace( "Transient instance of: " + getLoggableName( entityName, entity ) ); } return TRANSIENT; } if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Detached instance of: {0}", getLoggableName( entityName, entity ) ); + LOG.trace( "Detached instance of: " + getLoggableName( entityName, entity ) ); } final PersistenceContext persistenceContext = source.getPersistenceContextInternal(); diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/ReattachVisitor.java b/hibernate-core/src/main/java/org/hibernate/event/internal/ReattachVisitor.java index e4fcc51760..568dff4ea7 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/ReattachVisitor.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/ReattachVisitor.java @@ -10,11 +10,12 @@ import org.hibernate.event.spi.EventSource; import org.hibernate.internal.CoreLogging; import org.hibernate.internal.CoreMessageLogger; import org.hibernate.persister.collection.CollectionPersister; -import org.hibernate.pretty.MessageHelper; import org.hibernate.type.CollectionType; import org.hibernate.type.CompositeType; import org.hibernate.type.Type; +import static org.hibernate.pretty.MessageHelper.collectionInfoString; + /** * Abstract superclass of visitors that reattach collections. * @@ -77,10 +78,8 @@ public abstract class ReattachVisitor extends ProxyVisitor { void removeCollection(CollectionPersister role, Object collectionKey, EventSource source) throws HibernateException { if ( LOG.isTraceEnabled() ) { - LOG.tracev( - "Collection dereferenced while transient {0}", - MessageHelper.collectionInfoString( role, ownerIdentifier, source.getFactory() ) - ); + LOG.trace( "Collection dereferenced while transient " + + collectionInfoString( role, ownerIdentifier, source.getFactory() ) ); } source.getActionQueue().addAction( new CollectionRemoveAction( owner, role, collectionKey, false, source ) ); } diff --git a/hibernate-core/src/main/java/org/hibernate/event/internal/WrapVisitor.java b/hibernate-core/src/main/java/org/hibernate/event/internal/WrapVisitor.java index b709790ee1..b52b3f14e1 100644 --- a/hibernate-core/src/main/java/org/hibernate/event/internal/WrapVisitor.java +++ b/hibernate-core/src/main/java/org/hibernate/event/internal/WrapVisitor.java @@ -125,7 +125,7 @@ public class WrapVisitor extends ProxyVisitor { final PersistentCollection persistentCollection = collectionType.wrap( session, collection ); persistenceContext.addNewCollection( persister, persistentCollection ); if ( LOG.isTraceEnabled() ) { - LOG.tracev( "Wrapped collection in role: {0}", collectionType.getRole() ); + LOG.trace( "Wrapped collection in role: " + collectionType.getRole() ); } return persistentCollection; //Force a substitution! }