From 33ac4174c731334fb46bd3c797ebb6d47abdb959 Mon Sep 17 00:00:00 2001 From: Erin Schnabel Date: Tue, 17 Nov 2020 17:39:43 -0500 Subject: [PATCH] HHH-14337 Micrometer support --- gradle/libraries.gradle | 3 + .../hibernate-micrometer.gradle | 31 ++ .../org/hibernate/stat/HibernateMetrics.java | 369 ++++++++++++++++++ .../hibernate/stat/HibernateQueryMetrics.java | 188 +++++++++ .../java/org/hibernate/test/stat/Account.java | 41 ++ .../org/hibernate/test/stat/AccountId.java | 43 ++ .../stat/MicrometerCacheStatisticsTest.java | 208 ++++++++++ .../test/stat/MicrometerStatisticsTest.java | 147 +++++++ .../src/test/resources/hibernate.properties | 27 ++ .../src/test/resources/log4j.properties | 19 + settings.gradle | 2 +- 11 files changed, 1077 insertions(+), 1 deletion(-) create mode 100644 hibernate-micrometer/hibernate-micrometer.gradle create mode 100644 hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateMetrics.java create mode 100644 hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateQueryMetrics.java create mode 100644 hibernate-micrometer/src/test/java/org/hibernate/test/stat/Account.java create mode 100644 hibernate-micrometer/src/test/java/org/hibernate/test/stat/AccountId.java create mode 100644 hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerCacheStatisticsTest.java create mode 100644 hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerStatisticsTest.java create mode 100644 hibernate-micrometer/src/test/resources/hibernate.properties create mode 100644 hibernate-micrometer/src/test/resources/log4j.properties diff --git a/gradle/libraries.gradle b/gradle/libraries.gradle index eb24c0eb92..4cebe5771e 100644 --- a/gradle/libraries.gradle +++ b/gradle/libraries.gradle @@ -44,6 +44,8 @@ ext { //GraalVM graalvmVersion = '19.3.1' + micrometerVersion = '1.6.1' + libraries = [ // Ant ant: 'org.apache.ant:ant:1.8.2', @@ -142,6 +144,7 @@ ext { vibur: "org.vibur:vibur-dbcp:25.0", agroal_api: "io.agroal:agroal-api:${agroalVersion}", agroal_pool: "io.agroal:agroal-pool:${agroalVersion}", + micrometer: "io.micrometer:micrometer-core:1.6.1", atomikos: "com.atomikos:transactions:4.0.6", atomikos_jta: "com.atomikos:transactions-jta:4.0.6", diff --git a/hibernate-micrometer/hibernate-micrometer.gradle b/hibernate-micrometer/hibernate-micrometer.gradle new file mode 100644 index 0000000000..dccd513b68 --- /dev/null +++ b/hibernate-micrometer/hibernate-micrometer.gradle @@ -0,0 +1,31 @@ +description = 'Integration for Micrometer metrics into Hibernate as a metrics collection package' + +apply from: rootProject.file( 'gradle/published-java-module.gradle' ) + + +dependencies { + compile project( ':hibernate-core' ) + compile( libraries.jpa ) + compile( libraries.micrometer ) + + testCompile project( ':hibernate-testing' ) + testCompile( libraries.mockito ) + testCompile( libraries.mockito_inline ) + testAnnotationProcessor( project( ':hibernate-jpamodelgen' ) ) +} + +sourceSets { + // resources inherently exclude sources + test { + resources { + setSrcDirs( ['src/test/java','src/test/resources'] ) + } + } + + testJavassist { + java { + compileClasspath += main.output + test.output + runtimeClasspath += main.output + test.output + } + } +} diff --git a/hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateMetrics.java b/hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateMetrics.java new file mode 100644 index 0000000000..339fc6d159 --- /dev/null +++ b/hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateMetrics.java @@ -0,0 +1,369 @@ +/* + * Hibernate, Relational Persistence for Idiomatic Java + * + * License: GNU Lesser General Public License (LGPL), version 2.1 or later. + * See the lgpl.txt file in the root directory or . + */ +package org.hibernate.stat; + +import io.micrometer.core.instrument.FunctionCounter; +import io.micrometer.core.instrument.MeterRegistry; +import io.micrometer.core.instrument.Tag; +import io.micrometer.core.instrument.Tags; +import io.micrometer.core.instrument.TimeGauge; +import io.micrometer.core.instrument.binder.MeterBinder; +import io.micrometer.core.lang.NonNullApi; +import io.micrometer.core.lang.NonNullFields; +import io.micrometer.core.lang.Nullable; + +import org.hibernate.SessionFactory; +import org.hibernate.stat.Statistics; + +import javax.persistence.EntityManagerFactory; +import javax.persistence.PersistenceException; +import java.util.Arrays; +import java.util.concurrent.TimeUnit; +import java.util.function.ToDoubleFunction; + +/** + * A {@link MeterBinder} implementation that provides Hibernate metrics. It exposes the + * same statistics as would be exposed when calling {@link Statistics#logSummary()}. + */ +@NonNullApi +@NonNullFields +public class HibernateMetrics implements MeterBinder { + + private static final String SESSION_FACTORY_TAG_NAME = "entityManagerFactory"; + + private final String cacheFactoryPrefix; + private final Iterable tags; + + @Nullable + private final Statistics statistics; + + /** + * Create {@code HibernateMetrics} and bind to the specified meter registry. + * + * @param registry meter registry to use + * @param sessionFactory session factory to use + * @param sessionFactoryName session factory name as a tag value + * @param tags additional tags + */ + public static void monitor( + MeterRegistry registry, + SessionFactory sessionFactory, + String sessionFactoryName, + String... tags) { + monitor( registry, sessionFactory, sessionFactoryName, Tags.of( tags ) ); + } + + /** + * Create {@code HibernateMetrics} and bind to the specified meter registry. + * + * @param registry meter registry to use + * @param sessionFactory session factory to use + * @param sessionFactoryName session factory name as a tag value + * @param tags additional tags + */ + public static void monitor( + MeterRegistry registry, + SessionFactory sessionFactory, + String sessionFactoryName, + Iterable tags) { + new HibernateMetrics( sessionFactory, sessionFactoryName, tags ).bindTo( registry ); + } + + /** + * Create a {@code HibernateMetrics}. + * + * @param sessionFactory session factory to use + * @param sessionFactoryName session factory name as a tag value + * @param tags additional tags + */ + public HibernateMetrics(SessionFactory sessionFactory, String sessionFactoryName, Iterable tags) { + this.tags = Tags.concat( tags, SESSION_FACTORY_TAG_NAME, sessionFactoryName ); + this.cacheFactoryPrefix = sessionFactory.getSessionFactoryOptions().getCacheRegionPrefix(); + Statistics statistics = sessionFactory.getStatistics(); + this.statistics = statistics.isStatisticsEnabled() ? statistics : null; + } + + private void counter( + MeterRegistry registry, + String name, + String description, + ToDoubleFunction f, + String... extraTags) { + if ( this.statistics == null ) { + return; + } + + FunctionCounter.builder( name, statistics, f ) + .tags( tags ) + .tags( extraTags ) + .description( description ) + .register( registry ); + } + + @Override + public void bindTo(MeterRegistry registry) { + if ( this.statistics == null ) { + return; + } + + // Session statistics + counter(registry, "hibernate.sessions.open", "Sessions opened", Statistics::getSessionOpenCount ); + counter(registry, "hibernate.sessions.closed", "Sessions closed", Statistics::getSessionCloseCount ); + + // Transaction statistics + counter(registry, "hibernate.transactions", "The number of transactions we know to have been successful", + Statistics::getSuccessfulTransactionCount, "result", "success" + ); + counter(registry, "hibernate.transactions", "The number of transactions we know to have failed", + s -> s.getTransactionCount() - s.getSuccessfulTransactionCount(), "result", "failure" + ); + counter(registry, + "hibernate.optimistic.failures", + "The number of StaleObjectStateExceptions that have occurred", + Statistics::getOptimisticFailureCount + ); + + counter(registry, + "hibernate.flushes", + "The global number of flushes executed by sessions (either implicit or explicit)", + Statistics::getFlushCount + ); + counter(registry, + "hibernate.connections.obtained", + "Get the global number of connections asked by the sessions " + + "(the actual number of connections used may be much smaller depending " + + "whether you use a connection pool or not)", + Statistics::getConnectCount + ); + + // Statements + counter(registry, "hibernate.statements", "The number of prepared statements that were acquired", + Statistics::getPrepareStatementCount, "status", "prepared" + ); + counter(registry, "hibernate.statements", "The number of prepared statements that were released", + Statistics::getCloseStatementCount, "status", "closed" + ); + + // Second Level Caching + // AWKWARD: getSecondLevelCacheRegionNames is the only way to retrieve a list of names + // The returned names are all qualified. + // getDomainDataRegionStatistics wants unqualified names, + // there are no "public" methods to unqualify the names + Arrays.stream( statistics.getSecondLevelCacheRegionNames() ) + .map(s -> { + if ( cacheFactoryPrefix != null ) { + return s.replaceAll( cacheFactoryPrefix + ".", "" ); + } + return s; + }) + .filter( this::hasDomainDataRegionStatistics ) + .forEach( regionName -> { + counter(registry, + "hibernate.second.level.cache.requests", + "The number of cacheable entities/collections successfully retrieved from the cache", + stats -> stats.getDomainDataRegionStatistics( regionName ).getHitCount(), + "region", + regionName, + "result", + "hit" + ); + counter(registry, + "hibernate.second.level.cache.requests", + "The number of cacheable entities/collections not found in the cache and loaded from the database", + stats -> stats.getDomainDataRegionStatistics( regionName ).getMissCount(), + "region", + regionName, + "result", + "miss" + ); + counter( + registry, + "hibernate.second.level.cache.puts", + "The number of cacheable entities/collections put in the cache", + stats -> stats.getDomainDataRegionStatistics( regionName ).getPutCount(), + "region", + regionName + ); + } ); + + // Entity information + counter(registry, + "hibernate.entities.deletes", + "The number of entity deletes", + Statistics::getEntityDeleteCount + ); + counter(registry, + "hibernate.entities.fetches", + "The number of entity fetches", + Statistics::getEntityFetchCount + ); + counter(registry, + "hibernate.entities.inserts", + "The number of entity inserts", + Statistics::getEntityInsertCount + ); + counter(registry, "hibernate.entities.loads", "The number of entity loads", Statistics::getEntityLoadCount ); + counter(registry, + "hibernate.entities.updates", + "The number of entity updates", + Statistics::getEntityUpdateCount + ); + + // Collections + counter(registry, + "hibernate.collections.deletes", + "The number of collection deletes", + Statistics::getCollectionRemoveCount + ); + counter(registry, + "hibernate.collections.fetches", + "The number of collection fetches", + Statistics::getCollectionFetchCount + ); + counter(registry, + "hibernate.collections.loads", + "The number of collection loads", + Statistics::getCollectionLoadCount + ); + counter(registry, + "hibernate.collections.recreates", + "The number of collections recreated", + Statistics::getCollectionRecreateCount + ); + counter(registry, + "hibernate.collections.updates", + "The number of collection updates", + Statistics::getCollectionUpdateCount + ); + + // Natural Id cache + counter(registry, + "hibernate.cache.natural.id.requests", + "The number of cached naturalId lookups successfully retrieved from cache", + Statistics::getNaturalIdCacheHitCount, + "result", + "hit" + ); + counter(registry, + "hibernate.cache.natural.id.requests", + "The number of cached naturalId lookups not found in cache", + Statistics::getNaturalIdCacheMissCount, + "result", + "miss" + ); + counter(registry, "hibernate.cache.natural.id.puts", "The number of cacheable naturalId lookups put in cache", + Statistics::getNaturalIdCachePutCount + ); + + counter(registry, + "hibernate.query.natural.id.executions", + "The number of naturalId queries executed against the database", + Statistics::getNaturalIdQueryExecutionCount + ); + + TimeGauge.builder( + "hibernate.query.natural.id.executions.max", + statistics, + TimeUnit.MILLISECONDS, + Statistics::getNaturalIdQueryExecutionMaxTime + ) + .description( "The maximum query time for naturalId queries executed against the database" ) + .tags( tags ) + .register( registry ); + + // Query statistics + counter(registry, + "hibernate.query.executions", + "The number of executed queries", + Statistics::getQueryExecutionCount + ); + + TimeGauge.builder( + "hibernate.query.executions.max", + statistics, + TimeUnit.MILLISECONDS, + Statistics::getQueryExecutionMaxTime + ) + .description( "The time of the slowest query" ) + .tags( tags ) + .register( registry ); + + // Update timestamp cache + counter(registry, + "hibernate.cache.update.timestamps.requests", + "The number of timestamps successfully retrieved from cache", + Statistics::getUpdateTimestampsCacheHitCount, + "result", + "hit" + ); + counter(registry, + "hibernate.cache.update.timestamps.requests", + "The number of tables for which no update timestamps was not found in cache", + Statistics::getUpdateTimestampsCacheMissCount, + "result", + "miss" + ); + counter(registry, "hibernate.cache.update.timestamps.puts", "The number of timestamps put in cache", + Statistics::getUpdateTimestampsCachePutCount + ); + + // Query Caching + counter(registry, + "hibernate.cache.query.requests", + "The number of cached queries successfully retrieved from cache", + Statistics::getQueryCacheHitCount, + "result", + "hit" + ); + counter(registry, "hibernate.cache.query.requests", "The number of cached queries not found in cache", + Statistics::getQueryCacheMissCount, "result", "miss" + ); + counter(registry, "hibernate.cache.query.puts", "The number of cacheable queries put in cache", + Statistics::getQueryCachePutCount + ); + counter(registry, + "hibernate.cache.query.plan", + "The global number of query plans successfully retrieved from cache", + Statistics::getQueryPlanCacheHitCount, + "result", + "hit" + ); + counter(registry, "hibernate.cache.query.plan", "The global number of query plans lookups not found in cache", + Statistics::getQueryPlanCacheMissCount, "result", "miss" + ); + } + + private boolean hasDomainDataRegionStatistics(String regionName) { + // This appears to be a _qualified + // In 5.3, getDomainDataRegionStatistics (a new method) will throw an IllegalArgumentException + // if the region can't be resolved. + try { + return statistics.getDomainDataRegionStatistics( regionName ) != null; + } + catch (IllegalArgumentException e) { + return false; + } + } + + /** + * Unwrap the {@link SessionFactory} from {@link EntityManagerFactory}. + * + * @param entityManagerFactory {@link EntityManagerFactory} to unwrap + * + * @return unwrapped {@link SessionFactory} + */ + @Nullable + private SessionFactory unwrap(EntityManagerFactory entityManagerFactory) { + try { + return entityManagerFactory.unwrap( SessionFactory.class ); + } + catch (PersistenceException ex) { + return null; + } + } + +} diff --git a/hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateQueryMetrics.java b/hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateQueryMetrics.java new file mode 100644 index 0000000000..21f9687cb0 --- /dev/null +++ b/hibernate-micrometer/src/main/java/org/hibernate/stat/HibernateQueryMetrics.java @@ -0,0 +1,188 @@ +/* + * Hibernate, Relational Persistence for Idiomatic Java + * + * License: GNU Lesser General Public License (LGPL), version 2.1 or later. + * See the lgpl.txt file in the root directory or . + */ +package org.hibernate.stat; + +import io.micrometer.core.instrument.*; +import io.micrometer.core.instrument.binder.MeterBinder; +import io.micrometer.core.lang.NonNullApi; +import io.micrometer.core.lang.NonNullFields; + +import org.hibernate.SessionFactory; +import org.hibernate.engine.spi.SessionFactoryImplementor; +import org.hibernate.event.service.spi.EventListenerRegistry; +import org.hibernate.event.spi.EventType; +import org.hibernate.event.spi.PostLoadEvent; +import org.hibernate.event.spi.PostLoadEventListener; + +import java.util.concurrent.TimeUnit; + +/** + * A {@link MeterBinder} implementation that provides Hibernate query metrics. It exposes the + * same statistics as would be exposed when calling {@link Statistics#getQueryStatistics(String)}. + * Note that only SELECT queries are recorded in {@link QueryStatistics}. + *

+ * Be aware of the potential for high cardinality of unique Hibernate queries executed by your + * application when considering using this {@link MeterBinder}. + */ +@NonNullApi +@NonNullFields +public class HibernateQueryMetrics implements MeterBinder { + + private static final String SESSION_FACTORY_TAG_NAME = "entityManagerFactory"; + + private final Iterable tags; + + private final SessionFactory sessionFactory; + + /** + * Create {@code HibernateQueryMetrics} and bind to the specified meter registry. + * + * @param registry meter registry to use + * @param sessionFactory session factory to use + * @param sessionFactoryName session factory name as a tag value + * @param tags additional tags + */ + public static void monitor( + MeterRegistry registry, + SessionFactory sessionFactory, + String sessionFactoryName, + String... tags) { + monitor( registry, sessionFactory, sessionFactoryName, Tags.of( tags ) ); + } + + /** + * Create {@code HibernateQueryMetrics} and bind to the specified meter registry. + * + * @param registry meter registry to use + * @param sessionFactory session factory to use + * @param sessionFactoryName session factory name as a tag value + * @param tags additional tags + */ + public static void monitor( + MeterRegistry registry, + SessionFactory sessionFactory, + String sessionFactoryName, + Iterable tags) { + new HibernateQueryMetrics( sessionFactory, sessionFactoryName, tags ).bindTo( registry ); + } + + /** + * Create a {@code HibernateQueryMetrics}. + * + * @param sessionFactory session factory to use + * @param sessionFactoryName session factory name as a tag value + * @param tags additional tags + */ + public HibernateQueryMetrics(SessionFactory sessionFactory, String sessionFactoryName, Iterable tags) { + this.tags = Tags.concat( tags, SESSION_FACTORY_TAG_NAME, sessionFactoryName ); + this.sessionFactory = sessionFactory; + } + + @Override + public void bindTo(MeterRegistry meterRegistry) { + if ( sessionFactory instanceof SessionFactoryImplementor ) { + EventListenerRegistry eventListenerRegistry = ( (SessionFactoryImplementor) sessionFactory ).getServiceRegistry() + .getService( EventListenerRegistry.class ); + MetricsEventHandler metricsEventHandler = new MetricsEventHandler( meterRegistry ); + eventListenerRegistry.appendListeners( EventType.POST_LOAD, metricsEventHandler ); + } + } + + class MetricsEventHandler implements PostLoadEventListener { + + private final MeterRegistry meterRegistry; + + MetricsEventHandler(MeterRegistry meterRegistry) { + this.meterRegistry = meterRegistry; + } + + @Override + public void onPostLoad(PostLoadEvent event) { + registerQueryMetric( event.getSession().getFactory().getStatistics() ); + } + + void registerQueryMetric(Statistics statistics) { + for ( String query : statistics.getQueries() ) { + QueryStatistics queryStatistics = statistics.getQueryStatistics( query ); + + FunctionCounter.builder( + "hibernate.query.cache.requests", + queryStatistics, + QueryStatistics::getCacheHitCount + ) + .tags( tags ) + .tags( "result", "hit", "query", query ) + .description( "Number of query cache hits" ) + .register( meterRegistry ); + + FunctionCounter.builder( + "hibernate.query.cache.requests", + queryStatistics, + QueryStatistics::getCacheMissCount + ) + .tags( tags ) + .tags( "result", "miss", "query", query ) + .description( "Number of query cache misses" ) + .register( meterRegistry ); + + FunctionCounter.builder( + "hibernate.query.cache.puts", + queryStatistics, + QueryStatistics::getCachePutCount + ) + .tags( tags ) + .tags( "query", query ) + .description( "Number of cache puts for a query" ) + .register( meterRegistry ); + + FunctionTimer.builder( + "hibernate.query.execution.total", + queryStatistics, + QueryStatistics::getExecutionCount, + QueryStatistics::getExecutionTotalTime, + TimeUnit.MILLISECONDS + ) + .tags( tags ) + .tags( "query", query ) + .description( "Query executions" ) + .register( meterRegistry ); + + TimeGauge.builder( + "hibernate.query.execution.max", + queryStatistics, + TimeUnit.MILLISECONDS, + QueryStatistics::getExecutionMaxTime + ) + .tags( tags ) + .tags( "query", query ) + .description( "Query maximum execution time" ) + .register( meterRegistry ); + + TimeGauge.builder( + "hibernate.query.execution.min", + queryStatistics, + TimeUnit.MILLISECONDS, + QueryStatistics::getExecutionMinTime + ) + .tags( tags ) + .tags( "query", query ) + .description( "Query minimum execution time" ) + .register( meterRegistry ); + + FunctionCounter.builder( + "hibernate.query.execution.rows", + queryStatistics, + QueryStatistics::getExecutionRowCount + ) + .tags( tags ) + .tags( "query", query ) + .description( "Number of rows processed for a query" ) + .register( meterRegistry ); + } + } + } +} diff --git a/hibernate-micrometer/src/test/java/org/hibernate/test/stat/Account.java b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/Account.java new file mode 100644 index 0000000000..0cc4ea1eb3 --- /dev/null +++ b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/Account.java @@ -0,0 +1,41 @@ +/* + * Hibernate, Relational Persistence for Idiomatic Java + * + * License: GNU Lesser General Public License (LGPL), version 2.1 or later. + * See the lgpl.txt file in the root directory or . + */ +package org.hibernate.test.stat; + +import javax.persistence.Basic; +import javax.persistence.EmbeddedId; +import javax.persistence.Entity; +import javax.persistence.Table; + +import org.hibernate.annotations.NaturalId; + +@Entity +@Table( name = "t_acct" ) +public class Account { + @EmbeddedId + private AccountId accountId; + + @Basic( optional = false ) + @NaturalId + private String shortCode; + + protected Account() { + } + + public Account(AccountId accountId, String shortCode) { + this.accountId = accountId; + this.shortCode = shortCode; + } + + public AccountId getAccountId() { + return accountId; + } + + public String getShortCode() { + return shortCode; + } +} diff --git a/hibernate-micrometer/src/test/java/org/hibernate/test/stat/AccountId.java b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/AccountId.java new file mode 100644 index 0000000000..1112721949 --- /dev/null +++ b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/AccountId.java @@ -0,0 +1,43 @@ +/* + * Hibernate, Relational Persistence for Idiomatic Java + * + * License: GNU Lesser General Public License (LGPL), version 2.1 or later. + * See the lgpl.txt file in the root directory or . + */ +package org.hibernate.test.stat; + +import javax.persistence.Embeddable; + +@Embeddable +public class AccountId implements java.io.Serializable { + private final int id; + + protected AccountId() { + this.id = 0; + } + + public AccountId(int id) { + this.id = id; + } + public int intValue() { + return id; + } + @Override + public int hashCode() { + return id; + } + @Override + public boolean equals(Object obj) { + if (this == obj) + return true; + if (obj == null) + return false; + if (getClass() != obj.getClass()) + return false; + AccountId other = (AccountId) obj; + if (other != null && id != other.id) + return false; + return true; + } +} + diff --git a/hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerCacheStatisticsTest.java b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerCacheStatisticsTest.java new file mode 100644 index 0000000000..0430e3db28 --- /dev/null +++ b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerCacheStatisticsTest.java @@ -0,0 +1,208 @@ +/* + * Hibernate, Relational Persistence for Idiomatic Java + * + * License: GNU Lesser General Public License (LGPL), version 2.1 or later. + * See the lgpl.txt file in the root directory or . + */ +package org.hibernate.test.stat; + +import java.util.List; +import java.util.Map; +import javax.persistence.Cacheable; +import javax.persistence.ElementCollection; +import javax.persistence.Entity; +import javax.persistence.Id; +import javax.persistence.Table; + +import org.hibernate.Session; +import org.hibernate.annotations.Cache; +import org.hibernate.annotations.CacheConcurrencyStrategy; +import org.hibernate.annotations.NaturalId; +import org.hibernate.annotations.NaturalIdCache; +import org.hibernate.boot.MetadataSources; +import org.hibernate.boot.registry.StandardServiceRegistryBuilder; +import org.hibernate.cfg.AvailableSettings; +import org.hibernate.stat.HibernateMetrics; + +import org.hibernate.testing.cache.CachingRegionFactory; +import org.hibernate.testing.junit4.BaseNonConfigCoreFunctionalTestCase; +import org.junit.After; +import org.junit.Assert; +import org.junit.Before; +import org.junit.Test; + +import io.micrometer.core.instrument.Tags; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; + +/** + * @author Erin Schnabel + * @author Steve Ebersole + */ +public class MicrometerCacheStatisticsTest extends BaseNonConfigCoreFunctionalTestCase { + + @Override + protected void applyMetadataSources(MetadataSources metadataSources) { + super.applyMetadataSources( metadataSources ); + metadataSources.addAnnotatedClass( Person.class ); + metadataSources.addAnnotatedClass( Account.class ); + metadataSources.addAnnotatedClass( AccountId.class ); + } + + private static final String REGION = "TheRegion"; + private static final String PREFIX = "test"; + + private SimpleMeterRegistry registry = new SimpleMeterRegistry(); + private HibernateMetrics hibernateMetrics; + + @Override + protected void configureStandardServiceRegistryBuilder(StandardServiceRegistryBuilder ssrb) { + super.configureStandardServiceRegistryBuilder( ssrb ); + ssrb.applySetting( AvailableSettings.USE_SECOND_LEVEL_CACHE, true ); + ssrb.applySetting( AvailableSettings.USE_QUERY_CACHE, true ); + ssrb.applySetting( AvailableSettings.CACHE_REGION_FACTORY, new CachingRegionFactory() ); + ssrb.applySetting( AvailableSettings.GENERATE_STATISTICS, "true" ); + } + + @Override + protected void addSettings(Map settings) { + super.addSettings( settings ); + settings.put( AvailableSettings.USE_SECOND_LEVEL_CACHE, "true" ); + settings.put( AvailableSettings.USE_QUERY_CACHE, "true" ); + settings.put( AvailableSettings.CACHE_REGION_FACTORY, new CachingRegionFactory() ); + + settings.put( AvailableSettings.GENERATE_STATISTICS, "true" ); + settings.put( AvailableSettings.HBM2DDL_AUTO, "create-drop" ); + settings.put( AvailableSettings.SESSION_FACTORY_NAME, "something" ); + settings.put( AvailableSettings.SESSION_FACTORY_NAME_IS_JNDI, "false" ); + } + + @Before + public void setUpMetrics() { + hibernateMetrics = new HibernateMetrics(sessionFactory(), + sessionFactory().getName(), + Tags.empty() ); + hibernateMetrics.bindTo( registry ); + } + + @After + public void cleanUpMetrics() { + registry.clear(); + } + + @Test + public void testMicrometerMetrics() { + Assert.assertNotNull(registry.get("hibernate.sessions.open").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.sessions.closed").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.transactions").tags("result", "success").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.transactions").tags("result", "failure").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.optimistic.failures").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.flushes").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.connections.obtained").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.statements").tags("status", "prepared").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.statements").tags("status", "closed").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.second.level.cache.requests").tags("result", "hit", "region", REGION)); + Assert.assertNotNull(registry.get("hibernate.second.level.cache.requests").tags("result", "miss", "region", REGION)); + Assert.assertNotNull(registry.get("hibernate.second.level.cache.puts").tags("region", REGION).functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.entities.deletes").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.fetches").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.inserts").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.loads").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.updates").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.collections.deletes").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.fetches").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.loads").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.recreates").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.updates").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.cache.natural.id.requests").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.natural.id.requests").tags("result", "miss").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.natural.id.puts").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.query.natural.id.executions").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.query.natural.id.executions.max").timeGauge()); + + Assert.assertNotNull(registry.get("hibernate.query.executions").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.query.executions.max").timeGauge()); + + Assert.assertNotNull(registry.get("hibernate.cache.update.timestamps.requests").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.update.timestamps.requests").tags("result", "miss").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.update.timestamps.puts").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.cache.query.requests").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.requests").tags("result", "miss").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.puts").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.plan").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.plan").tags("result", "miss").functionCounter()); + + // prepare some test data... + Session session = openSession(); + session.beginTransaction(); + Person person = new Person( 1, "testAcct"); + session.save( person ); + session.getTransaction().commit(); + session.close(); + + Assert.assertEquals( 1, registry.get("hibernate.sessions.open").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.sessions.closed").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.entities.inserts").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.transactions").tags("result", "success").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.cache.natural.id.puts").functionCounter().count(), 0); + Assert.assertEquals(2, registry.get("hibernate.second.level.cache.puts").tags("region", REGION).functionCounter().count(), 0); + + final String queryString = "select p from Person p"; + inTransaction( + // Only way to generate query region (to be accessible via stats) is to execute the query + s -> s.createQuery( queryString ).setCacheable( true ).setCacheRegion( REGION ).list() + ); + + Assert.assertEquals( 2, registry.get("hibernate.sessions.open").functionCounter().count(), 0 ); + Assert.assertEquals( 2, registry.get("hibernate.sessions.closed").functionCounter().count(), 0 ); + Assert.assertEquals( 0, registry.get("hibernate.entities.deletes").functionCounter().count(), 0 ); + Assert.assertEquals( 2, registry.get("hibernate.transactions").tags("result", "success").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.cache.natural.id.puts").functionCounter().count(), 0); + Assert.assertEquals(3, registry.get("hibernate.second.level.cache.puts").tags("region", REGION).functionCounter().count(), 0); + + // clean up + session = openSession(); + session.beginTransaction(); + session.delete( person ); + session.getTransaction().commit(); + session.close(); + + Assert.assertEquals( 3, registry.get("hibernate.sessions.open").functionCounter().count(), 0 ); + Assert.assertEquals( 3, registry.get("hibernate.sessions.closed").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.entities.deletes").functionCounter().count(), 0 ); + Assert.assertEquals( 3, registry.get("hibernate.transactions").tags("result", "success").functionCounter().count(), 0 ); + } + + @Entity( name = "Person" ) + @Table( name = "persons" ) + @Cacheable + @Cache( region = REGION, usage = CacheConcurrencyStrategy.READ_WRITE ) + @NaturalIdCache( region = REGION ) + public static class Person { + @Id + public Integer id; + + @NaturalId + public String name; + + protected Person() { + } + + public Person(int id, String name) { + this.id = id; + this.name = name; + } + + @ElementCollection + @Cache( region = REGION, usage = CacheConcurrencyStrategy.READ_WRITE ) + public List nickNames; + } +} diff --git a/hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerStatisticsTest.java b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerStatisticsTest.java new file mode 100644 index 0000000000..43965841e1 --- /dev/null +++ b/hibernate-micrometer/src/test/java/org/hibernate/test/stat/MicrometerStatisticsTest.java @@ -0,0 +1,147 @@ +/* + * Hibernate, Relational Persistence for Idiomatic Java + * + * License: GNU Lesser General Public License (LGPL), version 2.1 or later. + * See the lgpl.txt file in the root directory or . + */ +package org.hibernate.test.stat; + +import org.hibernate.Session; +import org.hibernate.cfg.Configuration; +import org.hibernate.cfg.Environment; +import org.hibernate.stat.HibernateMetrics; + +import org.hibernate.testing.junit4.BaseCoreFunctionalTestCase; +import org.junit.After; +import org.junit.Assert; +import org.junit.Before; +import org.junit.Test; + +import io.micrometer.core.instrument.Tags; +import io.micrometer.core.instrument.search.MeterNotFoundException; +import io.micrometer.core.instrument.simple.SimpleMeterRegistry; + +import static org.junit.Assert.assertEquals; + +/** + * @author Erin Schnabel + * @author Donnchadh O Donnabhain + */ +public class MicrometerStatisticsTest extends BaseCoreFunctionalTestCase { + + @Override + protected Class[] getAnnotatedClasses() { + return new Class[] { Account.class, AccountId.class }; + } + + private SimpleMeterRegistry registry = new SimpleMeterRegistry(); + private HibernateMetrics hibernateMetrics; + + @Override + protected void configure(Configuration configuration) { + super.configure( configuration ); + + configuration.setProperty( Environment.USE_SECOND_LEVEL_CACHE, "false" ); + configuration.setProperty( Environment.USE_QUERY_CACHE, "false" ); + configuration.setProperty( Environment.GENERATE_STATISTICS, "true" ); + configuration.setProperty( Environment.SESSION_FACTORY_NAME, "something" ); + configuration.setProperty( Environment.SESSION_FACTORY_NAME_IS_JNDI, "false" ); + } + + @Before + public void setUpMetrics() { + hibernateMetrics = new HibernateMetrics(sessionFactory(), + sessionFactory().getName(), + Tags.empty() ); + hibernateMetrics.bindTo( registry ); + } + + @After + public void cleanUpMetrics() { + registry.clear(); + } + + @Test + public void testMicrometerMetrics() { + Assert.assertNotNull(registry.get("hibernate.sessions.open").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.sessions.closed").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.transactions").tags("result", "success").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.transactions").tags("result", "failure").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.optimistic.failures").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.flushes").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.connections.obtained").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.statements").tags("status", "prepared").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.statements").tags("status", "closed").functionCounter()); + + // Second level cache disabled + verifyMeterNotFoundException("hibernate.second.level.cache.requests"); + verifyMeterNotFoundException("hibernate.second.level.cache.puts"); + + Assert.assertNotNull(registry.get("hibernate.entities.deletes").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.fetches").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.inserts").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.loads").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.entities.updates").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.collections.deletes").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.fetches").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.loads").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.recreates").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.collections.updates").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.cache.natural.id.requests").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.natural.id.requests").tags("result", "miss").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.natural.id.puts").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.query.natural.id.executions").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.query.natural.id.executions.max").timeGauge()); + + Assert.assertNotNull(registry.get("hibernate.query.executions").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.query.executions.max").timeGauge()); + + Assert.assertNotNull(registry.get("hibernate.cache.update.timestamps.requests").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.update.timestamps.requests").tags("result", "miss").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.update.timestamps.puts").functionCounter()); + + Assert.assertNotNull(registry.get("hibernate.cache.query.requests").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.requests").tags("result", "miss").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.puts").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.plan").tags("result", "hit").functionCounter()); + Assert.assertNotNull(registry.get("hibernate.cache.query.plan").tags("result", "miss").functionCounter()); + + // prepare some test data... + Session session = openSession(); + session.beginTransaction(); + Account account = new Account( new AccountId( 1), "testAcct"); + session.save( account ); + session.getTransaction().commit(); + session.close(); + + Assert.assertEquals( 1, registry.get("hibernate.sessions.open").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.sessions.closed").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.entities.inserts").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.transactions").tags("result", "success").functionCounter().count(), 0 ); + + // clean up + session = openSession(); + session.beginTransaction(); + session.delete( account ); + session.getTransaction().commit(); + session.close(); + + Assert.assertEquals( 2, registry.get("hibernate.sessions.open").functionCounter().count(), 0 ); + Assert.assertEquals( 2, registry.get("hibernate.sessions.closed").functionCounter().count(), 0 ); + Assert.assertEquals( 1, registry.get("hibernate.entities.deletes").functionCounter().count(), 0 ); + Assert.assertEquals( 2, registry.get("hibernate.transactions").tags("result", "success").functionCounter().count(), 0 ); + } + + void verifyMeterNotFoundException(String name) { + try { + registry.get(name).meter(); + Assert.fail(name + " should not have been found"); + } catch(MeterNotFoundException mnfe) { + } + } +} diff --git a/hibernate-micrometer/src/test/resources/hibernate.properties b/hibernate-micrometer/src/test/resources/hibernate.properties new file mode 100644 index 0000000000..de12583ef4 --- /dev/null +++ b/hibernate-micrometer/src/test/resources/hibernate.properties @@ -0,0 +1,27 @@ +# +# Hibernate, Relational Persistence for Idiomatic Java +# +# License: GNU Lesser General Public License (LGPL), version 2.1 or later. +# See the lgpl.txt file in the root directory or . +# + +hibernate.dialect @db.dialect@ +hibernate.connection.driver_class @jdbc.driver@ +hibernate.connection.url @jdbc.url@ +hibernate.connection.username @jdbc.user@ +hibernate.connection.password @jdbc.pass@ + +hibernate.connection.pool_size 5 + +hibernate.show_sql false +hibernate.format_sql true + +hibernate.max_fetch_depth 5 + +hibernate.cache.region_prefix hibernate.test +hibernate.cache.region.factory_class org.hibernate.testing.cache.CachingRegionFactory + +javax.persistence.validation.mode=NONE +hibernate.service.allow_crawling=false +hibernate.session.events.log=true +hibernate.hql.bulk_id_strategy.global_temporary.drop_tables=true \ No newline at end of file diff --git a/hibernate-micrometer/src/test/resources/log4j.properties b/hibernate-micrometer/src/test/resources/log4j.properties new file mode 100644 index 0000000000..4567cb1105 --- /dev/null +++ b/hibernate-micrometer/src/test/resources/log4j.properties @@ -0,0 +1,19 @@ +# +# Hibernate, Relational Persistence for Idiomatic Java +# +# License: GNU Lesser General Public License (LGPL), version 2.1 or later. +# See the lgpl.txt file in the root directory or . +# +log4j.appender.stdout=org.apache.log4j.ConsoleAppender +log4j.appender.stdout.Target=System.out +log4j.appender.stdout.layout=org.apache.log4j.PatternLayout +log4j.appender.stdout.layout.ConversionPattern=%d{ABSOLUTE} %5p %c{1}:%L - %m%n + +log4j.rootLogger=info, stdout + +log4j.logger.org.hibernate.stat=trace + +log4j.logger.org.hibernate.tool.hbm2ddl=trace +log4j.logger.org.hibernate.SQL=debug +log4j.logger.org.hibernate.type.descriptor.sql.BasicBinder=trace +log4j.logger.org.hibernate.type.descriptor.sql.BasicExtractor=trace \ No newline at end of file diff --git a/settings.gradle b/settings.gradle index 280858666f..54000713c5 100644 --- a/settings.gradle +++ b/settings.gradle @@ -105,7 +105,7 @@ include 'hibernate-agroal' include 'hibernate-jcache' include 'hibernate-ehcache' include 'hibernate-infinispan' - +include 'hibernate-micrometer' include 'hibernate-graalvm' // The plugin used to generate Java modules was compiled using JDK11.