Skip to content

Commit 992868e

Browse files
gavinkinggavinking
committed
introduce EventListenerLogging
1 parent c0acf55 commit 992868e

28 files changed

+620
-345
lines changed

‎hibernate-core/src/main/java/org/hibernate/boot/model/internal/CollectionPropertyHolder.java‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -99,11 +99,11 @@ private void applyLocalConvert(
9999
Map<String,AttributeConversionInfo> elementAttributeConversionInfoMap,
100100
Map<String,AttributeConversionInfo> keyAttributeConversionInfoMap) {
101101

102-
// IMPL NOTE : the rules here are quite more lenient than what JPA says. For example, JPA says that @Convert
103-
// on a Map of basic types should default to "value" but it should explicitly specify attributeName of "key"
102+
// IMPL NOTE: the rules here are quite more lenient than what JPA says. For example, JPA says that @Convert
103+
// on a Map of basic types should default to "value" but it should explicitly specify 'attributeName' of "key"
104104
// (or prefixed with "key." for embedded paths) to be applied on the key. However, we try to see if conversion
105-
// of either is disabled for whatever reason. For example, if the Map is annotated with @Enumerated the
106-
// elements cannot be converted so any @Convert likely meant the key, so we apply it to the key
105+
// of either is disabled for whatever reason. For example, if the Map is annotated with @Enumerated, the
106+
// elements cannot be converted, and so any @Convert likely meant the key, so we apply it to the key
107107

108108
final var info = new AttributeConversionInfo( convertAnnotation, collectionProperty );
109109
final String attributeName = info.getAttributeName();

‎hibernate-core/src/main/java/org/hibernate/event/internal/AbstractFlushingEventListener.java‎

Lines changed: 14 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -27,15 +27,14 @@
2727
import org.hibernate.event.spi.FlushEntityEventListener;
2828
import org.hibernate.event.spi.FlushEvent;
2929
import org.hibernate.event.spi.PersistContext;
30-
import org.hibernate.internal.CoreLogging;
31-
import org.hibernate.internal.CoreMessageLogger;
3230
import org.hibernate.internal.util.EntityPrinter;
3331
import org.hibernate.internal.util.collections.InstanceIdentityMap;
3432
import org.hibernate.persister.entity.EntityPersister;
3533

3634

3735
import static org.hibernate.engine.internal.Collections.processUnreachableCollection;
3836
import static org.hibernate.engine.internal.Collections.skipRemoval;
37+
import static org.hibernate.event.internal.EventListenerLogging.EVENT_LISTENER_LOGGER;
3938

4039
/**
4140
* A convenience base class for listeners whose functionality results in flushing.
@@ -44,8 +43,6 @@
4443
*/
4544
public abstract class AbstractFlushingEventListener {
4645

47-
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( AbstractFlushingEventListener.class );
48-
4946
// ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
5047
// Pre-flushing section
5148
// ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
@@ -59,7 +56,7 @@ public abstract class AbstractFlushingEventListener {
5956
* @throws HibernateException Error flushing caches to execution queues.
6057
*/
6158
protected void flushEverythingToExecutions(FlushEvent event) throws HibernateException {
62-
LOG.trace( "Flushing session" );
59+
EVENT_LISTENER_LOGGER.flushingSession();
6360
final var session = event.getSession();
6461
final var persistenceContext = session.getPersistenceContextInternal();
6562
preFlush( session, persistenceContext );
@@ -94,19 +91,17 @@ protected void preFlush(EventSource session, PersistenceContext persistenceConte
9491
}
9592

9693
protected void logFlushResults(FlushEvent event) {
97-
if ( LOG.isDebugEnabled() ) {
94+
if ( EVENT_LISTENER_LOGGER.isDebugEnabled() ) {
9895
final var session = event.getSession();
9996
final var persistenceContext = session.getPersistenceContextInternal();
10097
final var actionQueue = session.getActionQueue();
101-
LOG.debugf(
102-
"Flushed: %s insertions, %s updates, %s deletions to %s objects",
98+
EVENT_LISTENER_LOGGER.flushedEntitiesSummary(
10399
actionQueue.numberOfInsertions(),
104100
actionQueue.numberOfUpdates(),
105101
actionQueue.numberOfDeletions(),
106102
persistenceContext.getNumberOfManagedEntities()
107103
);
108-
LOG.debugf(
109-
"Flushed: %s (re)creations, %s updates, %s removals to %s collections",
104+
EVENT_LISTENER_LOGGER.flushedCollectionsSummary(
110105
actionQueue.numberOfCollectionCreations(),
111106
actionQueue.numberOfCollectionUpdates(),
112107
actionQueue.numberOfCollectionRemovals(),
@@ -124,7 +119,7 @@ protected void logFlushResults(FlushEvent event) {
124119
*/
125120
private void prepareEntityFlushes(EventSource session, PersistenceContext persistenceContext)
126121
throws HibernateException {
127-
LOG.trace( "Processing flush-time cascades" );
122+
EVENT_LISTENER_LOGGER.processingFlushTimeCascades();
128123
final var context = PersistContext.create();
129124
// safe from concurrent modification because of how concurrentEntries() is implemented on IdentityMap
130125
for ( var entry : persistenceContext.reentrantSafeEntityEntries() ) {
@@ -188,7 +183,7 @@ private void cascadeOnFlush(EventSource session, EntityPersister persister, Obje
188183
private void prepareCollectionFlushes(PersistenceContext persistenceContext) throws HibernateException {
189184
// Initialize dirty flags for arrays + collections with composite elements
190185
// and reset reached, doupdate, etc.
191-
LOG.trace( "Dirty checking collections" );
186+
EVENT_LISTENER_LOGGER.dirtyCheckingCollections();
192187
final var collectionEntries = persistenceContext.getCollectionEntries();
193188
if ( collectionEntries != null ) {
194189
final var identityMap =
@@ -209,7 +204,7 @@ private void prepareCollectionFlushes(PersistenceContext persistenceContext) thr
209204
*/
210205
private int flushEntities(final FlushEvent event, final PersistenceContext persistenceContext)
211206
throws HibernateException {
212-
LOG.trace( "Flushing entities and processing referenced collections" );
207+
EVENT_LISTENER_LOGGER.flushingEntitiesAndProcessingReferencedCollections();
213208

214209
final var source = event.getSession();
215210
final var flushListeners =
@@ -267,13 +262,13 @@ private FlushEntityEvent createOrReuseEventInstance(
267262
*/
268263
private int flushCollections(final EventSource session, final PersistenceContext persistenceContext)
269264
throws HibernateException {
270-
LOG.trace( "Processing unreferenced collections" );
265+
EVENT_LISTENER_LOGGER.processingUnreferencedCollections();
271266
final var collectionEntries = persistenceContext.getCollectionEntries();
272267
final int count = processUnreachableCollections( session, collectionEntries );
273268

274269
// Schedule updates to collections:
275270

276-
LOG.trace( "Scheduling collection removes/(re)creates/updates" );
271+
EVENT_LISTENER_LOGGER.schedulingCollectionOperations();
277272
final var actionQueue = session.getActionQueue();
278273
final var interceptor = session.getInterceptor();
279274
persistenceContext.forEachCollectionEntry(
@@ -370,11 +365,9 @@ private static int processUnreachableCollections(
370365
* @param session The session being flushed
371366
*/
372367
protected void performExecutions(EventSource session) {
373-
LOG.trace( "Executing flush" );
374-
375-
// IMPL NOTE : here we alter the flushing flag of the persistence context to allow
376-
// during-flush callbacks more leniency in regards to initializing proxies and
377-
// lazy collections during their processing.
368+
// IMPL NOTE: here we alter the flushing flag of the persistence context to allow
369+
// callbacks occurring during flush more leniency regarding initializing
370+
// proxies and lazy collections
378371
// For more information, see HHH-2763
379372
final var persistenceContext = session.getPersistenceContextInternal();
380373
final var jdbcCoordinator = session.getJdbcCoordinator();
@@ -406,7 +399,7 @@ protected void performExecutions(EventSource session) {
406399
* </ol>
407400
*/
408401
protected void postFlush(SessionImplementor session) throws HibernateException {
409-
LOG.trace( "Post flush" );
402+
EVENT_LISTENER_LOGGER.postFlush();
410403

411404
final var persistenceContext = session.getPersistenceContextInternal();
412405
persistenceContext.clearCollectionsByKey();

‎hibernate-core/src/main/java/org/hibernate/event/internal/AbstractSaveEventListener.java‎

Lines changed: 6 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -22,8 +22,6 @@
2222
import org.hibernate.event.spi.EventSource;
2323
import org.hibernate.id.CompositeNestedGeneratedValueGenerator;
2424
import org.hibernate.id.IdentifierGenerationException;
25-
import org.hibernate.internal.CoreLogging;
26-
import org.hibernate.internal.CoreMessageLogger;
2725
import org.hibernate.jpa.event.spi.CallbackRegistry;
2826
import org.hibernate.jpa.event.spi.CallbackRegistryConsumer;
2927
import org.hibernate.persister.entity.EntityPersister;
@@ -35,6 +33,7 @@
3533
import static org.hibernate.engine.internal.ManagedTypeHelper.processIfManagedEntity;
3634
import static org.hibernate.engine.internal.Versioning.getVersion;
3735
import static org.hibernate.engine.internal.Versioning.seedVersion;
36+
import static org.hibernate.event.internal.EventListenerLogging.EVENT_LISTENER_LOGGER;
3837
import static org.hibernate.generator.EventType.INSERT;
3938
import static org.hibernate.id.IdentifierGeneratorHelper.SHORT_CIRCUIT_INDICATOR;
4039
import static org.hibernate.pretty.MessageHelper.infoString;
@@ -48,8 +47,6 @@
4847
*/
4948
public abstract class AbstractSaveEventListener<C> implements CallbackRegistryConsumer {
5049

51-
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( AbstractSaveEventListener.class );
52-
5350
private CallbackRegistry callbackRegistry;
5451

5552
@Override
@@ -158,10 +155,9 @@ private static Object generateId(
158155
throw new IdentifierGenerationException( "Null id generated for entity '" + persister.getEntityName() + "'" );
159156
}
160157
else {
161-
if ( LOG.isTraceEnabled() ) {
158+
if ( EVENT_LISTENER_LOGGER.isTraceEnabled() ) {
162159
// TODO: define toString()s for generators
163-
LOG.tracef(
164-
"Generated identifier [%s] using generator '%s'",
160+
EVENT_LISTENER_LOGGER.generatedId(
165161
persister.getIdentifierType().toLoggableString( id, source.getFactory() ),
166162
generator.getClass().getName()
167163
);
@@ -210,8 +206,9 @@ protected Object performSave(
210206
}
211207
}
212208

213-
if ( LOG.isTraceEnabled() ) {
214-
LOG.trace( "Persisting " + infoString( persister, id, source.getFactory() ) );
209+
if ( EVENT_LISTENER_LOGGER.isTraceEnabled() ) {
210+
EVENT_LISTENER_LOGGER.persisting(
211+
infoString( persister, id, source.getFactory() ) );
215212
}
216213

217214
final var key = useIdentityColumn ? null : entityKey( id, persister, source );

‎hibernate-core/src/main/java/org/hibernate/event/internal/DefaultAutoFlushEventListener.java‎

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -9,9 +9,8 @@
99
import org.hibernate.event.spi.AutoFlushEvent;
1010
import org.hibernate.event.spi.AutoFlushEventListener;
1111
import org.hibernate.event.spi.EventSource;
12-
import org.hibernate.internal.CoreLogging;
13-
import org.hibernate.internal.CoreMessageLogger;
1412

13+
import static org.hibernate.event.internal.EventListenerLogging.EVENT_LISTENER_LOGGER;
1514

1615

1716
/**
@@ -22,8 +21,6 @@
2221
*/
2322
public class DefaultAutoFlushEventListener extends AbstractFlushingEventListener implements AutoFlushEventListener {
2423

25-
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( DefaultAutoFlushEventListener.class );
26-
2724
/**
2825
* Handle the given auto-flush event.
2926
*
@@ -50,7 +47,7 @@ public void onAutoFlush(AutoFlushEvent event) throws HibernateException {
5047
final int oldSize = actionQueue.numberOfCollectionRemovals();
5148
flushEverythingToExecutions( event, persistenceContext, session );
5249
if ( flushIsReallyNeeded( event, source ) ) {
53-
LOG.trace( "Need to execute flush" );
50+
EVENT_LISTENER_LOGGER.needToExecuteFlush();
5451
event.setFlushRequired( true );
5552

5653
// note: performExecutions() clears all collectionXxxxtion
@@ -70,7 +67,7 @@ public void onAutoFlush(AutoFlushEvent event) throws HibernateException {
7067
}
7168
}
7269
else {
73-
LOG.trace( "No need to execute flush" );
70+
EVENT_LISTENER_LOGGER.noNeedToExecuteFlush();
7471
event.setFlushRequired( false );
7572
actionQueue.clearFromFlushNeededCheck( oldSize );
7673
}

‎hibernate-core/src/main/java/org/hibernate/event/internal/DefaultDeleteEventListener.java‎

Lines changed: 10 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -27,8 +27,6 @@
2727
import org.hibernate.event.spi.DeleteEvent;
2828
import org.hibernate.event.spi.DeleteEventListener;
2929
import org.hibernate.event.spi.EventSource;
30-
import org.hibernate.internal.CoreLogging;
31-
import org.hibernate.internal.CoreMessageLogger;
3230
import org.hibernate.internal.EmptyInterceptor;
3331
import org.hibernate.jpa.event.spi.CallbackRegistry;
3432
import org.hibernate.jpa.event.spi.CallbackRegistryConsumer;
@@ -42,6 +40,7 @@
4240

4341
import static java.util.Arrays.fill;
4442
import static org.hibernate.engine.internal.Collections.skipRemoval;
43+
import static org.hibernate.event.internal.EventListenerLogging.EVENT_LISTENER_LOGGER;
4544
import static org.hibernate.pretty.MessageHelper.infoString;
4645
import static org.hibernate.proxy.HibernateProxy.extractLazyInitializer;
4746

@@ -53,8 +52,6 @@
5352
*/
5453
public class DefaultDeleteEventListener implements DeleteEventListener, CallbackRegistryConsumer {
5554

56-
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( DefaultDeleteEventListener.class );
57-
5855
private CallbackRegistry callbackRegistry;
5956

6057
@Override
@@ -155,7 +152,7 @@ private void delete(DeleteEvent event, DeleteContext transientEntities) {
155152
}
156153

157154
private void deleteUnmanagedInstance(DeleteEvent event, DeleteContext transientEntities, Object entity) {
158-
LOG.trace( "Deleted entity was not associated with current session" );
155+
EVENT_LISTENER_LOGGER.deletedEntityNotAssociatedWithSession();
159156
final var source = event.getSession();
160157
final var persister = source.getEntityPersister( event.getEntityName(), entity );
161158
if ( ForeignKeys.isTransient( persister.getEntityName(), entity, null, source ) ) {
@@ -220,7 +217,7 @@ private static boolean flushAndEvictExistingEntity(
220217
return true;
221218
}
222219
else {
223-
LOG.flushAndEvictOnRemove( key.getEntityName() );
220+
EVENT_LISTENER_LOGGER.flushAndEvictOnRemove( key.getEntityName() );
224221
source.flush();
225222
if ( !persister.isVersioned()
226223
|| persister.getVersionType()
@@ -244,12 +241,12 @@ private void deletePersistentInstance(
244241
DeleteContext transientEntities,
245242
Object entity,
246243
EntityEntry entityEntry) {
247-
LOG.trace( "Deleting a persistent instance" );
244+
EVENT_LISTENER_LOGGER.deletingPersistentInstance();
248245
final var source = event.getSession();
249246
if ( entityEntry.getStatus().isDeletedOrGone()
250247
|| source.getPersistenceContextInternal()
251248
.containsDeletedUnloadedEntityKey( entityEntry.getEntityKey() ) ) {
252-
LOG.trace( "Object was already deleted" );
249+
EVENT_LISTENER_LOGGER.alreadyDeleted();
253250
}
254251
else {
255252
delete(
@@ -339,13 +336,13 @@ protected void deleteTransientEntity(
339336
Object entity,
340337
EntityPersister persister,
341338
DeleteContext transientEntities) {
342-
LOG.handlingTransientEntity();
339+
EVENT_LISTENER_LOGGER.handlingTransientEntity();
343340
if ( transientEntities.add( entity ) ) {
344341
cascadeBeforeDelete( session, persister, entity, transientEntities );
345342
cascadeAfterDelete( session, persister, entity, transientEntities );
346343
}
347344
else {
348-
LOG.trace( "Already handled transient entity; skipping" );
345+
EVENT_LISTENER_LOGGER.alreadyHandledTransient();
349346
}
350347
}
351348

@@ -370,8 +367,9 @@ protected final void deleteEntity(
370367
final EntityPersister persister,
371368
final DeleteContext transientEntities) {
372369

373-
if ( LOG.isTraceEnabled() ) {
374-
LOG.trace( "Deleting " + infoString( persister, entityEntry.getId(), session.getFactory() ) );
370+
if ( EVENT_LISTENER_LOGGER.isTraceEnabled() ) {
371+
EVENT_LISTENER_LOGGER.deleting(
372+
infoString( persister, entityEntry.getId(), session.getFactory() ) );
375373
}
376374

377375
final Object version = entityEntry.getVersion();

‎hibernate-core/src/main/java/org/hibernate/event/internal/DefaultEvictEventListener.java‎

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -12,11 +12,10 @@
1212
import org.hibernate.event.spi.EventSource;
1313
import org.hibernate.event.spi.EvictEvent;
1414
import org.hibernate.event.spi.EvictEventListener;
15-
import org.hibernate.internal.CoreLogging;
16-
import org.hibernate.internal.CoreMessageLogger;
1715
import org.hibernate.persister.entity.EntityPersister;
1816
import org.hibernate.proxy.LazyInitializer;
1917

18+
import static org.hibernate.event.internal.EventListenerLogging.EVENT_LISTENER_LOGGER;
2019
import static org.hibernate.pretty.MessageHelper.infoString;
2120
import static org.hibernate.proxy.HibernateProxy.extractLazyInitializer;
2221

@@ -30,8 +29,6 @@
3029
*/
3130
public class DefaultEvictEventListener implements EvictEventListener {
3231

33-
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( DefaultEvictEventListener.class );
34-
3532
/**
3633
* Handle the given evict event.
3734
*
@@ -106,8 +103,8 @@ protected void doEvict(
106103
final EntityPersister persister,
107104
final EventSource session)
108105
throws HibernateException {
109-
if ( LOG.isTraceEnabled() ) {
110-
LOG.trace( "Evicting " + infoString( persister ) );
106+
if ( EVENT_LISTENER_LOGGER.isTraceEnabled() ) {
107+
EVENT_LISTENER_LOGGER.evicting( infoString( persister ) );
111108
}
112109

113110
final var persistenceContext = session.getPersistenceContextInternal();

0 commit comments

Comments
 (0)