introduce SessionFactoryLogging

Author: gavinking

hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java

@@ -9,7 +9,6 @@
 import java.io.IOException;
 import java.sql.SQLException;
 import java.sql.SQLWarning;
-import java.util.Map;
 import java.util.Properties;
 import java.util.ServiceConfigurationError;
 import java.util.Set;
@@ -67,22 +66,6 @@ public interface CoreMessageLogger extends BasicLogger {
 	@Message(value = "Second-level cache disabled", id = 26)
 	void noRegionFactory();
 
-	@LogMessage(level = DEBUG)
-	@Message(value = "Instantiating factory [%s] with settings: %s", id = 30)
-	void instantiatingFactory(String uuid, Map<String, Object> settings);
-
-	@LogMessage(level = DEBUG)
-	@Message(value = "Closing factory [%s]", id = 31)
-	void closingFactory(String uuid);
-
-	@LogMessage(level = DEBUG)
-	@Message(value = "Serializing factory [%s]", id = 32)
-	void serializingFactory(String uuid);
-
-	@LogMessage(level = DEBUG)
-	@Message(value = "Deserialized factory [%s]", id = 33)
-	void deserializedFactory(String uuid);
-
 	@LogMessage(level = WARN)
 	@Message(value = "Composite id class does not override equals(): %s", id = 38)
 	void compositeIdClassDoesNotOverrideEquals(String name);
@@ -306,10 +289,6 @@ void missingArguments(
 	@Message(value = "Could not close stream on hibernate.properties: %s", id = 297)
 	void unableToCloseStreamError(IOException error);
 
-	@LogMessage(level = ERROR)
-	@Message(value = "Unable to construct current session context [%s]", id = 302)
-	void unableToConstructCurrentSessionContext(String impl, @Cause Throwable e);
-
 	@LogMessage(level = WARN)
 	@Message(value = "Unable to close temporary session used to load lazy collection associated to no session", id = 303)
 	void unableToCloseTemporarySession();

hibernate-core/src/main/java/org/hibernate/internal/SessionFactoryImpl.java

@@ -127,6 +127,7 @@
 import static java.util.Collections.unmodifiableSet;
 import static org.hibernate.cfg.AvailableSettings.CURRENT_SESSION_CONTEXT_CLASS;
 import static org.hibernate.internal.FetchProfileHelper.addFetchProfiles;
+import static org.hibernate.internal.SessionFactoryLogging.SESSION_FACTORY_LOGGER;
 import static org.hibernate.internal.SessionFactorySettings.determineJndiName;
 import static org.hibernate.internal.SessionFactorySettings.getMaskedSettings;
 import static org.hibernate.internal.SessionFactorySettings.getSessionFactoryName;
@@ -155,7 +156,6 @@
  * @author Chris Cranford
  */
 public class SessionFactoryImpl implements SessionFactoryImplementor {
-	private static final CoreMessageLogger LOG = CoreLogging.messageLogger( SessionFactoryImpl.class );
 
 	private final String name;
 	private final String jndiName;
@@ -211,7 +211,7 @@ public SessionFactoryImpl(
 			final MetadataImplementor bootMetamodel,
 			final SessionFactoryOptions options,
 			final BootstrapContext bootstrapContext) {
-		LOG.trace( "Building session factory" );
+SESSION_FACTORY_LOGGER.buildingSessionFactory();
 		typeConfiguration = bootstrapContext.getTypeConfiguration();
 
 		sessionFactoryOptions = options;
@@ -228,7 +228,7 @@ public SessionFactoryImpl(
 		jdbcServices = serviceRegistry.requireService( JdbcServices.class );
 
 		settings = getMaskedSettings( options, serviceRegistry );
-		LOG.instantiatingFactory( uuid, settings );
+		SESSION_FACTORY_LOGGER.instantiatingFactory( uuid, settings );
 
 		sqlStringGenerationContext = createSqlStringGenerationContext( bootMetamodel, options, jdbcServices );
 
@@ -330,14 +330,12 @@ public SessionFactoryImpl(
 				close();
 			}
 			catch (Exception closeException) {
-				LOG.trace( "Eating error closing factory after failed instantiation" );
+				SESSION_FACTORY_LOGGER.eatingErrorClosingFactoryAfterFailedInstantiation();
 			}
 			throw e;
 		}
 
-		if ( LOG.isTraceEnabled() ) {
-			LOG.trace( "Instantiated factory: " + uuid );
-		}
+		SESSION_FACTORY_LOGGER.instantiatedFactory( uuid );
 	}
 
 	private JavaType<Object> tenantIdentifierType(SessionFactoryOptions options) {
@@ -762,7 +760,7 @@ public Interceptor getInterceptor() {
 	@Override
 	public Reference getReference() {
 		// from javax.naming.Referenceable
-		LOG.trace( "Returning a Reference to the factory" );
+		SESSION_FACTORY_LOGGER.returningReferenceToFactory();
 		return new Reference(
 				SessionFactoryImpl.class.getName(),
 				new StringRefAddr( "uuid", getUuid() ),
@@ -792,16 +790,14 @@ public void close() {
 				if ( getSessionFactoryOptions().getJpaCompliance().isJpaClosedComplianceEnabled() ) {
 					throw new IllegalStateException( "EntityManagerFactory is already closed" );
 				}
-
-				LOG.trace( "Already closed" );
+				SESSION_FACTORY_LOGGER.alreadyClosed();
 				return;
 			}
-
 			status = Status.CLOSING;
 		}
 
 		try {
-			LOG.closingFactory( getUuid() );
+			SESSION_FACTORY_LOGGER.closingFactory( uuid );
 			observer.sessionFactoryClosing( this );
 
 			// NOTE: the null checks below handle cases where close is called
@@ -1036,8 +1032,8 @@ private CurrentSessionContext createSessionContext(String sessionContextType) {
 									.getConstructor( new Class[]{ SessionFactoryImplementor.class } )
 									.newInstance( this );
 				}
-				catch ( Throwable t ) {
-					LOG.unableToConstructCurrentSessionContext( sessionContextType, t );
+				catch ( Throwable throwable ) {
+					SESSION_FACTORY_LOGGER.unableToConstructCurrentSessionContext( sessionContextType, throwable );
 					return null;
 				}
 		}
@@ -1109,9 +1105,9 @@ boolean connectionProviderHandlesConnectionSchema() {
 	 */
 	@Serial
 	private void writeObject(ObjectOutputStream out) throws IOException {
-		LOG.serializingFactory( getUuid() );
+		SESSION_FACTORY_LOGGER.serializingFactory( uuid );
 		out.defaultWriteObject();
-		LOG.trace( "Serialized factory" );
+		SESSION_FACTORY_LOGGER.serializedFactory();
 	}
 
 	/**
@@ -1124,9 +1120,9 @@ private void writeObject(ObjectOutputStream out) throws IOException {
 	 */
 	@Serial
 	private void readObject(ObjectInputStream in) throws IOException, ClassNotFoundException {
-		LOG.trace( "Deserializing factory" );
+		SESSION_FACTORY_LOGGER.deserializingFactory();
 		in.defaultReadObject();
-		LOG.deserializedFactory( getUuid() );
+		SESSION_FACTORY_LOGGER.deserializedFactory( uuid );
 	}
 
 	/**
@@ -1142,27 +1138,27 @@ private void readObject(ObjectInputStream in) throws IOException, ClassNotFoundE
 	 */
 	@Serial
 	private Object readResolve() throws InvalidObjectException {
-		LOG.trace( "Resolving serialized factory" );
-		return locateSessionFactoryOnDeserialization( getUuid(), name );
+		SESSION_FACTORY_LOGGER.trace( "Resolving serialized factory" );
+		return locateSessionFactoryOnDeserialization( uuid, name );
 	}
 
 	private static SessionFactory locateSessionFactoryOnDeserialization(String uuid, String name)
 			throws InvalidObjectException{
-		final SessionFactory uuidResult = SessionFactoryRegistry.INSTANCE.getSessionFactory( uuid );
+		final var uuidResult = SessionFactoryRegistry.INSTANCE.getSessionFactory( uuid );
 		if ( uuidResult != null ) {
-			if ( LOG.isTraceEnabled() ) {
-				LOG.trace( "Resolved factory by UUID: " + uuid );
+			if ( SESSION_FACTORY_LOGGER.isTraceEnabled() ) {
+				SESSION_FACTORY_LOGGER.resolvedFactoryByUuid( uuid );
 			}
 			return uuidResult;
 		}
 
 		// in case we were deserialized in a different JVM, look for an instance with the same name
 		// (provided we were given a name)
 		if ( name != null ) {
-			final SessionFactory namedResult = SessionFactoryRegistry.INSTANCE.getNamedSessionFactory( name );
+			final var namedResult = SessionFactoryRegistry.INSTANCE.getNamedSessionFactory( name );
 			if ( namedResult != null ) {
-				if ( LOG.isTraceEnabled() ) {
-					LOG.trace( "Resolved factory by name: " + name );
+				if ( SESSION_FACTORY_LOGGER.isTraceEnabled() ) {
+					SESSION_FACTORY_LOGGER.resolvedFactoryByName( name );
 				}
 				return namedResult;
 			}
@@ -1193,7 +1189,7 @@ void serialize(ObjectOutputStream oos) throws IOException {
 	 * @throws IOException indicates problems reading back serial data stream
 	 */
 	static SessionFactoryImpl deserialize(ObjectInputStream ois) throws IOException {
-		LOG.trace( "Resolving factory from deserialized session" );
+		SESSION_FACTORY_LOGGER.resolvingFactoryFromDeserializedSession();
 		final String uuid = ois.readUTF();
 		boolean isNamed = ois.readBoolean();
 		final String name = isNamed ? ois.readUTF() : null;

hibernate-core/src/main/java/org/hibernate/internal/SessionFactoryLogging.java

@@ -0,0 +1,106 @@
+/*
+ * SPDX-License-Identifier: Apache-2.0
+ * Copyright Red Hat Inc. and Hibernate Authors
+ */
+package org.hibernate.internal;
+
+import org.hibernate.Internal;
+import org.hibernate.internal.log.SubSystemLogging;
+
+import org.jboss.logging.BasicLogger;
+import org.jboss.logging.Logger;
+import org.jboss.logging.annotations.Cause;
+import org.jboss.logging.annotations.LogMessage;
+import org.jboss.logging.annotations.Message;
+import org.jboss.logging.annotations.MessageLogger;
+import org.jboss.logging.annotations.ValidIdRange;
+
+import java.lang.invoke.MethodHandles;
+import java.util.Map;
+
+import static org.jboss.logging.Logger.Level.DEBUG;
+import static org.jboss.logging.Logger.Level.TRACE;
+import static org.jboss.logging.Logger.Level.WARN;
+
+/**
+ * Sub-system logging related to SessionFactory and its registry
+ */
+@SubSystemLogging(
+		name = SessionFactoryLogging.NAME,
+		description = "Logging related to SessionFactory lifecycle, serialization, and registry/JNDI operations"
+)
+@MessageLogger(projectCode = "HHH")
+@ValidIdRange(min = 90006001, max = 90006100)
+@Internal
+public interface SessionFactoryLogging extends BasicLogger {
+	String NAME = SubSystemLogging.BASE + ".factory";
+
+	SessionFactoryLogging SESSION_FACTORY_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), SessionFactoryLogging.class, NAME );
+
+	// ---- SessionFactoryImpl related ---------------------------------------------------------------
+
+	@LogMessage(level = TRACE)
+	@Message("Building session factory")
+	void buildingSessionFactory();
+
+	@LogMessage(level = DEBUG)
+	@Message(value = "Instantiating factory [%s] with settings: %s", id = 90006001)
+	void instantiatingFactory(String uuid, Map<String, Object> settings);
+
+	@LogMessage(level = TRACE)
+	@Message("Eating error closing factory after failed instantiation")
+	void eatingErrorClosingFactoryAfterFailedInstantiation();
+
+	@LogMessage(level = TRACE)
+	@Message("Instantiated factory: %s")
+	void instantiatedFactory(String uuid);
+
+	@LogMessage(level = TRACE)
+	@Message("Returning a Reference to the factory")
+	void returningReferenceToFactory();
+
+	@LogMessage(level = TRACE)
+	@Message("Already closed")
+	void alreadyClosed();
+
+	@LogMessage(level = DEBUG)
+	@Message(value = "Closing factory [%s]", id = 90006005)
+	void closingFactory(String uuid);
+
+	@LogMessage(level = DEBUG)
+	@Message(value = "Serializing factory [%s]", id = 90006010)
+	void serializingFactory(String uuid);
+
+	@LogMessage(level = DEBUG)
+	@Message(value = "Deserialized factory [%s]", id = 90006011)
+	void deserializedFactory(String uuid);
+
+	@LogMessage(level = TRACE)
+	@Message("Serialized factory")
+	void serializedFactory();
+
+	@LogMessage(level = TRACE)
+	@Message("Deserializing factory")
+	void deserializingFactory();
+
+	@LogMessage(level = TRACE)
+	@Message("Resolving serialized factory")
+	void resolvingSerializedFactory();
+
+	@LogMessage(level = TRACE)
+	@Message("Resolved factory by UUID: %s")
+	void resolvedFactoryByUuid(String uuid);
+
+	@LogMessage(level = TRACE)
+	@Message("Resolved factory by name: %s")
+	void resolvedFactoryByName(String name);
+
+	@LogMessage(level = TRACE)
+	@Message("Resolving factory from deserialized session")
+	void resolvingFactoryFromDeserializedSession();
+
+	@LogMessage(level = WARN)
+	@Message(value = "Unable to construct current session context [%s]", id = 90006030)
+	void unableToConstructCurrentSessionContext(String sessionContextType, @Cause Throwable throwable);
+
+}