HHH-14632 - Call statistics.queryPlanCacheHit and statistics.queryPlanCacheMiss for FilterQueryPlan and NativeSQLQueryPlan

Author: vladmihalcea

hibernate-core/src/main/java/org/hibernate/engine/query/spi/QueryPlanCache.java

@@ -200,17 +200,26 @@ public FilterQueryPlan getFilterQueryPlan(
 			Map<String,Filter> enabledFilters) throws QueryException, MappingException {
 		final FilterQueryPlanKey key =  new FilterQueryPlanKey( filterString, collectionRole, shallow, enabledFilters );
 		FilterQueryPlan value = (FilterQueryPlan) queryPlanCache.get( key );
+		final StatisticsImplementor statistics = factory.getStatistics();
+		boolean stats = statistics.isStatisticsEnabled();
 		if ( value == null ) {
 			LOG.tracev(
 					"Unable to locate collection-filter query plan in cache; generating ({0} : {1} )",
 					collectionRole,
 					filterString
 			);
 			value = new FilterQueryPlan( filterString, collectionRole, shallow, enabledFilters,factory );
+			if ( stats ) {
+				statistics.queryPlanCacheMiss( key.query  );
+			}
 			queryPlanCache.putIfAbsent( key, value );
 		}
 		else {
 			LOG.tracev( "Located collection-filter query plan in cache ({0} : {1})", collectionRole, filterString );
+
+			if ( stats ) {
+				statistics.queryPlanCacheHit( key.query );
+			}
 		}
 		return value;
 	}
@@ -228,13 +237,22 @@ public FilterQueryPlan getFilterQueryPlan(
 	@SuppressWarnings("unchecked")
 	public NativeSQLQueryPlan getNativeSQLQueryPlan(final NativeSQLQuerySpecification spec) {
 		NativeSQLQueryPlan value = (NativeSQLQueryPlan) queryPlanCache.get( spec );
+		final StatisticsImplementor statistics = factory.getStatistics();
+		boolean stats = statistics.isStatisticsEnabled();
 		if ( value == null ) {
 			LOG.tracev( "Unable to locate native-sql query plan in cache; generating ({0})", spec.getQueryString() );
 			value = nativeQueryInterpreter.createQueryPlan( spec, factory );
+			if ( stats ) {
+				statistics.queryPlanCacheMiss( spec.getQueryString() );
+			}
 			queryPlanCache.putIfAbsent( spec, value );
 		}
 		else {
 			LOG.tracev( "Located native-sql query plan in cache ({0})", spec.getQueryString() );
+
+			if ( stats ) {
+				statistics.queryPlanCacheHit( spec.getQueryString() );
+			}
 		}
 		return value;
 	}

hibernate-core/src/main/java/org/hibernate/stat/internal/QueryStatisticsImpl.java

@@ -202,6 +202,10 @@ void incrementPlanCacheHitCount() {
 		planCacheHitCount.increment();
 	}
 
+	void incrementPlanCacheMissCount() {
+		planCacheMissCount.increment();
+	}
+
 	public String toString() {
 		return "QueryStatistics"
 				+ "[query=" + query

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

@@ -805,11 +805,20 @@ public void queryCompiled(String hql, long microseconds) {
 	}
 
 	@Override
-	public void queryPlanCacheHit(String hql) {
+	public void queryPlanCacheHit(String query) {
 		queryPlanCacheHitCount.increment();
 
-		if ( hql != null ) {
-			getQueryStatistics( hql ).incrementPlanCacheHitCount();
+		if ( query != null ) {
+			getQueryStatistics( query ).incrementPlanCacheHitCount();
+		}
+	}
+
+	@Override
+	public void queryPlanCacheMiss(String query) {
+		queryPlanCacheMissCount.increment();
+
+		if ( query != null ) {
+			getQueryStatistics( query ).incrementPlanCacheMissCount();
 		}
 	}
 

hibernate-core/src/main/java/org/hibernate/stat/spi/StatisticsImplementor.java

@@ -251,9 +251,18 @@ public interface StatisticsImplementor extends Statistics, Service {
 	/**
 	 * Callback indicating a get from the query plan cache resulted in a hit.
 	 *
-	 * @param hql The query
+	 * @param query The query
+	 */
+	default void queryPlanCacheHit(String query) {
+		//For backward compatibility
+	}
+
+	/**
+	 * Callback indicating a get from the query plan cache resulted in a miss.
+	 *
+	 * @param query The query
 	 */
-	default void queryPlanCacheHit(String hql) {
+	default void queryPlanCacheMiss(String query) {
 		//For backward compatibility
 	}
 

hibernate-core/src/test/java/org/hibernate/stat/internal/QueryPlanCacheStatisticsTest.java

@@ -14,6 +14,7 @@
 import javax.persistence.Id;
 import javax.persistence.LockModeType;
 import javax.persistence.NamedQuery;
+import javax.persistence.Table;
 import javax.persistence.Tuple;
 import javax.persistence.TypedQuery;
 
@@ -150,7 +151,7 @@ public void testCreateQueryHitCount() {
 
 			assertEquals( 5, employees.size() );
 
-			//The miss count is still 1, as no we got the query plan from the cache
+			//The miss count is still 1, as now we got the query plan from the cache
 			assertEquals( 1, statistics.getQueryPlanCacheMissCount() );
 			//And the cache hit count increases.
 			assertEquals( 1, statistics.getQueryPlanCacheHitCount() );
@@ -164,7 +165,55 @@ public void testCreateQueryHitCount() {
 
 			assertEquals( 5, employees.size() );
 
-			//The miss count is still 1, as no we got the query plan from the cache
+			//The miss count is still 1, as now we got the query plan from the cache
+			assertEquals( 1, statistics.getQueryPlanCacheMissCount() );
+			//And the cache hit count increases.
+			assertEquals( 2, statistics.getQueryPlanCacheHitCount() );
+		} );
+	}
+
+	@Test
+	@TestForIssue( jiraKey = "HHH-14632" )
+	public void testCreateNativeQueryHitCount() {
+		statistics.clear();
+
+		doInJPA( this::entityManagerFactory, entityManager -> {
+
+			List<Employee> employees = entityManager.createNativeQuery(
+				"select * from employee e", Employee.class )
+			.getResultList();
+
+			assertEquals( 5, employees.size() );
+
+			//First time, we get a cache miss, so the query is compiled
+			assertEquals( 1, statistics.getQueryPlanCacheMissCount() );
+			//The hit count should be 0 as we don't need to go to the cache after we already compiled the query
+			assertEquals( 0, statistics.getQueryPlanCacheHitCount() );
+		} );
+
+		doInJPA( this::entityManagerFactory, entityManager -> {
+
+			List<Employee> employees = entityManager.createNativeQuery(
+				"select * from employee e", Employee.class )
+			.getResultList();
+
+			assertEquals( 5, employees.size() );
+
+			//The miss count is still 1, as now we got the query plan from the cache
+			assertEquals( 1, statistics.getQueryPlanCacheMissCount() );
+			//And the cache hit count increases.
+			assertEquals( 1, statistics.getQueryPlanCacheHitCount() );
+		} );
+
+		doInJPA( this::entityManagerFactory, entityManager -> {
+
+			List<Employee> employees = entityManager.createNativeQuery(
+				"select * from employee e", Employee.class )
+			.getResultList();
+
+			assertEquals( 5, employees.size() );
+
+			//The miss count is still 1, as now we got the query plan from the cache
 			assertEquals( 1, statistics.getQueryPlanCacheMissCount() );
 			//And the cache hit count increases.
 			assertEquals( 2, statistics.getQueryPlanCacheHitCount() );
@@ -232,7 +281,7 @@ public void testCreateQueryTupleHitCount() {
 
 			assertEquals( 5, employees.size() );
 
-			//The miss count is still 1, as no we got the query plan from the cache
+			//The miss count is still 1, as now we got the query plan from the cache
 			assertEquals( 1, statistics.getQueryPlanCacheMissCount() );
 			//And the cache hit count increases.
 			assertEquals( 1, statistics.getQueryPlanCacheHitCount() );
@@ -246,7 +295,7 @@ public void testCreateQueryTupleHitCount() {
 
 			assertEquals( 5, employees.size() );
 
-			//The miss count is still 1, as no we got the query plan from the cache
+			//The miss count is still 1, as now we got the query plan from the cache
 			assertEquals( 1, statistics.getQueryPlanCacheMissCount() );
 			//And the cache hit count increases.
 			assertEquals( 2, statistics.getQueryPlanCacheHitCount() );
@@ -292,6 +341,7 @@ private void assertQueryStatistics(String hql, int hitCount) {
 	}
 
 	@Entity(name = "Employee")
+	@Table(name = "employee")
 	@NamedQuery(
 		name = "find_employee_by_name",
 		query = "select e from Employee e where e.name = :name"