Hibernate
/
hibernate-orm
mirror of https://github.com/hibernate/hibernate-orm
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

HHH-18907 fix weird way of enabling logging of session metric 

hibernate.session.events.log is now obsolete

also deprecate obsolete BaseSessionEventListener class
This commit is contained in:
Gavin King 2024-12-04 01:30:17 +01:00
parent a1b4773496
commit c9fa8aabab
12 changed files with 142 additions and 204 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

95
hibernate-core/src/main/java/org/hibernate/BaseSessionEventListener.java
View File

@ -5,97 +5,14 @@
package org.hibernate;
/**
* A no-op implementation of SessionEventListener. Intended as a convenient base class for developing
* SessionEventListener implementations.
* A noop implementation of {@link SessionEventListener}.
* Intended as a convenient base class for developing
* {@code SessionEventListener} implementations.
*
* @author Steve Ebersole
*
* @deprecated Just implement {@link SessionEventListener} directly.
*/
@Deprecated(since = "7", forRemoval = true)
public class BaseSessionEventListener implements SessionEventListener {
@Override
public void transactionCompletion(boolean successful) {
}
@Override
public void jdbcConnectionAcquisitionStart() {
}
@Override
public void jdbcConnectionAcquisitionEnd() {
}
@Override
public void jdbcConnectionReleaseStart() {
}
@Override
public void jdbcConnectionReleaseEnd() {
}
@Override
public void jdbcPrepareStatementStart() {
}
@Override
public void jdbcPrepareStatementEnd() {
}
@Override
public void jdbcExecuteStatementStart() {
}
@Override
public void jdbcExecuteStatementEnd() {
}
@Override
public void jdbcExecuteBatchStart() {
}
@Override
public void jdbcExecuteBatchEnd() {
}
@Override
public void cachePutStart() {
}
@Override
public void cachePutEnd() {
}
@Override
public void cacheGetStart() {
}
@Override
public void cacheGetEnd(boolean hit) {
}
@Override
public void flushStart() {
}
@Override
public void flushEnd(int numberOfEntities, int numberOfCollections) {
}
@Override
public void partialFlushStart() {
}
@Override
public void partialFlushEnd(int numberOfEntities, int numberOfCollections) {
}
@Override
public void dirtyCalculationStart() {
}
@Override
public void dirtyCalculationEnd(boolean dirty) {
}
@Override
public void end() {
}
}

4
hibernate-core/src/main/java/org/hibernate/SessionEventListener.java
View File

@ -15,8 +15,8 @@ import java.io.Serializable;
* sessions may be registered using the configuration property
* {@value org.hibernate.cfg.AvailableSettings#AUTO_SESSION_EVENTS_LISTENER}.
* A new instance of the class will be created for each new session.
* <p>
* <em>This an incubating API, subject to change.</em>
*
* @apiNote This an incubating API, subject to change.
*
* @see org.hibernate.cfg.AvailableSettings#AUTO_SESSION_EVENTS_LISTENER
* @see SessionBuilder#eventListeners(SessionEventListener...)

4
hibernate-core/src/main/java/org/hibernate/boot/internal/SessionFactoryOptionsBuilder.java
View File

@ -100,7 +100,6 @@ import static org.hibernate.cfg.AvailableSettings.IN_CLAUSE_PARAMETER_PADDING;
import static org.hibernate.cfg.AvailableSettings.JDBC_TIME_ZONE;
import static org.hibernate.cfg.AvailableSettings.JPA_CALLBACKS_ENABLED;
import static org.hibernate.cfg.AvailableSettings.JTA_TRACK_BY_THREAD;
import static org.hibernate.cfg.AvailableSettings.LOG_SESSION_METRICS;
import static org.hibernate.cfg.AvailableSettings.MAX_FETCH_DEPTH;
import static org.hibernate.cfg.AvailableSettings.MULTI_TENANT_IDENTIFIER_RESOLVER;
import static org.hibernate.cfg.AvailableSettings.ORDER_INSERTS;
@ -357,8 +356,7 @@ public class SessionFactoryOptionsBuilder implements SessionFactoryOptions {
? null
: strategySelector.selectStrategyImplementor( SessionEventListener.class, autoSessionEventsListenerName );
final boolean logSessionMetrics = configurationService.getSetting( LOG_SESSION_METRICS, BOOLEAN, statisticsEnabled );
this.baselineSessionEventsListenerBuilder = new BaselineSessionEventsListenerBuilder( logSessionMetrics, autoSessionEventsListener );
this.baselineSessionEventsListenerBuilder = new BaselineSessionEventsListenerBuilder( autoSessionEventsListener );
this.customEntityDirtinessStrategy = strategySelector.resolveDefaultableStrategy(
CustomEntityDirtinessStrategy.class,

3
hibernate-core/src/main/java/org/hibernate/cache/spi/SecondLevelCacheLogger.java vendored
View File

@ -84,6 +84,7 @@ public interface SecondLevelCacheLogger extends BasicLogger {
" You can disable this warning by setting '%2$s' to '%3$s'.",
id = NAMESPACE + 6
)
@SuppressWarnings( "unused" ) // used by hibernate-jcache
void missingCacheCreated(String regionName, String configurationPropertyToDisableKey, String configurationPropertyToDisableValue);
@LogMessage(level = WARN)
@ -92,6 +93,7 @@ public interface SecondLevelCacheLogger extends BasicLogger {
" Update your configuration to rename cache [%2$s] to [%1$s].",
id = NAMESPACE + 7
)
@SuppressWarnings( "unused" ) // used by hibernate-jcache
void usingLegacyCacheName(String currentName, String legacyName);
@LogMessage(level = WARN)
@ -100,6 +102,7 @@ public interface SecondLevelCacheLogger extends BasicLogger {
" Make sure your cache implementation supports JTA transactions.",
id = NAMESPACE + 8
)
@SuppressWarnings( "unused" ) // used by hibernate-jcache
void nonStandardSupportForAccessType(String key, String accessType, String regionName);
}

1
hibernate-core/src/main/java/org/hibernate/cfg/PersistenceSettings.java
View File

@ -134,7 +134,6 @@ public interface PersistenceSettings {
*
* @see #SCANNER
* @see org.hibernate.boot.archive.scan.spi.Scanner
* @see org.hibernate.boot.archive.scan.spi.AbstractScannerImpl
* @see org.hibernate.boot.MetadataBuilder#applyArchiveDescriptorFactory
*/
String SCANNER_ARCHIVE_INTERPRETER = "hibernate.archive.interpreter";

20
hibernate-core/src/main/java/org/hibernate/cfg/SessionEventSettings.java
View File

@ -13,18 +13,6 @@ import org.hibernate.Interceptor;
*/
public interface SessionEventSettings {
/**
* Controls whether {@linkplain org.hibernate.stat.SessionStatistics session metrics}
* should be {@linkplain org.hibernate.engine.internal.StatisticalLoggingSessionEventListener
* logged} for any session in which statistics are being collected.
* <p>
* By default, logging of session metrics is disabled unless {@link StatisticsSettings#GENERATE_STATISTICS}
* is enabled.
*
* @settingDefault Defined by {@link StatisticsSettings#GENERATE_STATISTICS}
*/
String LOG_SESSION_METRICS = "hibernate.session.events.log";
/**
* Defines a default {@link org.hibernate.SessionEventListener} to be applied to
* newly-opened {@link org.hibernate.Session}s.
@ -75,4 +63,12 @@ public interface SessionEventSettings {
* @since 5.2
*/
String SESSION_SCOPED_INTERCEPTOR = "hibernate.session_factory.session_scoped_interceptor";
/**
* @deprecated This setting is now ignored. Enable the log category
* {@code org.hibernate.session.metrics} to automatically
* collect and log session-level metrics.
*/
@Deprecated(since = "7", forRemoval = true)
String LOG_SESSION_METRICS = "hibernate.session.events.log";
}

30
hibernate-core/src/main/java/org/hibernate/engine/internal/StatisticalLoggingSessionEventListener.java
View File

@ -4,17 +4,18 @@
*/
package org.hibernate.engine.internal;
import org.hibernate.BaseSessionEventListener;
import org.hibernate.SessionEventListener;
import org.hibernate.internal.CoreMessageLogger;
import org.jboss.logging.Logger;
import static org.hibernate.internal.CoreLogging.messageLogger;
/**
* @see org.hibernate.cfg.AvailableSettings#LOG_SESSION_METRICS
* Tracks and logs certain session-level metrics.
*
* @author Steve Ebersole
*/
public class StatisticalLoggingSessionEventListener extends BaseSessionEventListener {
private static final Logger log = Logger.getLogger( StatisticalLoggingSessionEventListener.class );
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
@ -22,7 +23,7 @@ public class StatisticalLoggingSessionEventListener extends BaseSessionEventList
* @return {@code true} if logging is enabled for this listener.
*/
public static boolean isLoggingEnabled() {
return log.isInfoEnabled();
return log.isDebugEnabled();
}
// cumulative state ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
@ -274,21 +275,8 @@ public class StatisticalLoggingSessionEventListener extends BaseSessionEventList
@Override
public void end() {
if ( log.isInfoEnabled() ) {
log.infof(
"Session Metrics {\n" +
" %s nanoseconds spent acquiring %s JDBC connections;\n" +
" %s nanoseconds spent releasing %s JDBC connections;\n" +
" %s nanoseconds spent preparing %s JDBC statements;\n" +
" %s nanoseconds spent executing %s JDBC statements;\n" +
" %s nanoseconds spent executing %s JDBC batches;\n" +
" %s nanoseconds spent performing %s L2C puts;\n" +
" %s nanoseconds spent performing %s L2C hits;\n" +
" %s nanoseconds spent performing %s L2C misses;\n" +
" %s nanoseconds spent executing %s flushes (flushing a total of %s entities and %s collections);\n" +
" %s nanoseconds spent executing %s pre-partial-flushes;\n" +
" %s nanoseconds spent executing %s partial-flushes (flushing a total of %s entities and %s collections)\n" +
"}",
if ( isLoggingEnabled() ) {
log.sessionMetrics(
jdbcConnectionAcquisitionTime,
jdbcConnectionAcquisitionCount,
jdbcConnectionReleaseTime,

47
hibernate-core/src/main/java/org/hibernate/internal/BaselineSessionEventsListenerBuilder.java
View File

@ -19,21 +19,12 @@ public class BaselineSessionEventsListenerBuilder {
private static final SessionEventListener[] EMPTY = new SessionEventListener[0];
private final boolean logSessionMetrics;
private final Class<? extends SessionEventListener> autoListener;
public BaselineSessionEventsListenerBuilder(
boolean logSessionMetrics,
Class<? extends SessionEventListener> autoListener) {
this.logSessionMetrics = logSessionMetrics;
public BaselineSessionEventsListenerBuilder(Class<? extends SessionEventListener> autoListener) {
this.autoListener = autoListener;
}
@SuppressWarnings("unused")
public boolean isLogSessionMetrics() {
return logSessionMetrics;
}
@SuppressWarnings("unused")
public Class<? extends SessionEventListener> getAutoListener() {
return autoListener;
@ -48,24 +39,26 @@ public class BaselineSessionEventsListenerBuilder {
}
public SessionEventListener[] buildBaseline() {
final boolean addStats = logSessionMetrics && StatisticalLoggingSessionEventListener.isLoggingEnabled();
final boolean addAutoListener = autoListener != null;
final SessionEventListener[] arr;
if ( addStats && addAutoListener ) {
arr = new SessionEventListener[2];
arr[0] = buildStatsListener();
arr[1] = buildAutoListener( autoListener );
if ( autoListener != null ) {
if ( StatisticalLoggingSessionEventListener.isLoggingEnabled() ) {
arr = new SessionEventListener[2];
arr[0] = buildStatsListener();
arr[1] = buildAutoListener( autoListener );
}
else {
arr = new SessionEventListener[1];
arr[0] = buildAutoListener( autoListener );
}
}
else if ( !addStats && addAutoListener ) {
arr = new SessionEventListener[1];
arr[0] = buildAutoListener( autoListener );
}
else if ( addStats && !addAutoListener ) {
arr = new SessionEventListener[1];
arr[0] = buildStatsListener();
}
else {//if ( !addStats && !addAutoListener )
arr = EMPTY;
else {
if ( StatisticalLoggingSessionEventListener.isLoggingEnabled() ) {
arr = new SessionEventListener[1];
arr[0] = buildStatsListener();
}
else {
arr = EMPTY;
}
}
return arr;
}
@ -76,7 +69,7 @@ public class BaselineSessionEventsListenerBuilder {
}
catch (Exception e) {
throw new HibernateException(
"Unable to instantiate specified auto SessionEventListener : " + autoListener.getName(),
"Unable to instantiate specified auto SessionEventListener: " + autoListener.getName(),
e
);
}

46
hibernate-core/src/main/java/org/hibernate/internal/CoreMessageLogger.java
View File

@ -887,4 +887,50 @@ public interface CoreMessageLogger extends BasicLogger {
value = "Encountered multiple persistence-unit stanzas defining same name [%s]; persistence-unit names must be unique"
)
void duplicatedPersistenceUnitName(String name);
@LogMessage(level = DEBUG)
@Message(
id = 425,
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);
}

88
hibernate-core/src/main/java/org/hibernate/stat/internal/StatisticsImpl.java
View File

@ -42,7 +42,7 @@ import static org.hibernate.internal.CoreLogging.messageLogger;
*/
public class StatisticsImpl implements StatisticsImplementor, Service {
private static final CoreMessageLogger LOG = messageLogger( StatisticsImpl.class );
private static final CoreMessageLogger log = messageLogger( StatisticsImpl.class );
private final MappingMetamodelImplementor metamodel;
private final CacheImplementor cache;
@ -702,7 +702,7 @@ public class StatisticsImpl implements StatisticsImplementor, Service {
@Override
public void queryExecuted(String hql, int rows, long time) {
LOG.hql( hql, time, (long) rows );
log.hql( hql, time, (long) rows );
queryExecutionCount.increment();
boolean isLongestQuery;
@ -724,7 +724,7 @@ public class StatisticsImpl implements StatisticsImplementor, Service {
@Override
public void queryCacheHit(String hql, String regionName) {
LOG.tracef( "Statistics#queryCacheHit( `%s`, `%s` )", hql, regionName );
log.tracef( "Statistics#queryCacheHit( `%s`, `%s` )", hql, regionName );
queryCacheHitCount.increment();
@ -737,7 +737,7 @@ public class StatisticsImpl implements StatisticsImplementor, Service {
@Override
public void queryCacheMiss(String hql, String regionName) {
LOG.tracef( "Statistics#queryCacheMiss( `%s`, `%s` )", hql, regionName );
log.tracef( "Statistics#queryCacheMiss( `%s`, `%s` )", hql, regionName );
queryCacheMissCount.increment();
@ -750,7 +750,7 @@ public class StatisticsImpl implements StatisticsImplementor, Service {
@Override
public void queryCachePut(String hql, String regionName) {
LOG.tracef( "Statistics#queryCachePut( `%s`, `%s` )", hql, regionName );
log.tracef( "Statistics#queryCachePut( `%s`, `%s` )", hql, regionName );
queryCachePutCount.increment();
@ -890,45 +890,45 @@ public class StatisticsImpl implements StatisticsImplementor, Service {
@Override
public void logSummary() {
LOG.loggingStatistics();
LOG.startTime( startTime.toEpochMilli() );
LOG.sessionsOpened( sessionOpenCount.sum() );
LOG.sessionsClosed( sessionCloseCount.sum() );
LOG.transactions( transactionCount.sum() );
LOG.successfulTransactions( committedTransactionCount.sum() );
LOG.optimisticLockFailures( optimisticFailureCount.sum() );
LOG.flushes( flushCount.sum() );
LOG.connectionsObtained( connectCount.sum() );
LOG.statementsPrepared( prepareStatementCount.sum() );
LOG.statementsClosed( closeStatementCount.sum() );
LOG.secondLevelCachePuts( secondLevelCachePutCount.sum() );
LOG.secondLevelCacheHits( secondLevelCacheHitCount.sum() );
LOG.secondLevelCacheMisses( secondLevelCacheMissCount.sum() );
LOG.entitiesLoaded( entityLoadCount.sum() );
LOG.entitiesUpdated( entityUpdateCount.sum() );
LOG.entitiesInserted( entityInsertCount.sum() );
LOG.entitiesDeleted( entityDeleteCount.sum() );
LOG.entitiesFetched( entityFetchCount.sum() );
LOG.collectionsLoaded( collectionLoadCount.sum() );
LOG.collectionsUpdated( collectionUpdateCount.sum() );
LOG.collectionsRemoved( collectionRemoveCount.sum() );
LOG.collectionsRecreated( collectionRecreateCount.sum() );
LOG.collectionsFetched( collectionFetchCount.sum() );
LOG.naturalIdCachePuts( naturalIdCachePutCount.sum() );
LOG.naturalIdCacheHits( naturalIdCacheHitCount.sum() );
LOG.naturalIdCacheMisses( naturalIdCacheMissCount.sum() );
LOG.naturalIdMaxQueryTime( naturalIdQueryExecutionMaxTime.get() );
LOG.naturalIdQueriesExecuted( naturalIdQueryExecutionCount.sum() );
LOG.queriesExecuted( queryExecutionCount.sum() );
LOG.queryCachePuts( queryCachePutCount.sum() );
LOG.timestampCachePuts( updateTimestampsCachePutCount.sum() );
LOG.timestampCacheHits( updateTimestampsCacheHitCount.sum() );
LOG.timestampCacheMisses( updateTimestampsCacheMissCount.sum() );
LOG.queryCacheHits( queryCacheHitCount.sum() );
LOG.queryCacheMisses( queryCacheMissCount.sum() );
LOG.maxQueryTime( queryExecutionMaxTime.get() );
LOG.queryPlanCacheHits( queryPlanCacheHitCount.sum() );
LOG.queryPlanCacheMisses( queryPlanCacheMissCount.sum() );
log.loggingStatistics();
log.startTime( startTime.toEpochMilli() );
log.sessionsOpened( sessionOpenCount.sum() );
log.sessionsClosed( sessionCloseCount.sum() );
log.transactions( transactionCount.sum() );
log.successfulTransactions( committedTransactionCount.sum() );
log.optimisticLockFailures( optimisticFailureCount.sum() );
log.flushes( flushCount.sum() );
log.connectionsObtained( connectCount.sum() );
log.statementsPrepared( prepareStatementCount.sum() );
log.statementsClosed( closeStatementCount.sum() );
log.secondLevelCachePuts( secondLevelCachePutCount.sum() );
log.secondLevelCacheHits( secondLevelCacheHitCount.sum() );
log.secondLevelCacheMisses( secondLevelCacheMissCount.sum() );
log.entitiesLoaded( entityLoadCount.sum() );
log.entitiesUpdated( entityUpdateCount.sum() );
log.entitiesInserted( entityInsertCount.sum() );
log.entitiesDeleted( entityDeleteCount.sum() );
log.entitiesFetched( entityFetchCount.sum() );
log.collectionsLoaded( collectionLoadCount.sum() );
log.collectionsUpdated( collectionUpdateCount.sum() );
log.collectionsRemoved( collectionRemoveCount.sum() );
log.collectionsRecreated( collectionRecreateCount.sum() );
log.collectionsFetched( collectionFetchCount.sum() );
log.naturalIdCachePuts( naturalIdCachePutCount.sum() );
log.naturalIdCacheHits( naturalIdCacheHitCount.sum() );
log.naturalIdCacheMisses( naturalIdCacheMissCount.sum() );
log.naturalIdMaxQueryTime( naturalIdQueryExecutionMaxTime.get() );
log.naturalIdQueriesExecuted( naturalIdQueryExecutionCount.sum() );
log.queriesExecuted( queryExecutionCount.sum() );
log.queryCachePuts( queryCachePutCount.sum() );
log.timestampCachePuts( updateTimestampsCachePutCount.sum() );
log.timestampCacheHits( updateTimestampsCacheHitCount.sum() );
log.timestampCacheMisses( updateTimestampsCacheMissCount.sum() );
log.queryCacheHits( queryCacheHitCount.sum() );
log.queryCacheMisses( queryCacheMissCount.sum() );
log.maxQueryTime( queryExecutionMaxTime.get() );
log.queryPlanCacheHits( queryPlanCacheHitCount.sum() );
log.queryPlanCacheMisses( queryPlanCacheMissCount.sum() );
}
@Override

5
hibernate-core/src/test/java/org/hibernate/orm/test/annotations/collectionelement/recreate/RecreateCollectionTest.java
View File

@ -6,8 +6,7 @@ package org.hibernate.orm.test.annotations.collectionelement.recreate;
import java.util.Date;
import org.hibernate.BaseSessionEventListener;
import org.hibernate.SessionEventListener;
import org.hibernate.testing.orm.junit.JiraKey;
import org.hibernate.testing.orm.junit.DomainModel;
import org.hibernate.testing.orm.junit.SessionFactory;
@ -29,7 +28,7 @@ import static org.junit.jupiter.api.Assertions.assertEquals;
@SessionFactory
public class RecreateCollectionTest {
private static class StatementsCounterListener extends BaseSessionEventListener {
private static class StatementsCounterListener implements SessionEventListener {
int statements;
@Override

3
hibernate-core/src/test/java/org/hibernate/orm/test/event/SessionEventListenersManagerTest.java
View File

@ -4,7 +4,6 @@
*/
package org.hibernate.orm.test.event;
import org.hibernate.BaseSessionEventListener;
import org.hibernate.SessionEventListener;
import org.hibernate.engine.internal.SessionEventListenerManagerImpl;
@ -43,7 +42,7 @@ public class SessionEventListenersManagerTest extends BaseUnitTestCase {
Assert.assertEquals( "e", sb.toString() );
}
private static class TestSessionEventListener extends BaseSessionEventListener {
private static class TestSessionEventListener implements SessionEventListener {
private final StringBuilder sb;
private final char theChar;