Skip to content

split out dedicated loggers for session and factory #10934

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 4 commits into from
Sep 13, 2025
Merged

split out dedicated loggers for session and factory #10934

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
4f82065
introduce SessionLogging
gavinking Sep 13, 2025
135b77c
introduce SessionFactoryLogging
gavinking Sep 13, 2025
1f3351a
move more logging to SessionLogging
gavinking Sep 13, 2025
17bb300
small fixes to new session/factory logging
gavinking Sep 13, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 10 additions & 14 deletions hibernate-core/src/main/java/org/hibernate/internal/AbstractSharedSessionContract.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -120,6 +120,7 @@

import static java.lang.Boolean.TRUE;
import static org.hibernate.boot.model.naming.Identifier.toIdentifier;
import static org.hibernate.internal.SessionLogging.SESSION_LOGGER;
import static org.hibernate.internal.util.StringHelper.isEmpty;
import static org.hibernate.query.sqm.internal.SqmUtil.verifyIsSelectStatement;

Expand All @@ -139,7 +140,6 @@
* @author Steve Ebersole
*/
public abstract class AbstractSharedSessionContract implements SharedSessionContractImplementor {
private static final CoreMessageLogger LOG = CoreLogging.messageLogger( SessionImpl.class );

private transient SessionFactoryImpl factory;
private transient SessionFactoryOptions factoryOptions;
Expand Down Expand Up @@ -282,13 +282,12 @@ protected final void setUpMultitenancy(SessionFactoryImplementor factory, LoadQu
}

private void logInconsistentOptions(SharedSessionCreationOptions sharedOptions) {
// TODO: these should probable be exceptions!
if ( sharedOptions.shouldAutoJoinTransactions() ) {
LOG.debug( "Session creation specified 'autoJoinTransactions', which is invalid in conjunction " +
"with sharing JDBC connection between sessions; ignoring" );
SESSION_LOGGER.invalidAutoJoinTransactionsWithSharedConnection();
}
if ( sharedOptions.getPhysicalConnectionHandlingMode() != connectionHandlingMode ) {
LOG.debug( "Session creation specified 'PhysicalConnectionHandlingMode' which is invalid in conjunction " +
"with sharing JDBC connection between sessions; ignoring" );
SESSION_LOGGER.invalidPhysicalConnectionHandlingModeWithSharedConnection();
}
}

Expand Down Expand Up @@ -357,15 +356,17 @@ void afterTransactionBeginEvents() {
}

void beforeTransactionCompletionEvents() {
SESSION_LOGGER.beforeTransactionCompletion();
try {
getInterceptor().beforeTransactionCompletion( getTransactionIfAccessible() );
}
catch (Throwable t) {
LOG.exceptionInBeforeTransactionCompletionInterceptor( t );
SESSION_LOGGER.exceptionInBeforeTransactionCompletionInterceptor( t );
}
}

void afterTransactionCompletionEvents(boolean successful) {
SESSION_LOGGER.afterTransactionCompletion( successful, false );
getEventListenerManager().transactionCompletion(successful);

final var statistics = getFactory().getStatistics();
Expand All @@ -377,7 +378,7 @@ void afterTransactionCompletionEvents(boolean successful) {
getInterceptor().afterTransactionCompletion( getTransactionIfAccessible() );
}
catch (Throwable t) {
LOG.exceptionInAfterTransactionCompletionInterceptor( t );
SESSION_LOGGER.exceptionInAfterTransactionCompletionInterceptor( t );
}
}

Expand Down Expand Up @@ -1686,9 +1687,7 @@ public SessionAssociationMarkers getSessionAssociationMarkers() {

@Serial
private void writeObject(ObjectOutputStream oos) throws IOException {
if ( LOG.isTraceEnabled() ) {
LOG.trace( "Serializing " + getClass().getSimpleName() + " [" );
}
SESSION_LOGGER.serializingSession( getSessionIdentifier() );


if ( !jdbcCoordinator.isReadyForSerialization() ) {
Expand Down Expand Up @@ -1721,13 +1720,10 @@ private void writeObject(ObjectOutputStream oos) throws IOException {

@Serial
private void readObject(ObjectInputStream ois) throws IOException, ClassNotFoundException, SQLException {
if ( LOG.isTraceEnabled() ) {
LOG.trace( "Deserializing " + getClass().getSimpleName() );
}

// ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
// Step 1 :: read back non-transient state...
ois.defaultReadObject();
SESSION_LOGGER.deserializingSession( getSessionIdentifier() );

// ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
// Step 2 :: read back transient state...
Expand Down
41 changes: 0 additions & 41 deletions hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,14 +9,12 @@
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;

import org.hibernate.HibernateException;
import org.hibernate.Internal;
import org.hibernate.JDBCException;
import org.hibernate.cache.CacheException;
import org.hibernate.id.IntegralDataTypeHolder;
import org.hibernate.type.SerializationException;
Expand Down Expand Up @@ -68,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);
Expand Down Expand Up @@ -113,14 +95,6 @@ public interface CoreMessageLogger extends BasicLogger {
id = 84)
void entityMappedAsNonAbstract(String name);

@LogMessage(level = ERROR)
@Message(value = "Exception in interceptor afterTransactionCompletion()", id = 87)
void exceptionInAfterTransactionCompletionInterceptor(@Cause Throwable e);

@LogMessage(level = ERROR)
@Message(value = "Exception in interceptor beforeTransactionCompletion()", id = 88)
void exceptionInBeforeTransactionCompletionInterceptor(@Cause Throwable e);

@LogMessage(level = INFO)
@Message(value = "Sub-resolver threw unexpected exception, continuing to next: %s", id = 89)
void exceptionInSubResolver(String message);
Expand Down Expand Up @@ -307,10 +281,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();
Expand Down Expand Up @@ -589,12 +559,6 @@ void cannotResolveNonNullableTransientDependencies(
id = 516)
void enhancementDiscoveryFailed(String className, @Cause Throwable cause);

@LogMessage(level = DEBUG)
@Message(value = "JDBCException was thrown for a transaction marked for rollback. " +
" This is probably due to an operation failing fast due to the transaction being marked for rollback.",
id = 520)
void jdbcExceptionThrownWithTransactionRolledBack(@Cause JDBCException e);

@LogMessage(level = DEBUG)
@Message(value = "Flushing and evicting managed instance of type [%s] before removing detached instance with same id",
id = 530)
Expand All @@ -614,11 +578,6 @@ void unableToLocateStaticMetamodelField(
String name,
String name2);

@LogMessage(level = DEBUG)
@Message(value = "Returning null (as required by JPA spec) rather than throwing EntityNotFoundException " +
"since the entity of type '%s' with id [%s] does not exist", id = 15013)
void ignoringEntityNotFound(String entityName, String identifier);

@LogMessage(level = DEBUG)
@Message(
id = 15015,
Expand Down
50 changes: 23 additions & 27 deletions hibernate-core/src/main/java/org/hibernate/internal/SessionFactoryImpl.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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;
Expand All @@ -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 );

Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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() ),
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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;
}
}
Expand Down Expand Up @@ -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();
}

/**
Expand All @@ -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 );
}

/**
Expand All @@ -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.resolvingSerializedFactory();
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;
}
Expand Down Expand Up @@ -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;
Expand Down
Loading