Added per-query metrics in HibernateStatisticsCollector (#388)

thombergs · brian-brazil · commit 09cb6ab3fda7 · 2018-07-13T14:49:25.000+01:00
exposing accumulated total execution time per query
(update to Hibernate 5 was necessary)
moved hibernate dependency to 5.2.0


Signed-off-by: Tom Hombergs &lt;tom.hombergs@gmail.com&gt;
diff --git a/simpleclient_hibernate/pom.xml b/simpleclient_hibernate/pom.xml
@@ -45,7 +45,7 @@
         <dependency>
             <groupId>org.hibernate</groupId>
             <artifactId>hibernate-core</artifactId>
-            <version>4.2.0.Final</version>
+            <version>5.2.0.Final</version>
             <scope>provided</scope>
         </dependency>
 
diff --git a/simpleclient_hibernate/src/main/java/io/prometheus/client/hibernate/HibernateStatisticsCollector.java b/simpleclient_hibernate/src/main/java/io/prometheus/client/hibernate/HibernateStatisticsCollector.java
@@ -3,6 +3,7 @@
 import io.prometheus.client.Collector;
 import io.prometheus.client.CollectorRegistry;
 import io.prometheus.client.CounterMetricFamily;
+import io.prometheus.client.GaugeMetricFamily;
 import java.util.ArrayList;
 import java.util.Arrays;
 import java.util.Collections;
@@ -32,15 +33,23 @@
  * SessionFactory sessionFactory =
  *     entityManagerFactory.unwrap(SessionFactory.class);
  * </pre>
+ * <p>
+ * When {@code enablePerQueryMetrics()} has been called, certain metrics like execution
+ * time are collected per query. This may create a lot of monitoring data, so it should
+ * be used with caution.
  *
  * @author Christian Kaltepoth
  */
 public class HibernateStatisticsCollector extends Collector {
 
   private static final List<String> LABEL_NAMES = Collections.singletonList("unit");
 
+  private static final List<String> LABEL_NAMES_PER_QUERY = Arrays.asList("unit", "query");
+
   private final Map<String, SessionFactory> sessionFactories = new ConcurrentHashMap<String, SessionFactory>();
 
+  private boolean perQueryMetricsEnabled;
+
   /**
    * Creates an empty collector. If you use this constructor, you have to add one or more
    * session factories to the collector by calling the {@link #add(SessionFactory, String)}
@@ -74,6 +83,19 @@ public HibernateStatisticsCollector add(SessionFactory sessionFactory, String na
     return this;
   }
 
+  /**
+   * Enables collection of per-query metrics. Produces a lot of monitoring data, so use with caution.
+   * <p>
+   * Per-query metrics have a label "query" with the actual HQL query as value. The query will contain
+   * placeholders ("?") instead of the real parameter values (example: {@code select u from User u where id=?}).
+   *
+   * @return Returns the collector
+   */
+  public HibernateStatisticsCollector enablePerQueryMetrics() {
+    this.perQueryMetricsEnabled = true;
+    return this;
+  }
+
   @Override
   public List<MetricFamilySamples> collect() {
     List<MetricFamilySamples> metrics = new ArrayList<MetricFamilySamples>();
@@ -82,6 +104,9 @@ public List<MetricFamilySamples> collect() {
     metrics.addAll(getCacheMetrics());
     metrics.addAll(getEntityMetrics());
     metrics.addAll(getQueryExecutionMetrics());
+    if (perQueryMetricsEnabled) {
+      metrics.addAll(getPerQueryMetrics());
+    }
     return metrics;
   }
 
@@ -448,25 +473,176 @@ public double getValue(Statistics statistics) {
     );
   }
 
+  private List<MetricFamilySamples> getPerQueryMetrics() {
+    List<MetricFamilySamples> metrics = new ArrayList<MetricFamilySamples>();
+
+    metrics.addAll(Arrays.asList(
+
+        createCounterForQuery("hibernate_per_query_cache_hit_total",
+                "Global number of cache hits for query (getCacheHitCount)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return statistics.getQueryStatistics(query)
+                        .getCacheHitCount();
+              }
+            }
+        ),
+        createCounterForQuery("hibernate_per_query_cache_miss_total",
+                "Global number of cache misses for query (getCacheMissCount)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return statistics.getQueryStatistics(query)
+                        .getCacheMissCount();
+              }
+            }
+        ),
+        createCounterForQuery("hibernate_per_query_cache_put_total",
+                "Global number of cache puts for query (getCachePutCount)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return statistics.getQueryStatistics(query)
+                        .getCachePutCount();
+              }
+            }
+        ),
+        createCounterForQuery("hibernate_per_query_execution_total",
+                "Global number of executions for query (getExecutionCount)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return statistics.getQueryStatistics(query)
+                        .getExecutionCount();
+              }
+            }
+        ),
+        createCounterForQuery("hibernate_per_query_execution_rows_total",
+                "Global number of rows for all executions of query (getExecutionRowCount)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return statistics.getQueryStatistics(query)
+                        .getExecutionRowCount();
+              }
+            }
+        ),
+        createGaugeForQuery("hibernate_per_query_execution_min_seconds",
+                "Minimum execution time of query in seconds (based on getExecutionMinTime)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return toSeconds(statistics.getQueryStatistics(query)
+                        .getExecutionMinTime());
+              }
+            }
+        ),
+        createGaugeForQuery("hibernate_per_query_execution_max_seconds",
+                "Maximum execution time of query in seconds (based on getExecutionMaxTime)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return toSeconds(statistics.getQueryStatistics(query)
+                        .getExecutionMaxTime());
+              }
+            }
+        ),
+        createCounterForQuery("hibernate_per_query_execution_seconds_total",
+            "Accumulated execution time of query in seconds (based on getExecutionTotalTime)",
+            new ValueProviderPerQuery() {
+              @Override
+              public double getValue(Statistics statistics, String query) {
+                return toSeconds(statistics.getQueryStatistics(query)
+                    .getExecutionTotalTime());
+              }
+            }
+        )
+    ));
+
+    return metrics;
+  }
+
   private CounterMetricFamily createCounter(String metric, String help, ValueProvider provider) {
 
     CounterMetricFamily metricFamily = new CounterMetricFamily(metric, help, LABEL_NAMES);
 
     for (Entry<String, SessionFactory> entry : sessionFactories.entrySet()) {
       metricFamily.addMetric(
-          Collections.singletonList(entry.getKey()),
-          provider.getValue(entry.getValue().getStatistics())
+              Collections.singletonList(entry.getKey()),
+              provider.getValue(entry.getValue().getStatistics())
       );
     }
 
     return metricFamily;
 
   }
 
+  private CounterMetricFamily createCounterForQuery(String metric, String help, ValueProviderPerQuery provider) {
+
+    final CounterMetricFamily counters = new CounterMetricFamily(metric, help, LABEL_NAMES_PER_QUERY);
+
+    addMetricsForQuery(new PerQuerySamples() {
+      @Override
+      public void addMetric(List<String> labelValues, double value) {
+        counters.addMetric(labelValues, value);
+      }
+    }, provider);
+
+    return counters;
+
+  }
+
+  private GaugeMetricFamily createGaugeForQuery(String metric, String help, ValueProviderPerQuery provider) {
+
+    final GaugeMetricFamily gauges = new GaugeMetricFamily(metric, help, LABEL_NAMES_PER_QUERY);
+
+    addMetricsForQuery(new PerQuerySamples() {
+      @Override
+      public void addMetric(List<String> labelValues, double value) {
+        gauges.addMetric(labelValues, value);
+      }
+    }, provider);
+
+    return gauges;
+
+  }
+
+  private void addMetricsForQuery(PerQuerySamples samples, ValueProviderPerQuery provider) {
+
+    for (Entry<String, SessionFactory> entry : sessionFactories.entrySet()) {
+      SessionFactory sessionFactory = entry.getValue();
+      Statistics stats = sessionFactory.getStatistics();
+      String unitName = entry.getKey();
+
+      for (String query : stats.getQueries()) {
+        samples.addMetric(Arrays.asList(unitName, query), provider.getValue(stats, query));
+      }
+    }
+  }
+
+  private double toSeconds(long milliseconds){
+    return milliseconds / 1000d;
+  }
+
+  private interface PerQuerySamples {
+
+    void addMetric(List<String> labelValues, double value);
+
+  }
+
+
   private interface ValueProvider {
 
     double getValue(Statistics statistics);
 
   }
 
+  private interface ValueProviderPerQuery {
+
+    double getValue(Statistics statistics, String query);
+
+  }
+
+
 }
diff --git a/simpleclient_hibernate/src/test/java/io/prometheus/client/hibernate/HibernateStatisticsCollectorTest.java b/simpleclient_hibernate/src/test/java/io/prometheus/client/hibernate/HibernateStatisticsCollectorTest.java
@@ -1,12 +1,15 @@
 package io.prometheus.client.hibernate;
 
 import static org.hamcrest.CoreMatchers.is;
+import static org.hamcrest.CoreMatchers.nullValue;
 import static org.junit.Assert.assertThat;
+import static org.mockito.ArgumentMatchers.eq;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.when;
 
 import io.prometheus.client.CollectorRegistry;
 import org.hibernate.SessionFactory;
+import org.hibernate.stat.QueryStatistics;
 import org.hibernate.stat.Statistics;
 import org.junit.Before;
 import org.junit.Rule;
@@ -20,13 +23,15 @@ public class HibernateStatisticsCollectorTest {
 
   private SessionFactory sessionFactory;
   private Statistics statistics;
+  private QueryStatistics queryStatistics;
   private CollectorRegistry registry;
 
   @Before
   public void before() {
     registry = new CollectorRegistry();
     sessionFactory = mock(SessionFactory.class);
     statistics = mock(Statistics.class);
+    queryStatistics = mock(QueryStatistics.class);
     when(sessionFactory.getStatistics()).thenReturn(statistics);
   }
 
@@ -159,6 +164,60 @@ public void shouldPublishQueryExecutionMetrics() {
 
   }
 
+  @Test
+  public void shouldPublishPerQueryMetricsWhenEnabled() {
+    String query = "query";
+    mockQueryStatistics(query);
+
+    new HibernateStatisticsCollector()
+            .add(sessionFactory, "factory6")
+            .enablePerQueryMetrics()
+            .register(registry);
+
+    assertThat(getSampleForQuery("hibernate_per_query_cache_hit_total", "factory6", query), is(1.0));
+    assertThat(getSampleForQuery("hibernate_per_query_cache_miss_total", "factory6", query), is(2.0));
+    assertThat(getSampleForQuery("hibernate_per_query_cache_put_total", "factory6", query), is(3.0));
+    assertThat(getSampleForQuery("hibernate_per_query_execution_max_seconds", "factory6", query), is(0.555d));
+    assertThat(getSampleForQuery("hibernate_per_query_execution_min_seconds", "factory6", query), is(0.123d));
+    assertThat(getSampleForQuery("hibernate_per_query_execution_rows_total", "factory6", query), is(7.0));
+    assertThat(getSampleForQuery("hibernate_per_query_execution_total", "factory6", query), is(8.0));
+    assertThat(getSampleForQuery("hibernate_per_query_execution_seconds_total", "factory6", query), is(102.540d));
+
+  }
+
+  @Test
+  public void shouldNotPublishPerQueryMetricsByDefault() {
+    String query = "query";
+    mockQueryStatistics(query);
+
+    new HibernateStatisticsCollector()
+            .add(sessionFactory, "factory7")
+            .register(registry);
+
+    assertThat(getSampleForQuery("hibernate_per_query_cache_hit_total", "factory7", query), nullValue());
+    assertThat(getSampleForQuery("hibernate_per_query_cache_miss_total", "factory7", query), nullValue());
+    assertThat(getSampleForQuery("hibernate_per_query_cache_put_total", "factory7", query), nullValue());
+    assertThat(getSampleForQuery("hibernate_per_query_execution_max_seconds", "factory7", query), nullValue());
+    assertThat(getSampleForQuery("hibernate_per_query_execution_min_seconds", "factory7", query), nullValue());
+    assertThat(getSampleForQuery("hibernate_per_query_execution_rows_total", "factory7", query), nullValue());
+    assertThat(getSampleForQuery("hibernate_per_query_execution_total", "factory7", query), nullValue());
+    assertThat(getSampleForQuery("hibernate_per_query_execution_seconds", "factory7", query), nullValue());
+
+  }
+
+  private void mockQueryStatistics(String query) {
+    when(statistics.getQueries()).thenReturn(new String[]{query});
+    when(statistics.getQueryStatistics(eq(query))).thenReturn(queryStatistics);
+    when(queryStatistics.getCacheHitCount()).thenReturn(1L);
+    when(queryStatistics.getCacheMissCount()).thenReturn(2L);
+    when(queryStatistics.getCachePutCount()).thenReturn(3L);
+    when(queryStatistics.getExecutionMaxTime()).thenReturn(555L);
+    when(queryStatistics.getExecutionMinTime()).thenReturn(123L);
+    when(queryStatistics.getExecutionRowCount()).thenReturn(7L);
+    when(queryStatistics.getExecutionCount()).thenReturn(8L);
+    when(queryStatistics.getExecutionTotalTime()).thenReturn(102540L);
+  }
+
   @Test
   public void shouldFailIfNoSessionFactoriesAreRegistered() {
 
@@ -175,4 +234,10 @@ private Double getSample(String metric, String factory) {
     );
   }
 
+  private Double getSampleForQuery(String metric, String factory, String query) {
+    return registry.getSampleValue(
+            metric, new String[]{"unit", "query"}, new String[]{factory, query}
+    );
+  }
+
 }
