Skip to content

Commit ab2512a

Browse files
gavinkinggavinking
committed
make SqlExecLogger typesafe
1 parent 3f944e6 commit ab2512a

File tree

6 files changed

+74
-24
lines changed

6 files changed

+74
-24
lines changed

‎hibernate-core/src/main/java/org/hibernate/sql/exec/SqlExecLogger.java‎

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,10 +9,16 @@
99

1010
import org.jboss.logging.BasicLogger;
1111
import org.jboss.logging.Logger;
12+
import org.jboss.logging.annotations.LogMessage;
13+
import org.jboss.logging.annotations.Message;
1214
import org.jboss.logging.annotations.MessageLogger;
1315
import org.jboss.logging.annotations.ValidIdRange;
1416

1517
import java.lang.invoke.MethodHandles;
18+
import java.util.Set;
19+
20+
import static org.jboss.logging.Logger.Level.DEBUG;
21+
import static org.jboss.logging.Logger.Level.TRACE;
1622

1723
/**
1824
* @author Steve Ebersole
@@ -28,4 +34,45 @@ public interface SqlExecLogger extends BasicLogger {
2834
String LOGGER_NAME = SubSystemLogging.BASE + ".sql.exec";
2935

3036
SqlExecLogger SQL_EXEC_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), SqlExecLogger.class, LOGGER_NAME );
37+
38+
@LogMessage(level = DEBUG)
39+
@Message(id = 90004001, value = "Collection locking for collection table '%s' - %s")
40+
void collectionLockingForCollectionTable(String keyTableName, String rootPathName);
41+
42+
@LogMessage(level = DEBUG)
43+
@Message(id = 90004002, value = "Follow-on locking for collection table '%s' - %s")
44+
void followOnLockingForCollectionTable(String keyTableName, String rootPathName);
45+
46+
@LogMessage(level = DEBUG)
47+
@Message(id = 90004003, value = "Follow-on locking collected loaded values:\n%s")
48+
void followOnLockingCollectedLoadedValues(String summary);
49+
50+
@LogMessage(level = DEBUG)
51+
@Message(id = 90004010, value = "Starting include-collections locking process - %s")
52+
void startingIncludeCollectionsLockingProcess(String entityName);
53+
54+
@LogMessage(level = DEBUG)
55+
@Message(id = 90004011, value = "Starting follow-on locking process - %s")
56+
void startingFollowOnLockingProcess(String entityName);
57+
58+
@LogMessage(level = DEBUG)
59+
@Message(id = 90004012, value = "Adding table '%s' for follow-on locking - %s")
60+
void addingTableForFollowOnLocking(String tableName, String entityName);
61+
62+
// Trace messages (typesafe)
63+
@LogMessage(level = TRACE)
64+
@Message(id = 90004013, value = "Reading query result cache data [%s]")
65+
void readingQueryResultCacheData(String cacheModeName);
66+
67+
@LogMessage(level = TRACE)
68+
@Message(id = 90004014, value = "Affected query spaces unexpectedly empty")
69+
void affectedQuerySpacesUnexpectedlyEmpty();
70+
71+
@LogMessage(level = TRACE)
72+
@Message(id = 90004015, value = "Affected query spaces %s")
73+
void affectedQuerySpaces(Set<String> querySpaces);
74+
75+
@LogMessage(level = TRACE)
76+
@Message(id = 90004016, value = "Skipping reading query result cache data (query cache %s, cache mode %s)")
77+
void skippingReadingQueryResultCacheData(String queryCacheStatus, String cacheModeName);
3178
}

‎hibernate-core/src/main/java/org/hibernate/sql/exec/internal/JdbcSelectExecutorStandardImpl.java‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -287,13 +287,13 @@ protected JdbcValues resolveJdbcValuesSource(
287287
final QueryKey queryResultsCacheKey;
288288
final List<?> cachedResults;
289289
if ( cacheable && cacheMode.isGetEnabled() ) {
290-
SQL_EXEC_LOGGER.tracef( "Reading query result cache data [%s]", cacheMode.name() );
290+
SQL_EXEC_LOGGER.readingQueryResultCacheData( cacheMode.name() );
291291
final Set<String> querySpaces = jdbcSelect.getAffectedTableNames();
292292
if ( querySpaces == null || querySpaces.isEmpty() ) {
293-
SQL_EXEC_LOGGER.tracef( "Affected query spaces unexpectedly empty" );
293+
SQL_EXEC_LOGGER.affectedQuerySpacesUnexpectedlyEmpty();
294294
}
295295
else {
296-
SQL_EXEC_LOGGER.tracef( "Affected query spaces %s", querySpaces );
296+
SQL_EXEC_LOGGER.affectedQuerySpaces( querySpaces );
297297
}
298298

299299
final var queryCache = factory.getCache()
@@ -333,7 +333,7 @@ protected JdbcValues resolveJdbcValuesSource(
333333
}
334334
}
335335
else {
336-
SQL_EXEC_LOGGER.tracef( "Skipping reading query result cache data (query cache %s, cache mode %s)",
336+
SQL_EXEC_LOGGER.skippingReadingQueryResultCacheData(
337337
queryCacheEnabled ? "enabled" : "disabled",
338338
cacheMode.name()
339339
);

‎hibernate-core/src/main/java/org/hibernate/sql/exec/internal/lock/CollectionLockingAction.java‎

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -31,7 +31,6 @@
3131
import java.util.Map;
3232

3333
import static org.hibernate.sql.exec.SqlExecLogger.SQL_EXEC_LOGGER;
34-
import static org.hibernate.sql.exec.internal.lock.LockingHelper.segmentLoadedValues;
3534

3635
/**
3736
* PostAction intended to perform collection locking with
@@ -98,8 +97,7 @@ public void performPostAction(
9897
// the select-list for that table-segment.
9998
entitySegments.forEach( (entityMappingType, entityKeys) -> {
10099
if ( SQL_EXEC_LOGGER.isDebugEnabled() ) {
101-
SQL_EXEC_LOGGER.debugf( "Starting include-collections locking process - %s",
102-
entityMappingType.getEntityName() );
100+
SQL_EXEC_LOGGER.startingIncludeCollectionsLockingProcess( entityMappingType.getEntityName() );
103101
}
104102

105103
// apply an empty "fetch graph" to make sure any embedded associations reachable from

‎hibernate-core/src/main/java/org/hibernate/sql/exec/internal/lock/FollowOnLockingAction.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -119,7 +119,7 @@ public void performPostAction(
119119
// the select-list for that table-segment.
120120
entitySegments.forEach( (entityMappingType, entityKeys) -> {
121121
if ( SQL_EXEC_LOGGER.isDebugEnabled() ) {
122-
SQL_EXEC_LOGGER.debugf( "Starting follow-on locking process - %s", entityMappingType.getEntityName() );
122+
SQL_EXEC_LOGGER.startingFollowOnLockingProcess( entityMappingType.getEntityName() );
123123
}
124124

125125
// apply an empty "fetch graph" to make sure any embedded associations reachable from

‎hibernate-core/src/main/java/org/hibernate/sql/exec/internal/lock/LockingHelper.java‎

Lines changed: 20 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,6 @@
1010
import org.hibernate.Session;
1111
import org.hibernate.collection.spi.PersistentCollection;
1212
import org.hibernate.engine.spi.CollectionKey;
13-
import org.hibernate.engine.spi.EntityEntry;
1413
import org.hibernate.engine.spi.EntityKey;
1514
import org.hibernate.engine.spi.SharedSessionContractImplementor;
1615
import org.hibernate.metamodel.mapping.EntityMappingType;
@@ -78,7 +77,7 @@ public static void lockCollectionTable(
7877
final String keyTableName = keyDescriptor.getKeyTable();
7978

8079
if ( SQL_EXEC_LOGGER.isDebugEnabled() ) {
81-
SQL_EXEC_LOGGER.debugf( "Collection locking for collection table `%s` - %s", keyTableName, attributeMapping.getRootPathName() );
80+
SQL_EXEC_LOGGER.collectionLockingForCollectionTable( keyTableName, attributeMapping.getRootPathName() );
8281
}
8382

8483
final var querySpec = new QuerySpec( true );
@@ -153,7 +152,7 @@ public static void lockCollectionTable(
153152
* @param lockTimeout A lock timeout to apply, if one.
154153
* @param ownerDetailsMap Details for each owner, whose collection-table rows should be locked.
155154
*/
156-
public static void lockCollectionTable(
155+
public static void lockCollectionTable(
157156
PluralAttributeMapping attributeMapping,
158157
LockMode lockMode,
159158
Timeout lockTimeout,
@@ -163,7 +162,7 @@ public static void lockCollectionTable(
163162
final String keyTableName = keyDescriptor.getKeyTable();
164163

165164
if ( SQL_EXEC_LOGGER.isDebugEnabled() ) {
166-
SQL_EXEC_LOGGER.debugf( "Follow-on locking for collection table `%s` - %s", keyTableName, attributeMapping.getRootPathName() );
165+
SQL_EXEC_LOGGER.followOnLockingForCollectionTable( keyTableName, attributeMapping.getRootPathName() );
167166
}
168167

169168
final var querySpec = new QuerySpec( true );
@@ -323,7 +322,7 @@ public static void lockCollectionTable(
323322
final String keyTableName = keyDescriptor.getKeyTable();
324323

325324
if ( SQL_EXEC_LOGGER.isDebugEnabled() ) {
326-
SQL_EXEC_LOGGER.debugf( "Follow-on locking for collection table `%s` - %s", keyTableName, attributeMapping.getRootPathName() );
325+
SQL_EXEC_LOGGER.followOnLockingForCollectionTable( keyTableName, attributeMapping.getRootPathName() );
327326
}
328327

329328
final var querySpec = new QuerySpec( true );
@@ -465,22 +464,28 @@ private static void performLocking(
465464
*/
466465
public static void logLoadedValues(LoadedValuesCollector collector) {
467466
if ( SQL_EXEC_LOGGER.isDebugEnabled() ) {
468-
SQL_EXEC_LOGGER.debug( "Follow-on locking collected loaded values..." );
469-
470-
SQL_EXEC_LOGGER.debug( " Loaded root entities:" );
467+
var summary = new StringBuilder();
468+
summary.append( " Loaded root entities:\n" );
471469
collector.getCollectedRootEntities().forEach( (reg) -> {
472-
SQL_EXEC_LOGGER.debugf( " - %s#%s", reg.entityDescriptor().getEntityName(), reg.entityKey().getIdentifier() );
470+
summary.append( String.format( " - %s#%s\n",
471+
reg.entityDescriptor().getEntityName(),
472+
reg.entityKey().getIdentifier() ) );
473473
} );
474474

475-
SQL_EXEC_LOGGER.debug( " Loaded non-root entities:" );
475+
summary.append( " Loaded non-root entities:\n" );
476476
collector.getCollectedNonRootEntities().forEach( (reg) -> {
477-
SQL_EXEC_LOGGER.debugf( " - %s#%s", reg.entityDescriptor().getEntityName(), reg.entityKey().getIdentifier() );
477+
summary.append( String.format( " - %s#%s\n",
478+
reg.entityDescriptor().getEntityName()
479+
, reg.entityKey().getIdentifier() ) );
478480
} );
479481

480-
SQL_EXEC_LOGGER.debug( " Loaded collections:" );
482+
summary.append( " Loaded collections:\n" );
481483
collector.getCollectedCollections().forEach( (reg) -> {
482-
SQL_EXEC_LOGGER.debugf( " - %s#%s", reg.collectionDescriptor().getRootPathName(), reg.collectionKey().getKey() );
484+
summary.append( String.format( " - %s#%s\n",
485+
reg.collectionDescriptor().getRootPathName(),
486+
reg.collectionKey().getKey() ) );
483487
} );
488+
SQL_EXEC_LOGGER.followOnLockingCollectedLoadedValues( summary.toString() );
484489
}
485490
}
486491

@@ -547,8 +552,8 @@ public static Map<Object, EntityDetails> resolveEntityKeys(List<EntityKey> entit
547552
final var persistenceContext = executionContext.getSession().getPersistenceContext();
548553
entityKeys.forEach( (entityKey) -> {
549554
final Object instance = persistenceContext.getEntity( entityKey );
550-
final EntityEntry entry = persistenceContext.getEntry( instance );
551-
map.put( entityKey.getIdentifierValue(), new EntityDetails( entityKey, entry, instance ) );
555+
final var entityEntry = persistenceContext.getEntry( instance );
556+
map.put( entityKey.getIdentifierValue(), new EntityDetails( entityKey, entityEntry, instance ) );
552557
} );
553558
return map;
554559
}

‎hibernate-core/src/main/java/org/hibernate/sql/exec/internal/lock/TableLock.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -76,7 +76,7 @@ public TableLock(
7676
List<EntityKey> entityKeys,
7777
SharedSessionContractImplementor session) {
7878
if ( SQL_EXEC_LOGGER.isDebugEnabled() ) {
79-
SQL_EXEC_LOGGER.debugf( "Adding table `%s` for follow-on locking - %s", tableDetails.getTableName(), entityMappingType.getEntityName() );
79+
SQL_EXEC_LOGGER.addingTableForFollowOnLocking( tableDetails.getTableName(), entityMappingType.getEntityName() );
8080
}
8181

8282
this.tableDetails = tableDetails;

0 commit comments

Comments
 (0)