diff --git a/hibernate-core/src/main/java/org/hibernate/engine/internal/SessionMetricsLogger.java b/hibernate-core/src/main/java/org/hibernate/engine/internal/SessionMetricsLogger.java new file mode 100644 index 000000000000..1bc782582807 --- /dev/null +++ b/hibernate-core/src/main/java/org/hibernate/engine/internal/SessionMetricsLogger.java @@ -0,0 +1,73 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * Copyright Red Hat Inc. and Hibernate Authors + */ +package org.hibernate.engine.internal; + +import org.hibernate.internal.log.SubSystemLogging; +import org.jboss.logging.BasicLogger; +import org.jboss.logging.Logger; +import org.jboss.logging.annotations.LogMessage; +import org.jboss.logging.annotations.Message; +import org.jboss.logging.annotations.MessageLogger; + +import java.lang.invoke.MethodHandles; + +import static org.jboss.logging.Logger.Level.DEBUG; + +@MessageLogger( projectCode = "HHH" ) +@SubSystemLogging( + name = SessionMetricsLogger.LOGGER_NAME, + description = "Logging related to session metrics" +) +public interface SessionMetricsLogger extends BasicLogger { + String LOGGER_NAME = "org.hibernate.session.metrics"; + + SessionMetricsLogger SESSION_METRICS_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), SessionMetricsLogger.class, LOGGER_NAME ); + + @LogMessage(level = DEBUG) + @Message( + id = 401, + value = """ + Logging session metrics: + %s ns acquiring %s JDBC connections + %s ns releasing %s JDBC connections + %s ns preparing %s JDBC statements + %s ns executing %s JDBC statements + %s ns executing %s JDBC batches + %s ns performing %s second-level cache puts + %s ns performing %s second-level cache hits + %s ns performing %s second-level cache misses + %s ns executing %s flushes (flushing a total of %s entities and %s collections) + %s ns executing %s pre-partial-flushes + %s ns executing %s partial-flushes (flushing a total of %s entities and %s collections) + """ + ) + void sessionMetrics( + long jdbcConnectionAcquisitionTime, + int jdbcConnectionAcquisitionCount, + long jdbcConnectionReleaseTime, + int jdbcConnectionReleaseCount, + long jdbcPrepareStatementTime, + int jdbcPrepareStatementCount, + long jdbcExecuteStatementTime, + int jdbcExecuteStatementCount, + long jdbcExecuteBatchTime, + int jdbcExecuteBatchCount, + long cachePutTime, + int cachePutCount, + long cacheHitTime, + int cacheHitCount, + long cacheMissTime, + int cacheMissCount, + long flushTime, + int flushCount, + long flushEntityCount, + long flushCollectionCount, + long prePartialFlushTime, + int prePartialFlushCount, + long partialFlushTime, + int partialFlushCount, + long partialFlushEntityCount, + long partialFlushCollectionCount); +} diff --git a/hibernate-core/src/main/java/org/hibernate/engine/internal/StatisticalLoggingSessionEventListener.java b/hibernate-core/src/main/java/org/hibernate/engine/internal/StatisticalLoggingSessionEventListener.java index fbab0cd8df25..8492a8965629 100644 --- a/hibernate-core/src/main/java/org/hibernate/engine/internal/StatisticalLoggingSessionEventListener.java +++ b/hibernate-core/src/main/java/org/hibernate/engine/internal/StatisticalLoggingSessionEventListener.java @@ -5,9 +5,8 @@ package org.hibernate.engine.internal; import org.hibernate.SessionEventListener; -import org.hibernate.internal.CoreMessageLogger; -import static org.hibernate.internal.CoreLogging.messageLogger; +import static org.hibernate.engine.internal.SessionMetricsLogger.SESSION_METRICS_LOGGER; /** * Tracks and logs certain session-level metrics. @@ -15,7 +14,6 @@ * @author Steve Ebersole */ public class StatisticalLoggingSessionEventListener implements SessionEventListener { - private static final CoreMessageLogger LOG = messageLogger( "org.hibernate.session.metrics" ); /** * Used by SettingsFactory (in conjunction with stats being enabled) to determine whether to apply this listener @@ -23,7 +21,7 @@ public class StatisticalLoggingSessionEventListener implements SessionEventListe * @return {@code true} if logging is enabled for this listener. */ public static boolean isLoggingEnabled() { - return LOG.isDebugEnabled(); + return SESSION_METRICS_LOGGER.isDebugEnabled(); } // cumulative state ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ @@ -276,7 +274,7 @@ public void partialFlushEnd(int numberOfEntities, int numberOfCollections) { @Override public void end() { if ( isLoggingEnabled() ) { - LOG.sessionMetrics( + SESSION_METRICS_LOGGER.sessionMetrics( jdbcConnectionAcquisitionTime, jdbcConnectionAcquisitionCount, jdbcConnectionReleaseTime, diff --git a/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java b/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java index 967621034af7..92cffbe91a45 100644 --- a/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java +++ b/hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java @@ -154,10 +154,6 @@ void expectedType(String name, @Message(value = "Handling transient entity in delete processing", id = 114) void handlingTransientEntity(); - @LogMessage(level = DEBUG) - @Message(value = "HQL: %s, time: %sms, rows: %s", id = 117) - void hql(String hql, Long valueOf, Long valueOf2); - @LogMessage(level = WARN) @Message(value = "HSQLDB supports only READ_UNCOMMITTED isolation", id = 118) void hsqldbSupportsOnlyReadCommittedIsolation(); @@ -515,8 +511,6 @@ void cannotResolveNonNullableTransientDependencies( ) void nonCompliantMapConversion(String collectionRole); - // 458-466 reserved for use by main branch (ORM 5.0.0) - @LogMessage(level = DEBUG) @Message(value = "Creating pooled optimizer (lo) with [incrementSize=%s; returnClass=%s]", id = 467) void creatingPooledLoOptimizer(int incrementSize, String name); @@ -689,22 +683,6 @@ void unableToLocateStaticMetamodelField( @Message(value = "Logical connection closed", id = 457) void logicalConnectionClosed(); - @LogMessage(level = TRACE) - @Message(value = "Statistics initialized", id = 460) - void statisticsInitialized(); - - @LogMessage(level = TRACE) - @Message(value = "Statistics collection enabled", id = 461) - void statisticsEnabled(); - - @LogMessage(level = TRACE) - @Message(value = "Statistics collection disabled", id = 462) - void statisticsDisabled(); - - @LogMessage(level = TRACE) - @Message(value = "Statistics reset", id = 463) - void statisticsReset(); - @LogMessage(level = TRACE) @Message(value = "Initializing service: %s", id = 500) void initializingService(String serviceRole); @@ -720,124 +698,4 @@ void unableToLocateStaticMetamodelField( @LogMessage(level = WARN) @Message(value = "Encountered request for service by non-primary service role [%s -> %s]", id = 450) void alternateServiceRole(String requestedRole, String targetRole); - - @LogMessage(level = DEBUG) - @Message( - id = 401, - value = """ - Logging session metrics: - %s ns acquiring %s JDBC connections - %s ns releasing %s JDBC connections - %s ns preparing %s JDBC statements - %s ns executing %s JDBC statements - %s ns executing %s JDBC batches - %s ns performing %s second-level cache puts - %s ns performing %s second-level cache hits - %s ns performing %s second-level cache misses - %s ns executing %s flushes (flushing a total of %s entities and %s collections) - %s ns executing %s pre-partial-flushes - %s ns executing %s partial-flushes (flushing a total of %s entities and %s collections) - """ - ) - void sessionMetrics( - long jdbcConnectionAcquisitionTime, - int jdbcConnectionAcquisitionCount, - long jdbcConnectionReleaseTime, - int jdbcConnectionReleaseCount, - long jdbcPrepareStatementTime, - int jdbcPrepareStatementCount, - long jdbcExecuteStatementTime, - int jdbcExecuteStatementCount, - long jdbcExecuteBatchTime, - int jdbcExecuteBatchCount, - long cachePutTime, - int cachePutCount, - long cacheHitTime, - int cacheHitCount, - long cacheMissTime, - int cacheMissCount, - long flushTime, - int flushCount, - long flushEntityCount, - long flushCollectionCount, - long prePartialFlushTime, - int prePartialFlushCount, - long partialFlushTime, - int partialFlushCount, - long partialFlushEntityCount, - long partialFlushCollectionCount); - - @LogMessage(level = INFO) - @Message( - id = 400, - value = """ - Logging statistics: - Start time: %s - Sessions opened (closed): %s (%s) - Transactions started (successful): %s (%s) - Optimistic lock failures: %s - Flushes: %s - Connections obtained: %s - Statements prepared (closed): %s (%s) - Second-level cache puts: %s - Second-level cache hits (misses): %s (%s) - Entities loaded: %s - Entities fetched: %s (minimize this) - Entities updated, upserted, inserted, deleted: %s, %s, %s, %s - Collections loaded: %s - Collections fetched: %s (minimize this) - Collections updated, removed, recreated: %s, %s, %s - Natural id queries executed on database: %s - Natural id cache puts: %s - Natural id cache hits (misses): %s (%s) - Max natural id query execution time: %s ms - Queries executed on database: %s - Query cache puts: %s - Query cache hits (misses): %s (%s) - Max query execution time: %s ms - Update timestamps cache puts: %s - Update timestamps cache hits (misses): %s (%s) - Query plan cache hits (misses): %s (%s) - """ - ) - void logStatistics( - long startTime, - long sessionOpenCount, - long sessionCloseCount, - long transactionCount, - long committedTransactionCount, - long optimisticFailureCount, - long flushCount, - long connectCount, - long prepareStatementCount, - long closeStatementCount, - long secondLevelCachePutCount, - long secondLevelCacheHitCount, - long secondLevelCacheMissCount, - long entityLoadCount, - long entityFetchCount, - long entityUpdateCount, - long entityUpsertCount, - long entityInsertCount, - long entityDeleteCount, - long collectionLoadCount, - long collectionFetchCount, - long collectionUpdateCount, - long collectionRemoveCount, - long collectionRecreateCount, - long naturalIdQueryExecutionCount, - long naturalIdCachePutCount, - long naturalIdCacheHitCount, - long naturalIdCacheMissCount, - long naturalIdQueryExecutionMaxTime, - long queryExecutionCount, - long queryCachePutCount, - long queryCacheHitCount, - long queryCacheMissCount, - long queryExecutionMaxTime, - long updateTimestampsCachePutCount, - long updateTimestampsCacheHitCount, - long updateTimestampsCacheMissCount, - long queryPlanCacheHitCount, - long queryPlanCacheMissCount); } diff --git a/hibernate-core/src/main/java/org/hibernate/internal/log/StatisticsLogger.java b/hibernate-core/src/main/java/org/hibernate/internal/log/StatisticsLogger.java new file mode 100644 index 000000000000..e7c12ac90ad5 --- /dev/null +++ b/hibernate-core/src/main/java/org/hibernate/internal/log/StatisticsLogger.java @@ -0,0 +1,122 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * Copyright Red Hat Inc. and Hibernate Authors + */ +package org.hibernate.internal.log; + +import org.jboss.logging.BasicLogger; +import org.jboss.logging.Logger; +import org.jboss.logging.annotations.LogMessage; +import org.jboss.logging.annotations.Message; +import org.jboss.logging.annotations.MessageLogger; + +import java.lang.invoke.MethodHandles; + +import static org.jboss.logging.Logger.Level.DEBUG; +import static org.jboss.logging.Logger.Level.INFO; +import static org.jboss.logging.Logger.Level.TRACE; + +@MessageLogger( projectCode = "HHH" ) +@SubSystemLogging( + name = StatisticsLogger.LOGGER_NAME, + description = "Logging related to statistics" +) +public interface StatisticsLogger extends BasicLogger { + String LOGGER_NAME = "org.hibernate.statistics"; + + StatisticsLogger STATISTICS_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), StatisticsLogger.class, LOGGER_NAME ); + + @LogMessage(level = TRACE) + @Message(value = "Statistics initialized", id = 460) + void statisticsInitialized(); + + @LogMessage(level = TRACE) + @Message(value = "Statistics collection enabled", id = 461) + void statisticsEnabled(); + + @LogMessage(level = TRACE) + @Message(value = "Statistics collection disabled", id = 462) + void statisticsDisabled(); + + @LogMessage(level = TRACE) + @Message(value = "Statistics reset", id = 463) + void statisticsReset(); + + @LogMessage(level = DEBUG) + @Message(value = "Query: %s, time: %sms, rows: %s", id = 117) + void queryExecuted(String query, Long time, Long rows); + + @LogMessage(level = INFO) + @Message( + id = 400, + value = """ + Logging statistics: + Start time: %s + Sessions opened (closed): %s (%s) + Transactions started (successful): %s (%s) + Optimistic lock failures: %s + Flushes: %s + Connections obtained: %s + Statements prepared (closed): %s (%s) + Second-level cache puts: %s + Second-level cache hits (misses): %s (%s) + Entities loaded: %s + Entities fetched: %s (minimize this) + Entities updated, upserted, inserted, deleted: %s, %s, %s, %s + Collections loaded: %s + Collections fetched: %s (minimize this) + Collections updated, removed, recreated: %s, %s, %s + Natural id queries executed on database: %s + Natural id cache puts: %s + Natural id cache hits (misses): %s (%s) + Max natural id query execution time: %s ms + Queries executed on database: %s + Query cache puts: %s + Query cache hits (misses): %s (%s) + Max query execution time: %s ms + Update timestamps cache puts: %s + Update timestamps cache hits (misses): %s (%s) + Query plan cache hits (misses): %s (%s) + """ + ) + void logStatistics( + long startTime, + long sessionOpenCount, + long sessionCloseCount, + long transactionCount, + long committedTransactionCount, + long optimisticFailureCount, + long flushCount, + long connectCount, + long prepareStatementCount, + long closeStatementCount, + long secondLevelCachePutCount, + long secondLevelCacheHitCount, + long secondLevelCacheMissCount, + long entityLoadCount, + long entityFetchCount, + long entityUpdateCount, + long entityUpsertCount, + long entityInsertCount, + long entityDeleteCount, + long collectionLoadCount, + long collectionFetchCount, + long collectionUpdateCount, + long collectionRemoveCount, + long collectionRecreateCount, + long naturalIdQueryExecutionCount, + long naturalIdCachePutCount, + long naturalIdCacheHitCount, + long naturalIdCacheMissCount, + long naturalIdQueryExecutionMaxTime, + long queryExecutionCount, + long queryCachePutCount, + long queryCacheHitCount, + long queryCacheMissCount, + long queryExecutionMaxTime, + long updateTimestampsCachePutCount, + long updateTimestampsCacheHitCount, + long updateTimestampsCacheMissCount, + long queryPlanCacheHitCount, + long queryPlanCacheMissCount); +} diff --git a/hibernate-core/src/main/java/org/hibernate/sql/exec/internal/JdbcSelectExecutorStandardImpl.java b/hibernate-core/src/main/java/org/hibernate/sql/exec/internal/JdbcSelectExecutorStandardImpl.java index 1018af682883..97e2b01c2a93 100644 --- a/hibernate-core/src/main/java/org/hibernate/sql/exec/internal/JdbcSelectExecutorStandardImpl.java +++ b/hibernate-core/src/main/java/org/hibernate/sql/exec/internal/JdbcSelectExecutorStandardImpl.java @@ -37,6 +37,7 @@ import org.hibernate.sql.results.spi.ResultsConsumer; import org.hibernate.sql.results.spi.RowReader; import org.hibernate.sql.results.spi.RowTransformer; +import org.hibernate.stat.spi.StatisticsImplementor; import org.hibernate.type.BasicType; import org.hibernate.type.descriptor.java.JavaType; import org.hibernate.type.spi.TypeConfiguration; @@ -44,6 +45,7 @@ import static org.hibernate.internal.util.NullnessHelper.coalesceSuppliedValues; import static org.hibernate.internal.util.collections.ArrayHelper.indexOf; import static org.hibernate.sql.exec.SqlExecLogger.SQL_EXEC_LOGGER; +import static org.hibernate.internal.log.StatisticsLogger.STATISTICS_LOGGER; /** * Standard JdbcSelectExecutor implementation used by Hibernate, @@ -208,19 +210,27 @@ public boolean shouldReturnProxies() { ); if ( stats ) { - final long endTime = System.nanoTime(); - final long milliseconds = - TimeUnit.MILLISECONDS.convert( endTime - startTime, TimeUnit.NANOSECONDS ); - statistics.queryExecuted( - executionContext.getQueryIdentifier( jdbcSelect.getSqlString() ), - getResultSize( result ), - milliseconds - ); + logQueryStatistics( jdbcSelect, executionContext, startTime, result, statistics ); } return result; } + private void logQueryStatistics( + JdbcOperationQuerySelect jdbcSelect, + ExecutionContext executionContext, + long startTime, + Object result, + StatisticsImplementor statistics) { + final String query = executionContext.getQueryIdentifier( jdbcSelect.getSqlString() ); + final long endTime = System.nanoTime(); + final long milliseconds = + TimeUnit.MILLISECONDS.convert( endTime - startTime, TimeUnit.NANOSECONDS ); + final int rows = getResultSize( result ); + STATISTICS_LOGGER.queryExecuted( query, milliseconds, (long) rows ); + statistics.queryExecuted( query, rows, milliseconds ); + } + private static RowTransformer getRowTransformer(ExecutionContext executionContext, JdbcValues jdbcValues) { @SuppressWarnings("unchecked") final var tupleTransformer = diff --git a/hibernate-core/src/main/java/org/hibernate/sql/results/graph/collection/CollectionLoadingLogger.java b/hibernate-core/src/main/java/org/hibernate/sql/results/graph/collection/CollectionLoadingLogger.java deleted file mode 100644 index 63c2ee31e233..000000000000 --- a/hibernate-core/src/main/java/org/hibernate/sql/results/graph/collection/CollectionLoadingLogger.java +++ /dev/null @@ -1,27 +0,0 @@ -/* - * SPDX-License-Identifier: Apache-2.0 - * Copyright Red Hat Inc. and Hibernate Authors - */ -package org.hibernate.sql.results.graph.collection; - -import org.hibernate.internal.log.SubSystemLogging; -import org.hibernate.sql.results.LoadingLogger; - -import org.jboss.logging.BasicLogger; -import org.jboss.logging.Logger; - -/** - * @author Steve Ebersole - */ -@SubSystemLogging( - name = CollectionLoadingLogger.LOGGER_NAME, - description = "Logging related to collection loading" -) -public interface CollectionLoadingLogger extends BasicLogger { - String LOGGER_NAME = LoadingLogger.LOGGER_NAME + ".collection"; - - /** - * Static access to the logging instance - */ - Logger COLL_LOAD_LOGGER = LoadingLogger.subLogger( LOGGER_NAME ); -} diff --git a/hibernate-core/src/main/java/org/hibernate/sql/results/graph/entity/EntityLoadingLogging.java b/hibernate-core/src/main/java/org/hibernate/sql/results/graph/entity/EntityLoadingLogging.java deleted file mode 100644 index 4b3dada86055..000000000000 --- a/hibernate-core/src/main/java/org/hibernate/sql/results/graph/entity/EntityLoadingLogging.java +++ /dev/null @@ -1,25 +0,0 @@ -/* - * SPDX-License-Identifier: Apache-2.0 - * Copyright Red Hat Inc. and Hibernate Authors - */ -package org.hibernate.sql.results.graph.entity; - -import org.hibernate.Internal; -import org.hibernate.internal.log.SubSystemLogging; -import org.hibernate.sql.results.LoadingLogger; -import org.hibernate.sql.results.graph.embeddable.EmbeddableLoadingLogger; - -import org.jboss.logging.Logger; - -/** - * @author Steve Ebersole - */ -@SubSystemLogging( - name = EmbeddableLoadingLogger.LOGGER_NAME, - description = "Logging related to entity loading" -) -@Internal -public interface EntityLoadingLogging { - String LOGGER_NAME = LoadingLogger.LOGGER_NAME + ".entity"; - Logger ENTITY_LOADING_LOGGER = Logger.getLogger( LOGGER_NAME ); -} diff --git a/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsImpl.java b/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsImpl.java index 87eb748ea427..5bad280404ad 100644 --- a/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsImpl.java +++ b/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsImpl.java @@ -20,7 +20,6 @@ import org.hibernate.cache.spi.QueryResultsRegion; import org.hibernate.cache.spi.Region; import org.hibernate.engine.spi.SessionFactoryImplementor; -import org.hibernate.internal.CoreMessageLogger; import org.hibernate.internal.util.NullnessUtil; import org.hibernate.metamodel.model.domain.NavigableRole; import org.hibernate.metamodel.spi.MappingMetamodelImplementor; @@ -32,7 +31,7 @@ import org.checkerframework.checker.initialization.qual.UnknownInitialization; import org.checkerframework.checker.nullness.qual.Nullable; -import static org.hibernate.internal.CoreLogging.messageLogger; +import static org.hibernate.internal.log.StatisticsLogger.STATISTICS_LOGGER; /** * Implementation of {@link Statistics} based on the {@link java.util.concurrent} package. @@ -42,8 +41,6 @@ */ public class StatisticsImpl implements StatisticsImplementor, Service { - private static final CoreMessageLogger LOG = messageLogger( StatisticsImpl.class ); - private final MappingMetamodelImplementor metamodel; private final CacheImplementor cache; @@ -212,7 +209,7 @@ public void clear() { resetStart(); - LOG.statisticsReset(); + STATISTICS_LOGGER.statisticsReset(); } private void resetStart(@UnknownInitialization StatisticsImpl this) { @@ -238,10 +235,10 @@ public boolean isStatisticsEnabled() { public void setStatisticsEnabled(boolean enabled) { isStatisticsEnabled = enabled; if ( enabled ) { - LOG.statisticsEnabled(); + STATISTICS_LOGGER.statisticsEnabled(); } else { - LOG.statisticsDisabled(); + STATISTICS_LOGGER.statisticsDisabled(); } } @@ -729,8 +726,7 @@ public long getQueryExecutionMaxTime() { } @Override - public void queryExecuted(String hql, int rows, long time) { - LOG.hql( hql, time, (long) rows ); + public void queryExecuted(String query, int rows, long time) { queryExecutionCount.increment(); boolean isLongestQuery; @@ -741,11 +737,11 @@ public void queryExecuted(String hql, int rows, long time) { // nothing to do here given the odd loop structure... } if ( isLongestQuery ) { - queryExecutionMaxTimeQueryString = hql; + queryExecutionMaxTimeQueryString = query; } - if ( hql != null ) { - getQueryStatistics( hql ).executed( rows, time ); + if ( query != null ) { + getQueryStatistics( query ).executed( rows, time ); } } @@ -911,7 +907,7 @@ public void endTransaction(boolean success) { @Override public void logSummary() { - LOG.logStatistics( + STATISTICS_LOGGER.logStatistics( startTime.toEpochMilli(), sessionOpenCount.sum(), sessionCloseCount.sum(), diff --git a/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsInitiator.java b/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsInitiator.java index 132f59f0bcef..a1532e9cd4d3 100644 --- a/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsInitiator.java +++ b/hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsInitiator.java @@ -7,8 +7,6 @@ import org.hibernate.HibernateException; import org.hibernate.boot.registry.classloading.spi.ClassLoaderService; import org.hibernate.engine.config.spi.ConfigurationService; -import org.hibernate.internal.CoreLogging; -import org.hibernate.internal.CoreMessageLogger; import org.hibernate.service.spi.ServiceRegistryImplementor; import org.hibernate.service.spi.SessionFactoryServiceInitiator; import org.hibernate.service.spi.SessionFactoryServiceInitiatorContext; @@ -20,14 +18,13 @@ import static org.hibernate.cfg.StatisticsSettings.STATS_BUILDER; +import static org.hibernate.internal.log.StatisticsLogger.STATISTICS_LOGGER; /** * @author Steve Ebersole */ public class StatisticsInitiator implements SessionFactoryServiceInitiator { - private static final CoreMessageLogger LOG = CoreLogging.messageLogger( StatisticsInitiator.class ); - public static final StatisticsInitiator INSTANCE = new StatisticsInitiator(); @Override @@ -43,7 +40,7 @@ public StatisticsImplementor initiateService(SessionFactoryServiceInitiatorConte final var statisticsFactory = statisticsFactory( configValue, context.getServiceRegistry() ); final var statistics = statisticsFactory.buildStatistics( context.getSessionFactory() ); final boolean enabled = context.getSessionFactoryOptions().isStatisticsEnabled(); - LOG.statisticsInitialized(); + STATISTICS_LOGGER.statisticsInitialized(); statistics.setStatisticsEnabled( enabled ); return statistics; } diff --git a/hibernate-core/src/main/java/org/hibernate/stat/spi/StatisticsImplementor.java b/hibernate-core/src/main/java/org/hibernate/stat/spi/StatisticsImplementor.java index bd32fbfb25c8..28ec8450b033 100644 --- a/hibernate-core/src/main/java/org/hibernate/stat/spi/StatisticsImplementor.java +++ b/hibernate-core/src/main/java/org/hibernate/stat/spi/StatisticsImplementor.java @@ -242,13 +242,13 @@ public interface StatisticsImplementor extends Statistics, Service { void queryCacheMiss(String hql, String regionName); /** - * Callback indicating execution of a sql/hql query + * Callback indicating execution of a SQL or HQL query * - * @param hql The query + * @param query The query * @param rows Number of rows returned * @param time execution time */ - void queryExecuted(String hql, int rows, long time); + void queryExecuted(String query, int rows, long time); /** * Callback indicating a hit to the timestamp cache diff --git a/hibernate-core/src/test/java/org/hibernate/orm/test/loading/EntityLoadingLoggingTest.java b/hibernate-core/src/test/java/org/hibernate/orm/test/loading/EntityLoadingLoggingTest.java deleted file mode 100644 index 1f74da6f8185..000000000000 --- a/hibernate-core/src/test/java/org/hibernate/orm/test/loading/EntityLoadingLoggingTest.java +++ /dev/null @@ -1,120 +0,0 @@ -/* - * SPDX-License-Identifier: Apache-2.0 - * Copyright Red Hat Inc. and Hibernate Authors - */ -package org.hibernate.orm.test.loading; - -import org.hibernate.sql.results.graph.entity.EntityLoadingLogging; - -import org.hibernate.testing.logger.LogInspectionHelper; -import org.hibernate.testing.logger.TriggerOnPrefixLogListener; -import org.hibernate.testing.orm.junit.DomainModel; -import org.hibernate.testing.orm.junit.Jira; -import org.hibernate.testing.orm.junit.SessionFactory; -import org.hibernate.testing.orm.junit.SessionFactoryScope; -import org.junit.jupiter.api.AfterAll; -import org.junit.jupiter.api.AfterEach; -import org.junit.jupiter.api.BeforeAll; -import org.junit.jupiter.api.BeforeEach; -import org.junit.jupiter.api.Test; - -import jakarta.persistence.Entity; -import jakarta.persistence.GeneratedValue; -import jakarta.persistence.Id; -import jakarta.persistence.ManyToOne; - -import static org.assertj.core.api.Assertions.assertThat; - -@SessionFactory -@DomainModel( annotatedClasses = { - EntityLoadingLoggingTest.Parent.class, - EntityLoadingLoggingTest.Child.class -} ) -@Jira( "https://hibernate.atlassian.net/browse/HHH-16234" ) -public class EntityLoadingLoggingTest { - private TriggerOnPrefixLogListener trigger; - - @BeforeAll - public void setUp(SessionFactoryScope scope) { - scope.inTransaction( session -> { - final Parent parent = new Parent( "parent_1" ); - final Child child = new Child( parent ); - session.persist( parent ); - session.persist( child ); - } ); - } - - @BeforeEach - public void setUp() { - trigger = new TriggerOnPrefixLogListener( "(EntityResultInitializer) Created new entity instance" ); - LogInspectionHelper.registerListener( trigger, EntityLoadingLogging.ENTITY_LOADING_LOGGER ); - } - - @AfterEach - public void reset() { - trigger.reset(); - } - - @AfterAll - public static void tearDown(SessionFactoryScope scope) { - LogInspectionHelper.clearAllListeners( EntityLoadingLogging.ENTITY_LOADING_LOGGER ); - scope.getSessionFactory().getSchemaManager().truncate(); - } - - @Test - public void test(SessionFactoryScope scope) { - scope.inTransaction( session -> { - final Child child = session.find( Child.class, 1L ); - assertThat( child.getParent().getId() ).isEqualTo( "parent_1" ); - // uncomment logger.results-loading-entity.name in log4j2.properties to verify log - // assertThat( trigger.wasTriggered() ).as( "Log should be triggered" ).isTrue(); - } ); - } - - @Entity( name = "Parent" ) - public static class Parent { - @Id - private String id; - - public Parent() { - } - - public Parent(String id) { - this.id = id; - } - - public String getId() { - return id; - } - } - - @Entity( name = "Child" ) - public static class Child { - @Id - @GeneratedValue - private Long id; - - @ManyToOne( optional = false ) - private Parent parent; - - public Child() { - } - - public Child(Parent parent) { - this.parent = parent; - } - - public Long getId() { - return id; - } - - public Parent getParent() { - return parent; - } - - @Override - public String toString() { - return id + "-" + parent.getId(); - } - } -}