Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
Original file line number Diff line number Diff line change
@@ -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);
}
Original file line number Diff line number Diff line change
Expand Up @@ -5,25 +5,23 @@
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.
*
* @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
*
* @return {@code true} if logging is enabled for this listener.
*/
public static boolean isLoggingEnabled() {
return LOG.isDebugEnabled();
return SESSION_METRICS_LOGGER.isDebugEnabled();
}

// cumulative state ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Expand Down Expand Up @@ -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,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -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);
Expand All @@ -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);
}
Loading
Loading