#1672 - ENH: Add ebean.dumpMetricsOnShutdown=true ... for dumping metrics

src/main/java/io/ebean/config/ServerConfig.java

@@ -524,6 +524,10 @@ public class ServerConfig {
    */
   private boolean idGeneratorAutomatic = true;
 
+  private boolean dumpMetricsOnShutdown;
+
+  private String dumpMetricsOptions;
+
   /**
    * Construct a Database Configuration for programmatically creating an Database.
    */
@@ -2903,6 +2907,8 @@ public class ServerConfig {
     }
     loadDocStoreSettings(p);
 
+    dumpMetricsOnShutdown = p.getBoolean("dumpMetricsOnShutdown", dumpMetricsOnShutdown);
+    dumpMetricsOptions = p.get("dumpMetricsOptions", dumpMetricsOptions);
     queryPlanTTLSeconds = p.getInt("queryPlanTTLSeconds", queryPlanTTLSeconds);
     slowQueryMillis = p.getLong("slowQueryMillis", slowQueryMillis);
     collectQueryPlans = p.getBoolean("collectQueryPlans", collectQueryPlans);
@@ -3287,6 +3293,36 @@ public class ServerConfig {
     this.collectQueryPlans = collectQueryPlans;
   }
 
+  /**
+   * Return true if metrics should be dumped when the server is shutdown.
+   */
+  public boolean isDumpMetricsOnShutdown() {
+    return dumpMetricsOnShutdown;
+  }
+
+  /**
+   * Set to true if metrics should be dumped when the server is shutdown.
+   */
+  public void setDumpMetricsOnShutdown(boolean dumpMetricsOnShutdown) {
+    this.dumpMetricsOnShutdown = dumpMetricsOnShutdown;
+  }
+
+  /**
+   * Return the options for dumping metrics.
+   */
+  public String getDumpMetricsOptions() {
+    return dumpMetricsOptions;
+  }
+
+  /**
+   * Include 'sql' or 'hash' in options such that they are included in the output.
+   *
+   * @param dumpMetricsOptions Example "sql,hash", "sql"
+   */
+  public void setDumpMetricsOptions(String dumpMetricsOptions) {
+    this.dumpMetricsOptions = dumpMetricsOptions;
+  }
+
   public enum UuidVersion {
     VERSION4,
     VERSION1,

src/main/java/io/ebean/meta/SortMetric.java

@@ -0,0 +1,80 @@
+package io.ebean.meta;
+
+import java.util.Comparator;
+
+/**
+ * Comparator for timed metrics sorted by name and then count.
+ */
+public class SortMetric {
+
+  public static final Comparator<MetaTimedMetric> NAME = new Name();
+  public static final Comparator<MetaTimedMetric> COUNT = new Count();
+  public static final Comparator<MetaTimedMetric> TOTAL = new Total();
+  public static final Comparator<MetaTimedMetric> MEAN = new Mean();
+  public static final Comparator<MetaTimedMetric> MAX = new Max();
+
+  /**
+   * Sort by name.
+   */
+  public static class Name implements Comparator<MetaTimedMetric> {
+
+    @Override
+    public int compare(MetaTimedMetric o1, MetaTimedMetric o2) {
+      String name = o1.getName();
+      String name2 = o2.getName();
+      if (name == null) {
+        return name2 == null ? 0 : -1;
+      }
+      if (name2 == null) {
+        return 1;
+      }
+
+      int i = name.compareTo(name2);
+      return i != 0 ? i : Long.compare(o1.getCount(), o2.getCount());
+    }
+  }
+
+  /**
+   * Sort by count desc.
+   */
+  public static class Count implements Comparator<MetaTimedMetric> {
+
+    @Override
+    public int compare(MetaTimedMetric o1, MetaTimedMetric o2) {
+      return Long.compare(o2.getCount(), o1.getCount());
+    }
+  }
+
+  /**
+   * Sort by total time desc.
+   */
+  public static class Total implements Comparator<MetaTimedMetric> {
+
+    @Override
+    public int compare(MetaTimedMetric o1, MetaTimedMetric o2) {
+      return Long.compare(o2.getTotal(), o1.getTotal());
+    }
+  }
+
+  /**
+   * Sort by mean desc.
+   */
+  public static class Mean implements Comparator<MetaTimedMetric> {
+
+    @Override
+    public int compare(MetaTimedMetric o1, MetaTimedMetric o2) {
+      return Long.compare(o2.getMean(), o1.getMean());
+    }
+  }
+
+  /**
+   * Sort by max desc.
+   */
+  public static class Max implements Comparator<MetaTimedMetric> {
+
+    @Override
+    public int compare(MetaTimedMetric o1, MetaTimedMetric o2) {
+      return Long.compare(o2.getMax(), o1.getMax());
+    }
+  }
+}

src/main/java/io/ebeaninternal/api/SpiQuery.java

@@ -54,67 +54,69 @@ public interface SpiQuery<T> extends Query<T>, TxnProfileEventCodes {
     /**
      * Find by Id or unique returning a single bean.
      */
-    BEAN(FIND_ONE),
+    BEAN(FIND_ONE, "byId"),
 
     /**
      * Find returning a List.
      */
-    LIST(FIND_MANY),
+    LIST(FIND_MANY, "findList"),
 
     /**
      * Find returning a Set.
      */
-    SET(FIND_MANY),
+    SET(FIND_MANY, "findSet"),
 
     /**
      * Find returning a Map.
      */
-    MAP(FIND_MANY),
+    MAP(FIND_MANY, "findMap"),
 
     /**
      * Find iterate type query - findEach(), findIterate() etc.
      */
-    ITERATE(FIND_ITERATE),
+    ITERATE(FIND_ITERATE, "findEach"),
 
     /**
      * Find the Id's.
      */
-    ID_LIST(FIND_ID_LIST),
+    ID_LIST(FIND_ID_LIST, "findIds"),
 
     /**
      * Find single attribute.
      */
-    ATTRIBUTE(FIND_ATTRIBUTE),
+    ATTRIBUTE(FIND_ATTRIBUTE, "findAttribute"),
 
     /**
      * Find rowCount.
      */
-    COUNT(FIND_COUNT),
+    COUNT(FIND_COUNT, "findCount"),
 
     /**
      * A subquery used as part of a where clause.
      */
-    SUBQUERY(FIND_SUBQUERY),
+    SUBQUERY(FIND_SUBQUERY, "subquery"),
 
     /**
      * Delete query.
      */
-    DELETE(FIND_DELETE, true),
+    DELETE(FIND_DELETE, "delete", true),
 
     /**
      * Update query.
      */
-    UPDATE(FIND_UPDATE, true);
+    UPDATE(FIND_UPDATE, "update", true);
 
-    boolean update;
-    String profileEventId;
+    private boolean update;
+    private String profileEventId;
+    private String label;
 
-    Type(String profileEventId) {
-      this(profileEventId, false);
+    Type(String profileEventId, String label) {
+      this(profileEventId, label, false);
     }
 
-    Type(String profileEventId, boolean update) {
+    Type(String profileEventId, String label, boolean update) {
       this.profileEventId = profileEventId;
+      this.label = label;
       this.update = update;
     }
 
@@ -128,6 +130,10 @@ public interface SpiQuery<T> extends Query<T>, TxnProfileEventCodes {
     public String profileEventId() {
       return profileEventId;
     }
+
+    public String label() {
+      return label;
+    }
   }
 
   enum TemporalMode {

src/main/java/io/ebeaninternal/server/core/DefaultServer.java

@@ -505,6 +505,10 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer {
 
   private void shutdownPlugins() {
 
+    if (serverConfig.isDumpMetricsOnShutdown()) {
+      new DumpMetrics(this, serverConfig.getDumpMetricsOptions()).dump();
+    }
+
     for (Plugin plugin : serverPlugins) {
       try {
         plugin.shutdown();
@@ -1234,7 +1238,6 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer {
     }
 
     SpiOrmQueryRequest<T> request = createQueryRequest(spiQuery, t);
-    request.profileLocationById();
     if (request.isUseDocStore()) {
       return docStore().find(request);
     }
@@ -1588,7 +1591,6 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer {
   private <T> List<T> findList(Query<T> query, Transaction t, boolean findOne) {
 
     SpiOrmQueryRequest<T> request = createQueryRequest(Type.LIST, query, t);
-    request.profileLocationAll();
     request.resetBeanCacheAutoMode(findOne);
     Object result = request.getFromQueryCache();
     if (result != null) {

src/main/java/io/ebeaninternal/server/core/DumpMetrics.java

@@ -0,0 +1,172 @@
+package io.ebeaninternal.server.core;
+
+import io.ebean.ProfileLocation;
+import io.ebean.meta.MetaOrmQueryMetric;
+import io.ebean.meta.MetaQueryMetric;
+import io.ebean.meta.MetaTimedMetric;
+import io.ebean.meta.ServerMetrics;
+import io.ebean.meta.SortMetric;
+import io.ebeaninternal.api.SpiEbeanServer;
+
+import java.util.Comparator;
+import java.util.List;
+
+class DumpMetrics {
+
+  private final SpiEbeanServer server;
+  private final String options;
+
+  private final String nameFormat;
+  private final String nameFormatTimed;
+
+  private boolean dumpHash;
+  private boolean dumpSql;
+  private boolean dumpLoc;
+
+  private Comparator<MetaTimedMetric> sortBy = SortMetric.NAME;
+
+  DumpMetrics(SpiEbeanServer server, String options) {
+    this.server = server;
+    this.options = options;
+
+    int width = 0;
+
+    if (options != null) {
+      dumpLoc = options.contains("loc");
+      dumpSql = options.contains("sql");
+      dumpHash = options.contains("hash");
+      for (int i = 5; i < 10; i++) {
+        width = Math.max(width, optionWidth(i * 10));
+      }
+      for (String option : new String[]{"Total", "Count", "Mean", "Max"}) {
+        sortOption(option);
+      }
+    }
+    if (width == 0) {
+      width = 80;
+    }
+
+    nameFormat = "%1$-" + width + "s";
+    nameFormatTimed = "%1$-" + (width + 6) + "s";
+  }
+
+  private int optionWidth(int check) {
+    return options.contains("w" + check) ? check : 0;
+  }
+
+  private void sortOption(String option) {
+    if (options.contains("sort" + option)) {
+      sortBy = setSortOption(option);
+    }
+  }
+
+  private Comparator<MetaTimedMetric> setSortOption(String option) {
+    switch (option.toUpperCase()) {
+      case "TOTAL":
+        return SortMetric.TOTAL;
+      case "COUNT":
+        return SortMetric.COUNT;
+      case "MEAN":
+        return SortMetric.MEAN;
+      case "MAX":
+        return SortMetric.MAX;
+    }
+    return SortMetric.NAME;
+  }
+
+  void dump() {
+
+    out("-- Dumping metrics for " + server.getName() + " -- ");
+    ServerMetrics serverMetrics = server.getMetaInfoManager().collectMetrics();
+
+    for (MetaTimedMetric metric : serverMetrics.getTimedMetrics()) {
+      log(metric);
+    }
+
+    List<MetaOrmQueryMetric> ormQueryMetrics = serverMetrics.getOrmQueryMetrics();
+    if (!ormQueryMetrics.isEmpty()) {
+      out("\n-- ORM queries --");
+      ormQueryMetrics.sort(sortBy);
+      for (MetaOrmQueryMetric metric : ormQueryMetrics) {
+        logQuery(metric);
+      }
+    }
+
+    List<MetaQueryMetric> dtoQueryMetrics = serverMetrics.getDtoQueryMetrics();
+    if (!dtoQueryMetrics.isEmpty()) {
+      out("\n-- DTO queries --");
+      dtoQueryMetrics.sort(sortBy);
+      for (MetaQueryMetric metric : dtoQueryMetrics) {
+        logDtoQuery(metric);
+      }
+    }
+  }
+
+  private void out(String sb) {
+    System.out.println(sb);
+  }
+
+  private void logQuery(MetaOrmQueryMetric metric) {
+
+    StringBuilder sb = new StringBuilder();
+
+    sb.append("query:").append(padName(metric.getName())).append(" ");
+    addCounters(metric, sb);
+
+    if (dumpHash) {
+      sb.append("\n hash:").append(metric.getQueryPlanHash());
+    }
+
+    ProfileLocation profileLocation = metric.getProfileLocation();
+    if (dumpLoc && profileLocation != null) {
+      sb.append("\n  loc:").append(profileLocation.shortDescription());
+    }
+
+    if (dumpSql) {
+      sb.append("\n\n  sql:").append(metric.getSql()).append("\n\n");
+    }
+
+    out(sb.toString());
+  }
+
+
+  private void logDtoQuery(MetaQueryMetric metric) {
+
+    StringBuilder sb = new StringBuilder();
+
+    sb.append("query:").append(padName(metric.getName())).append(" ");
+    addCounters(metric, sb);
+
+    if (dumpSql) {
+      sb.append(" \n\n  sql:").append(metric.getSql()).append("\n\n");
+    }
+    out(sb.toString());
+  }
+
+  private void log(MetaTimedMetric metric) {
+
+    StringBuilder sb = new StringBuilder();
+    sb.append(padNameTimed(metric.getName())).append(" ");
+    addCounters(metric, sb);
+    out(sb.toString());
+  }
+
+  private void addCounters(MetaTimedMetric timedMetric, StringBuilder sb) {
+    sb.append(" count:").append(pad(timedMetric.getCount()))
+      .append(" total:").append(pad(timedMetric.getTotal()))
+      .append(" mean:").append(pad(timedMetric.getMean()))
+      .append(" max:").append(pad(timedMetric.getMax()));
+  }
+
+  private String padName(String name) {
+    return String.format(nameFormat, name);
+  }
+
+  private String padNameTimed(String name) {
+    return String.format(nameFormatTimed, name);
+  }
+
+  private String pad(long value) {
+    return String.format("%1$-8s", value);
+  }
+}

src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java

@@ -102,20 +102,6 @@ public final class OrmQueryRequest<T> extends BeanRequest implements SpiOrmQuery
     return queryEngine.translate(this, bindLog, sql, e);
   }
 
-  @Override
-  public void profileLocationById() {
-    if (query.getProfileLocation() == null) {
-      query.setProfileLocation(beanDescriptor.profileLocationById());
-    }
-  }
-
-  @Override
-  public void profileLocationAll() {
-    if (query.getProfileLocation() == null && query.isFindAll()) {
-      query.setProfileLocation(beanDescriptor.profileLocationAll());
-    }
-  }
-
   @Override
   public boolean isDeleteByStatement() {
     if (!transaction.isPersistCascade() || beanDescriptor.isDeleteByStatement()) {

src/main/java/io/ebeaninternal/server/core/SpiOrmQueryRequest.java

@@ -162,16 +162,6 @@ public interface SpiOrmQueryRequest<T> extends BeanQueryRequest<T>, DocQueryRequ
    */
   boolean isUseDocStore();
 
-  /**
-   * Set profile location for "find by id" if not set.
-   */
-  void profileLocationById();
-
-  /**
-   * Set profile location for "find all" if not set.
-   */
-  void profileLocationAll();
-
   /**
    * Return true if delete by statement is allowed for this type given cascade rules etc.
    */

src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java

@@ -1,7 +1,6 @@
 package io.ebeaninternal.server.deploy;
 
 import io.ebean.PersistenceContextScope;
-import io.ebean.ProfileLocation;
 import io.ebean.Query;
 import io.ebean.SqlUpdate;
 import io.ebean.Transaction;
@@ -136,8 +135,6 @@ public class BeanDescriptor<T> implements BeanType<T>, STreeType {
   private final Map<String, String> namedQuery;
 
   private final short profileBeanId;
-  private final ProfileLocation locationById;
-  private final ProfileLocation locationAll;
 
   private final boolean multiValueSupported;
 
@@ -448,8 +445,6 @@ public class BeanDescriptor<T> implements BeanType<T>, STreeType {
     this.name = InternString.intern(deploy.getName());
     this.baseTableAlias = "t0";
     this.fullName = InternString.intern(deploy.getFullName());
-    this.locationById = ProfileLocation.createAt(fullName + ".byId");
-    this.locationAll = ProfileLocation.createAt(fullName + ".all");
     this.profileBeanId = deploy.getProfileId();
     this.beanType = deploy.getBeanType();
     this.rootBeanType = PersistenceContextUtil.root(beanType);
@@ -582,20 +577,6 @@ public class BeanDescriptor<T> implements BeanType<T>, STreeType {
     }
   }
 
-  /**
-   * Return a location for "find by id".
-   */
-  public ProfileLocation profileLocationById() {
-    return locationById;
-  }
-
-  /**
-   * Return a location for "find all".
-   */
-  public ProfileLocation profileLocationAll() {
-    return locationAll;
-  }
-
   /**
    * Return the id used in profiling to identify the bean type.
    */

src/main/java/io/ebeaninternal/server/profile/DQueryPlanMeta.java

@@ -4,18 +4,28 @@ class DQueryPlanMeta {
 
   private final Class<?> type;
   private final String label;
+  private final String name;
   private final String sql;
 
   DQueryPlanMeta(Class<?> type, String label, String sql) {
     this.type = type;
     this.label = label;
     this.sql = sql;
+    String name = type.getSimpleName();
+    if (label != null) {
+      name += "_" + label;
+    }
+    this.name = name;
   }
 
   public Class<?> getType() {
     return type;
   }
 
+  public String getName() {
+    return name;
+  }
+
   public String getLabel() {
     return label;
   }

src/main/java/io/ebeaninternal/server/profile/DQueryPlanMetric.java

@@ -67,7 +67,7 @@ class DQueryPlanMetric implements QueryPlanMetric {
 
     @Override
     public String getName() {
-      return stats.getName();
+      return meta.getName();
     }
 
     @Override

src/main/java/io/ebeaninternal/server/query/CQueryPlan.java

@@ -65,6 +65,8 @@ public class CQueryPlan {
 
   private final String label;
 
+  private final String name;
+
   private final CQueryPlanKey planKey;
 
   private final boolean rawSql;
@@ -112,6 +114,7 @@ public class CQueryPlan {
     SpiQuery<?> query = request.getQuery();
     this.profileLocation = query.getProfileLocation();
     this.label = query.getPlanLabel();
+    this.name = deriveName(label, query.getType());
     this.location = location();
     this.autoTuned = query.isAutoTuned();
     this.asOfTableCount = query.getAsOfTableCount();
@@ -138,6 +141,7 @@ public class CQueryPlan {
     SpiQuery<?> query = request.getQuery();
     this.profileLocation = query.getProfileLocation();
     this.label = query.getPlanLabel();
+    this.name = deriveName(label, query.getType());
     this.location = location();
     this.planKey = buildPlanKey(sql, rawSql, rowNumberIncluded, logWhereSql);
     this.autoTuned = false;
@@ -154,6 +158,16 @@ public class CQueryPlan {
     this.bindCapture = initBindCapture(server.getServerConfig(), query);
   }
 
+  private String deriveName(String label, SpiQuery.Type type) {
+    if (label == null) {
+      return beanType.getSimpleName() + "." + type.label();
+    }
+    if (label.startsWith(beanType.getSimpleName())) {
+      return label;
+    }
+    return beanType.getSimpleName() + "_" + label;
+  }
+
   private CQueryBindCapture initBindCapture(ServerConfig serverConfig, SpiQuery<?> query) {
     if (serverConfig.isCollectQueryPlans() && !query.getType().isUpdate()) {
       return new CQueryBindCapture(this, PlatformQueryPlan.getLogger(serverConfig.getDatabasePlatform().getPlatform()));
@@ -192,6 +206,10 @@ public class CQueryPlan {
     return label;
   }
 
+  public String getName() {
+    return name;
+  }
+
   public String getLocation() {
     return location;
   }

src/main/java/io/ebeaninternal/server/query/CQueryPlanStats.java

@@ -184,7 +184,7 @@ public final class CQueryPlanStats {
 
     @Override
     public String getName() {
-      return queryPlan.getLabel();
+      return queryPlan.getName();
     }
 
     @Override

src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java

@@ -26,7 +26,7 @@ public abstract class QueryPlanLogger {
   }
 
   protected DQueryPlanOutput createPlan(CQueryPlan plan, String bind, String planString) {
-    return new DQueryPlanOutput(plan.getBeanType(), plan.getLabel(), plan.getSql(), bind, planString);
+    return new DQueryPlanOutput(plan.getBeanType(), plan.getName(), plan.getSql(), bind, planString);
   }
 
   DQueryPlanOutput readQueryPlanBasic(CQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException {