use typesafe logging in EnhancementHelper

Author: gavinking

hibernate-core/src/main/java/org/hibernate/bytecode/enhance/spi/interceptor/BytecodeInterceptorLogging.java

@@ -17,6 +17,7 @@
 import java.lang.invoke.MethodHandles;
 
 import static org.jboss.logging.Logger.Level.TRACE;
+import static org.jboss.logging.Logger.Level.DEBUG;
 import static org.jboss.logging.Logger.Level.WARN;
 
 /**
@@ -38,13 +39,66 @@ public interface BytecodeInterceptorLogging extends BasicLogger {
 	@LogMessage(level = WARN)
 	@Message(
 			id = 90005901,
-			value = "'%s.%s' was mapped with explicit lazy group '%s'. Hibernate will ignore the lazy group - this is generally " +
-					"not a good idea for to-one associations as it leads to two separate SQL selects to initialize the association. " +
-					"This is expected to be improved in future versions of Hibernate"
+			value = "Ignoring explicit lazy group '%s' specified for association '%s.%s'"
+					+ " (a lazy group for a to-one association would lead to two separate SELECTs to initialize the association)"
 	)
-	void lazyGroupIgnoredForToOne(String ownerName, String attributeName, String requestedLazyGroup);
+	void lazyGroupIgnoredForToOne(String requestedLazyGroup, String ownerName, String attributeName);
 
 	@LogMessage(level = TRACE)
 	@Message(id = 90005902, value = "Forcing initialization: %s.%s -> %s")
 	void enhancementAsProxyLazinessForceInitialize(String entityName, Object identifier, String attributeName);
+
+	@LogMessage(level = WARN)
+	@Message(
+			id = 90005903,
+			value = "Unable to commit JDBC transaction on temporary session used to load lazy collection associated to no session"
+	)
+	void unableToCommitTransactionOnTemporarySession();
+
+	@LogMessage(level = WARN)
+	@Message(
+			id = 90005904,
+			value = "Unable to close temporary session used to load lazy collection associated to no session"
+	)
+	void unableToCloseTemporarySession();
+
+	// DEBUG messages (type-safe)
+
+	@LogMessage(level = DEBUG)
+	@Message(
+			id = 90005905,
+			value = "To-one property '%s.%s' was mapped with LAZY + NO_PROXY but the class was not enhanced"
+	)
+	void toOneLazyNoProxyButNotEnhanced(String ownerName, String attributeName);
+
+	@LogMessage(level = DEBUG)
+	@Message(
+			id = 90005906,
+			value = "'%s.%s' was mapped with LAZY and explicit NO_PROXY but the associated entity ('%s') has subclasses"
+	)
+	void lazyNoProxyButAssociatedHasSubclasses(String ownerName, String attributeName, String associatedEntityName);
+
+	@LogMessage(level = DEBUG)
+	@Message(
+			id = 90005907,
+			value = "'%s.%s' specified NotFoundAction.IGNORE & LazyToOneOption.NO_PROXY;"
+					+ " skipping foreign key selection to more efficiently handle NotFoundAction.IGNORE"
+	)
+	void notFoundIgnoreWithNoProxySkippingFkSelection(String ownerName, String attributeName);
+
+	@LogMessage(level = DEBUG)
+	@Message(id = 90005908, value = "Enhancement interception started temporary Session")
+	void enhancementHelperStartedTemporarySession();
+
+	@LogMessage(level = DEBUG)
+	@Message(id = 90005909, value = "Enhancement interception starting transaction on temporary Session")
+	void enhancementHelperStartingTransactionOnTemporarySession();
+
+	@LogMessage(level = DEBUG)
+	@Message(id = 90005910, value = "Enhancement interception committing transaction on temporary Session")
+	void enhancementHelperCommittingTransactionOnTemporarySession();
+
+	@LogMessage(level = DEBUG)
+	@Message(id = 90005911, value = "Enhancement interception closing temporary Session")
+	void enhancementHelperClosingTemporarySession();
 }

hibernate-core/src/main/java/org/hibernate/bytecode/enhance/spi/interceptor/EnhancementHelper.java

@@ -41,8 +41,7 @@ public static boolean includeInBaseFetchGroup(
 		if ( ! isEnhanced ) {
 			if ( value instanceof ToOne toOne ) {
 				if ( toOne.isUnwrapProxy() ) {
-					BYTECODE_INTERCEPTOR_LOGGER.debugf(
-							"To-one property `%s#%s` was mapped with LAZY + NO_PROXY but the class was not enhanced",
+					BYTECODE_INTERCEPTOR_LOGGER.toOneLazyNoProxyButNotEnhanced(
 							bootMapping.getPersistentClass().getEntityName(),
 							bootMapping.getName()
 					);
@@ -73,9 +72,9 @@ public static boolean includeInBaseFetchGroup(
 				// we simply log a message that we are ignoring the `@LazyGroup` for to-ones
 
 				BYTECODE_INTERCEPTOR_LOGGER.lazyGroupIgnoredForToOne(
+						bootMapping.getLazyGroup(),
 						bootMapping.getPersistentClass().getEntityName(),
-						bootMapping.getName(),
-						bootMapping.getLazyGroup()
+						bootMapping.getName()
 				);
 
 				// at a later time - for example 6.0 when we can implement the join solution
@@ -105,8 +104,7 @@ public static boolean includeInBaseFetchGroup(
 				// the associated type has subclasses - we cannot use the enhanced proxy and will generate a HibernateProxy
 				if ( unwrapExplicitlyRequested ) {
 					// NO_PROXY was explicitly requested
-					BytecodeInterceptorLogging.LOGGER.debugf(
-							"`%s#%s` was mapped with LAZY and explicit NO_PROXY but the associated entity (`%s`) has subclasses",
+					BYTECODE_INTERCEPTOR_LOGGER.lazyNoProxyButAssociatedHasSubclasses(
 							bootMapping.getPersistentClass().getEntityName(),
 							bootMapping.getName(),
 							toOne.getReferencedEntityName()
@@ -118,9 +116,7 @@ public static boolean includeInBaseFetchGroup(
 
 			if ( toOne instanceof ManyToOne manyToOne && manyToOne.isIgnoreNotFound() ) {
 				if ( unwrapExplicitlyRequested ) {
-					BytecodeInterceptorLogging.LOGGER.debugf(
-							"%s#%s specified NotFoundAction.IGNORE & LazyToOneOption.NO_PROXY; " +
-									"skipping FK selection to more efficiently handle NotFoundAction.IGNORE",
+					BYTECODE_INTERCEPTOR_LOGGER.notFoundIgnoreWithNoProxySkippingFkSelection(
 							bootMapping.getPersistentClass().getEntityName(),
 							bootMapping.getName()
 					);
@@ -186,7 +182,7 @@ else if ( !session.isConnected() ) {
 
 		// If we are using a temporary Session, begin a transaction if necessary
 		if ( isTempSession ) {
-			BytecodeInterceptorLogging.LOGGER.debug( "Enhancement interception Helper#performWork started temporary Session" );
+			BYTECODE_INTERCEPTOR_LOGGER.enhancementHelperStartedTemporarySession();
 
 			isJta = session.getTransactionCoordinator().getTransactionCoordinatorBuilder().isJta();
 
@@ -196,7 +192,7 @@ else if ( !session.isConnected() ) {
 				// be created even if a current session and transaction are
 				// open (ex: session.clear() was used).  We must prevent
 				// multiple transactions.
-				BytecodeInterceptorLogging.LOGGER.debug( "Enhancement interception Helper#performWork starting transaction on temporary Session" );
+				BYTECODE_INTERCEPTOR_LOGGER.enhancementHelperStartingTransactionOnTemporarySession();
 				session.beginTransaction();
 			}
 		}
@@ -213,24 +209,21 @@ else if ( !session.isConnected() ) {
 				try {
 					// Commit the JDBC transaction if we started one.
 					if ( !isJta ) {
-						BytecodeInterceptorLogging.LOGGER.debug( "Enhancement interception Helper#performWork committing transaction on temporary Session" );
+						BYTECODE_INTERCEPTOR_LOGGER.enhancementHelperCommittingTransactionOnTemporarySession();
 						session.getTransaction().commit();
 					}
 				}
 				catch (Exception e) {
-					BytecodeInterceptorLogging.LOGGER.warn(
-							"Unable to commit JDBC transaction on temporary session used to load lazy " +
-									"collection associated to no session"
-					);
+					BYTECODE_INTERCEPTOR_LOGGER.unableToCommitTransactionOnTemporarySession();
 				}
 
 				// Close the just opened temp Session
 				try {
-					BytecodeInterceptorLogging.LOGGER.debug( "Enhancement interception Helper#performWork closing temporary Session" );
+					BYTECODE_INTERCEPTOR_LOGGER.enhancementHelperClosingTemporarySession();
 					session.close();
 				}
 				catch (Exception e) {
-					BytecodeInterceptorLogging.LOGGER.warn( "Unable to close temporary session used to load lazy collection associated to no session" );
+					BYTECODE_INTERCEPTOR_LOGGER.unableToCloseTemporarySession();
 				}
 			}
 		}