Skip to content

Commit c080cbe

Browse files
gavinkinggavinking
committed
move some logging to dedicated subsystem loggers
1 parent 0462773 commit c080cbe

File tree

11 files changed

+230
-348
lines changed

11 files changed

+230
-348
lines changed

‎hibernate-core/src/main/java/org/hibernate/engine/internal/SessionMetricsLogger.java‎

Lines changed: 73 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,73 @@
1+
/*
2+
* SPDX-License-Identifier: Apache-2.0
3+
* Copyright Red Hat Inc. and Hibernate Authors
4+
*/
5+
package org.hibernate.engine.internal;
6+
7+
import org.hibernate.internal.log.SubSystemLogging;
8+
import org.jboss.logging.BasicLogger;
9+
import org.jboss.logging.Logger;
10+
import org.jboss.logging.annotations.LogMessage;
11+
import org.jboss.logging.annotations.Message;
12+
import org.jboss.logging.annotations.MessageLogger;
13+
14+
import java.lang.invoke.MethodHandles;
15+
16+
import static org.jboss.logging.Logger.Level.DEBUG;
17+
18+
@MessageLogger( projectCode = "HHH" )
19+
@SubSystemLogging(
20+
name = SessionMetricsLogger.LOGGER_NAME,
21+
description = "Logging related to session metrics"
22+
)
23+
public interface SessionMetricsLogger extends BasicLogger {
24+
String LOGGER_NAME = "org.hibernate.session.metrics";
25+
26+
SessionMetricsLogger SESSION_METRICS_LOGGER = Logger.getMessageLogger( MethodHandles.lookup(), SessionMetricsLogger.class, LOGGER_NAME );
27+
28+
@LogMessage(level = DEBUG)
29+
@Message(
30+
id = 401,
31+
value = """
32+
Logging session metrics:
33+
%s ns acquiring %s JDBC connections
34+
%s ns releasing %s JDBC connections
35+
%s ns preparing %s JDBC statements
36+
%s ns executing %s JDBC statements
37+
%s ns executing %s JDBC batches
38+
%s ns performing %s second-level cache puts
39+
%s ns performing %s second-level cache hits
40+
%s ns performing %s second-level cache misses
41+
%s ns executing %s flushes (flushing a total of %s entities and %s collections)
42+
%s ns executing %s pre-partial-flushes
43+
%s ns executing %s partial-flushes (flushing a total of %s entities and %s collections)
44+
"""
45+
)
46+
void sessionMetrics(
47+
long jdbcConnectionAcquisitionTime,
48+
int jdbcConnectionAcquisitionCount,
49+
long jdbcConnectionReleaseTime,
50+
int jdbcConnectionReleaseCount,
51+
long jdbcPrepareStatementTime,
52+
int jdbcPrepareStatementCount,
53+
long jdbcExecuteStatementTime,
54+
int jdbcExecuteStatementCount,
55+
long jdbcExecuteBatchTime,
56+
int jdbcExecuteBatchCount,
57+
long cachePutTime,
58+
int cachePutCount,
59+
long cacheHitTime,
60+
int cacheHitCount,
61+
long cacheMissTime,
62+
int cacheMissCount,
63+
long flushTime,
64+
int flushCount,
65+
long flushEntityCount,
66+
long flushCollectionCount,
67+
long prePartialFlushTime,
68+
int prePartialFlushCount,
69+
long partialFlushTime,
70+
int partialFlushCount,
71+
long partialFlushEntityCount,
72+
long partialFlushCollectionCount);
73+
}

‎hibernate-core/src/main/java/org/hibernate/engine/internal/StatisticalLoggingSessionEventListener.java‎

Lines changed: 3 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -5,25 +5,23 @@
55
package org.hibernate.engine.internal;
66

77
import org.hibernate.SessionEventListener;
8-
import org.hibernate.internal.CoreMessageLogger;
98

10-
import static org.hibernate.internal.CoreLogging.messageLogger;
9+
import static org.hibernate.engine.internal.SessionMetricsLogger.SESSION_METRICS_LOGGER;
1110

1211
/**
1312
* Tracks and logs certain session-level metrics.
1413
*
1514
* @author Steve Ebersole
1615
*/
1716
public class StatisticalLoggingSessionEventListener implements SessionEventListener {
18-
private static final CoreMessageLogger LOG = messageLogger( "org.hibernate.session.metrics" );
1917

2018
/**
2119
* Used by SettingsFactory (in conjunction with stats being enabled) to determine whether to apply this listener
2220
*
2321
* @return {@code true} if logging is enabled for this listener.
2422
*/
2523
public static boolean isLoggingEnabled() {
26-
return LOG.isDebugEnabled();
24+
return SESSION_METRICS_LOGGER.isDebugEnabled();
2725
}
2826

2927
// cumulative state ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
@@ -276,7 +274,7 @@ public void partialFlushEnd(int numberOfEntities, int numberOfCollections) {
276274
@Override
277275
public void end() {
278276
if ( isLoggingEnabled() ) {
279-
LOG.sessionMetrics(
277+
SESSION_METRICS_LOGGER.sessionMetrics(
280278
jdbcConnectionAcquisitionTime,
281279
jdbcConnectionAcquisitionCount,
282280
jdbcConnectionReleaseTime,

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

Lines changed: 0 additions & 142 deletions
Original file line numberDiff line numberDiff line change
@@ -154,10 +154,6 @@ void expectedType(String name,
154154
@Message(value = "Handling transient entity in delete processing", id = 114)
155155
void handlingTransientEntity();
156156

157-
@LogMessage(level = DEBUG)
158-
@Message(value = "HQL: %s, time: %sms, rows: %s", id = 117)
159-
void hql(String hql, Long valueOf, Long valueOf2);
160-
161157
@LogMessage(level = WARN)
162158
@Message(value = "HSQLDB supports only READ_UNCOMMITTED isolation", id = 118)
163159
void hsqldbSupportsOnlyReadCommittedIsolation();
@@ -515,8 +511,6 @@ void cannotResolveNonNullableTransientDependencies(
515511
)
516512
void nonCompliantMapConversion(String collectionRole);
517513

518-
// 458-466 reserved for use by main branch (ORM 5.0.0)
519-
520514
@LogMessage(level = DEBUG)
521515
@Message(value = "Creating pooled optimizer (lo) with [incrementSize=%s; returnClass=%s]", id = 467)
522516
void creatingPooledLoOptimizer(int incrementSize, String name);
@@ -689,22 +683,6 @@ void unableToLocateStaticMetamodelField(
689683
@Message(value = "Logical connection closed", id = 457)
690684
void logicalConnectionClosed();
691685

692-
@LogMessage(level = TRACE)
693-
@Message(value = "Statistics initialized", id = 460)
694-
void statisticsInitialized();
695-
696-
@LogMessage(level = TRACE)
697-
@Message(value = "Statistics collection enabled", id = 461)
698-
void statisticsEnabled();
699-
700-
@LogMessage(level = TRACE)
701-
@Message(value = "Statistics collection disabled", id = 462)
702-
void statisticsDisabled();
703-
704-
@LogMessage(level = TRACE)
705-
@Message(value = "Statistics reset", id = 463)
706-
void statisticsReset();
707-
708686
@LogMessage(level = TRACE)
709687
@Message(value = "Initializing service: %s", id = 500)
710688
void initializingService(String serviceRole);
@@ -720,124 +698,4 @@ void unableToLocateStaticMetamodelField(
720698
@LogMessage(level = WARN)
721699
@Message(value = "Encountered request for service by non-primary service role [%s -> %s]", id = 450)
722700
void alternateServiceRole(String requestedRole, String targetRole);
723-
724-
@LogMessage(level = DEBUG)
725-
@Message(
726-
id = 401,
727-
value = """
728-
Logging session metrics:
729-
%s ns acquiring %s JDBC connections
730-
%s ns releasing %s JDBC connections
731-
%s ns preparing %s JDBC statements
732-
%s ns executing %s JDBC statements
733-
%s ns executing %s JDBC batches
734-
%s ns performing %s second-level cache puts
735-
%s ns performing %s second-level cache hits
736-
%s ns performing %s second-level cache misses
737-
%s ns executing %s flushes (flushing a total of %s entities and %s collections)
738-
%s ns executing %s pre-partial-flushes
739-
%s ns executing %s partial-flushes (flushing a total of %s entities and %s collections)
740-
"""
741-
)
742-
void sessionMetrics(
743-
long jdbcConnectionAcquisitionTime,
744-
int jdbcConnectionAcquisitionCount,
745-
long jdbcConnectionReleaseTime,
746-
int jdbcConnectionReleaseCount,
747-
long jdbcPrepareStatementTime,
748-
int jdbcPrepareStatementCount,
749-
long jdbcExecuteStatementTime,
750-
int jdbcExecuteStatementCount,
751-
long jdbcExecuteBatchTime,
752-
int jdbcExecuteBatchCount,
753-
long cachePutTime,
754-
int cachePutCount,
755-
long cacheHitTime,
756-
int cacheHitCount,
757-
long cacheMissTime,
758-
int cacheMissCount,
759-
long flushTime,
760-
int flushCount,
761-
long flushEntityCount,
762-
long flushCollectionCount,
763-
long prePartialFlushTime,
764-
int prePartialFlushCount,
765-
long partialFlushTime,
766-
int partialFlushCount,
767-
long partialFlushEntityCount,
768-
long partialFlushCollectionCount);
769-
770-
@LogMessage(level = INFO)
771-
@Message(
772-
id = 400,
773-
value = """
774-
Logging statistics:
775-
Start time: %s
776-
Sessions opened (closed): %s (%s)
777-
Transactions started (successful): %s (%s)
778-
Optimistic lock failures: %s
779-
Flushes: %s
780-
Connections obtained: %s
781-
Statements prepared (closed): %s (%s)
782-
Second-level cache puts: %s
783-
Second-level cache hits (misses): %s (%s)
784-
Entities loaded: %s
785-
Entities fetched: %s (minimize this)
786-
Entities updated, upserted, inserted, deleted: %s, %s, %s, %s
787-
Collections loaded: %s
788-
Collections fetched: %s (minimize this)
789-
Collections updated, removed, recreated: %s, %s, %s
790-
Natural id queries executed on database: %s
791-
Natural id cache puts: %s
792-
Natural id cache hits (misses): %s (%s)
793-
Max natural id query execution time: %s ms
794-
Queries executed on database: %s
795-
Query cache puts: %s
796-
Query cache hits (misses): %s (%s)
797-
Max query execution time: %s ms
798-
Update timestamps cache puts: %s
799-
Update timestamps cache hits (misses): %s (%s)
800-
Query plan cache hits (misses): %s (%s)
801-
"""
802-
)
803-
void logStatistics(
804-
long startTime,
805-
long sessionOpenCount,
806-
long sessionCloseCount,
807-
long transactionCount,
808-
long committedTransactionCount,
809-
long optimisticFailureCount,
810-
long flushCount,
811-
long connectCount,
812-
long prepareStatementCount,
813-
long closeStatementCount,
814-
long secondLevelCachePutCount,
815-
long secondLevelCacheHitCount,
816-
long secondLevelCacheMissCount,
817-
long entityLoadCount,
818-
long entityFetchCount,
819-
long entityUpdateCount,
820-
long entityUpsertCount,
821-
long entityInsertCount,
822-
long entityDeleteCount,
823-
long collectionLoadCount,
824-
long collectionFetchCount,
825-
long collectionUpdateCount,
826-
long collectionRemoveCount,
827-
long collectionRecreateCount,
828-
long naturalIdQueryExecutionCount,
829-
long naturalIdCachePutCount,
830-
long naturalIdCacheHitCount,
831-
long naturalIdCacheMissCount,
832-
long naturalIdQueryExecutionMaxTime,
833-
long queryExecutionCount,
834-
long queryCachePutCount,
835-
long queryCacheHitCount,
836-
long queryCacheMissCount,
837-
long queryExecutionMaxTime,
838-
long updateTimestampsCachePutCount,
839-
long updateTimestampsCacheHitCount,
840-
long updateTimestampsCacheMissCount,
841-
long queryPlanCacheHitCount,
842-
long queryPlanCacheMissCount);
843701
}

0 commit comments

Comments
 (0)