From 6fcac27dfeaef4c7cdf5e3c951f7529ab3d2cecc Mon Sep 17 00:00:00 2001 From: rob bygrave Date: Mon, 23 Dec 2019 10:28:08 +1300 Subject: [PATCH 1/2] Refactor for query plan capture with initial threshold micros --- .../java/io/ebean/config/ServerConfig.java | 20 +++++++ .../io/ebeaninternal/api/ExtraMetrics.java | 46 +++++++++++++++ .../api/NoopQueryBindCapture.java | 22 +++++++ .../api/NoopQueryPlanManager.java | 9 +++ .../ebeaninternal/api/QueryPlanManager.java | 14 +++++ .../io/ebeaninternal/api/SpiEbeanServer.java | 6 +- .../api/SpiQueryBindCapture.java | 31 ++++++++++ .../io/ebeaninternal/api/SpiQueryPlan.java | 34 +++++++++++ .../server/core/DefaultServer.java | 19 +++++- .../server/core/InternalConfiguration.java | 46 +++++++++++++-- .../server/deploy/BeanDescriptor.java | 7 +-- .../server/deploy/BeanDescriptorManager.java | 7 +-- .../server/query/CQueryBindCapture.java | 34 ++++++----- .../server/query/CQueryPlan.java | 58 +++++++++---------- .../server/query/CQueryPlanManager.java | 22 +++++++ .../server/query/PlatformQueryPlan.java | 36 ------------ .../server/query/QueryPlanLogger.java | 41 +++++++++++-- .../server/query/QueryPlanLoggerExplain.java | 12 +++- .../server/query/QueryPlanLoggerOracle.java | 8 ++- .../server/query/QueryPlanLoggerPostgres.java | 8 ++- .../query/QueryPlanLoggerSqlServer.java | 8 ++- .../io/ebean/config/ServerConfigTest.java | 4 +- .../ebeaninternal/api/TDSpiEbeanServer.java | 5 ++ .../query/finder/TestCustomerFinder.java | 3 +- src/test/resources/ebean.properties | 2 +- 25 files changed, 388 insertions(+), 114 deletions(-) create mode 100644 src/main/java/io/ebeaninternal/api/ExtraMetrics.java create mode 100644 src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java create mode 100644 src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java create mode 100644 src/main/java/io/ebeaninternal/api/QueryPlanManager.java create mode 100644 src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java create mode 100644 src/main/java/io/ebeaninternal/api/SpiQueryPlan.java create mode 100644 src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java delete mode 100644 src/main/java/io/ebeaninternal/server/query/PlatformQueryPlan.java diff --git a/src/main/java/io/ebean/config/ServerConfig.java b/src/main/java/io/ebean/config/ServerConfig.java index 53127965d..3e346570a 100644 --- a/src/main/java/io/ebean/config/ServerConfig.java +++ b/src/main/java/io/ebean/config/ServerConfig.java @@ -497,6 +497,11 @@ public class ServerConfig { */ private boolean collectQueryPlans; + /** + * The default threshold in micros for collecting query plans. + */ + private long collectQueryPlanThresholdMicros = Long.MAX_VALUE; + /** * The time in millis used to determine when a query is alerted for being slow. */ @@ -2857,6 +2862,7 @@ public class ServerConfig { queryPlanTTLSeconds = p.getInt("queryPlanTTLSeconds", queryPlanTTLSeconds); slowQueryMillis = p.getLong("slowQueryMillis", slowQueryMillis); collectQueryPlans = p.getBoolean("collectQueryPlans", collectQueryPlans); + collectQueryPlanThresholdMicros = p.getLong("collectQueryPlanThresholdMicros", collectQueryPlanThresholdMicros); docStoreOnly = p.getBoolean("docStoreOnly", docStoreOnly); disableL2Cache = p.getBoolean("disableL2Cache", disableL2Cache); enabledL2Regions = p.get("enabledL2Regions", enabledL2Regions); @@ -3242,6 +3248,20 @@ public class ServerConfig { this.collectQueryPlans = collectQueryPlans; } + /** + * Return the query plan collection threshold in microseconds. + */ + public long getCollectQueryPlanThresholdMicros() { + return collectQueryPlanThresholdMicros; + } + + /** + * Set the query plan collection threshold in microseconds. + */ + public void setCollectQueryPlanThresholdMicros(long collectQueryPlanThresholdMicros) { + this.collectQueryPlanThresholdMicros = collectQueryPlanThresholdMicros; + } + /** * Return true if metrics should be dumped when the server is shutdown. */ diff --git a/src/main/java/io/ebeaninternal/api/ExtraMetrics.java b/src/main/java/io/ebeaninternal/api/ExtraMetrics.java new file mode 100644 index 000000000..dac31b2a9 --- /dev/null +++ b/src/main/java/io/ebeaninternal/api/ExtraMetrics.java @@ -0,0 +1,46 @@ +package io.ebeaninternal.api; + +import io.ebean.meta.MetricType; +import io.ebean.meta.MetricVisitor; +import io.ebean.metric.MetricFactory; +import io.ebean.metric.TimedMetric; + +/** + * Extra metrics collected to measure internal behaviour. + */ +public class ExtraMetrics { + + private final TimedMetric bindCapture; + private final TimedMetric planCollect; + + /** + * Create the extra metrics. + */ + public ExtraMetrics() { + final MetricFactory factory = MetricFactory.get(); + this.bindCapture = factory.createTimedMetric(MetricType.ORM, "ebean.queryplan.bindcapture"); + this.planCollect = factory.createTimedMetric(MetricType.ORM, "ebean.queryplan.collect"); + } + + /** + * Timed metric for bind capture used with query plan collection. + */ + public TimedMetric getBindCapture() { + return bindCapture; + } + + /** + * Timed metric for query plan collection. + */ + public TimedMetric getPlanCollect() { + return planCollect; + } + + /** + * Collect the metrics. + */ + public void visitMetrics(MetricVisitor visitor) { + bindCapture.visit(visitor); + planCollect.visit(visitor); + } +} diff --git a/src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java b/src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java new file mode 100644 index 000000000..e4c747497 --- /dev/null +++ b/src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java @@ -0,0 +1,22 @@ +package io.ebeaninternal.api; + +import io.ebean.meta.QueryPlanRequest; +import io.ebeaninternal.server.type.bindcapture.BindCapture; + +class NoopQueryBindCapture implements SpiQueryBindCapture { + + @Override + public boolean collectFor(long timeMicros) { + return false; + } + + @Override + public void setBind(BindCapture bindCapture, long timeMicros, long startNanos) { + // do nothing + } + + @Override + public void collectQueryPlan(QueryPlanRequest request) { + // do nothing + } +} diff --git a/src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java b/src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java new file mode 100644 index 000000000..7b97d821f --- /dev/null +++ b/src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java @@ -0,0 +1,9 @@ +package io.ebeaninternal.api; + +class NoopQueryPlanManager implements QueryPlanManager { + + @Override + public SpiQueryBindCapture createBindCapture(SpiQueryPlan queryPlan) { + return SpiQueryBindCapture.NOOP; + } +} diff --git a/src/main/java/io/ebeaninternal/api/QueryPlanManager.java b/src/main/java/io/ebeaninternal/api/QueryPlanManager.java new file mode 100644 index 000000000..fea4d1976 --- /dev/null +++ b/src/main/java/io/ebeaninternal/api/QueryPlanManager.java @@ -0,0 +1,14 @@ +package io.ebeaninternal.api; + +/** + * Manage query plan capture. + */ +public interface QueryPlanManager { + + QueryPlanManager NOOP = new NoopQueryPlanManager(); + + /** + * Create the bind capture for the given query plan. + */ + SpiQueryBindCapture createBindCapture(SpiQueryPlan queryPlan); +} diff --git a/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java b/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java index 0afa7726e..36b1f3901 100644 --- a/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java +++ b/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java @@ -12,7 +12,6 @@ import io.ebean.TxScope; import io.ebean.bean.BeanCollectionLoader; import io.ebean.bean.BeanLoader; import io.ebean.bean.CallOrigin; -import io.ebean.bean.ObjectGraphNode; import io.ebean.config.ServerConfig; import io.ebean.config.dbplatform.DatabasePlatform; import io.ebean.event.readaudit.ReadAuditLogger; @@ -311,4 +310,9 @@ public interface SpiEbeanServer extends ExtendedServer, EbeanServer, BeanLoader, * Execute the sql update regardless of transaction batch mode. */ int executeNow(SpiSqlUpdate sqlUpdate); + + /** + * Create a query bind capture for the given query plan. + */ + SpiQueryBindCapture createQueryBindCapture(SpiQueryPlan queryPlan); } diff --git a/src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java b/src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java new file mode 100644 index 000000000..9088f54ad --- /dev/null +++ b/src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java @@ -0,0 +1,31 @@ +package io.ebeaninternal.api; + +import io.ebean.meta.QueryPlanRequest; +import io.ebeaninternal.server.type.bindcapture.BindCapture; + +/** + * Capture query bind values and with those actual database query plans. + */ +public interface SpiQueryBindCapture { + + /** + * NOOP implementation. + */ + SpiQueryBindCapture NOOP = new NoopQueryBindCapture(); + + /** + * Return true if the query just executed should be bind captured to collect + * the query plan from (as the query time is large / interesting). + */ + boolean collectFor(long timeMicros); + + /** + * Set the bind capture and the related query execution time. + */ + void setBind(BindCapture bindCapture, long timeMicros, long startNanos); + + /** + * Collect the query execution plan usually executing the query to do so. + */ + void collectQueryPlan(QueryPlanRequest request); +} diff --git a/src/main/java/io/ebeaninternal/api/SpiQueryPlan.java b/src/main/java/io/ebeaninternal/api/SpiQueryPlan.java new file mode 100644 index 000000000..e06243df8 --- /dev/null +++ b/src/main/java/io/ebeaninternal/api/SpiQueryPlan.java @@ -0,0 +1,34 @@ +package io.ebeaninternal.api; + +import io.ebean.ProfileLocation; + +/** + * The internal ORM "query plan". + */ +public interface SpiQueryPlan { + + /** + * The related entity bean type + */ + Class getBeanType(); + + /** + * The plan name. + */ + String getName(); + + /** + * The hash for the query plan. + */ + String getHash(); + + /** + * The SQL for the query plan. + */ + String getSql(); + + /** + * The related profile location. + */ + ProfileLocation getProfileLocation(); +} diff --git a/src/main/java/io/ebeaninternal/server/core/DefaultServer.java b/src/main/java/io/ebeaninternal/server/core/DefaultServer.java index c504d4061..aa59462c1 100644 --- a/src/main/java/io/ebeaninternal/server/core/DefaultServer.java +++ b/src/main/java/io/ebeaninternal/server/core/DefaultServer.java @@ -38,7 +38,6 @@ import io.ebean.bean.BeanCollection; import io.ebean.bean.CallOrigin; import io.ebean.bean.EntityBean; import io.ebean.bean.EntityBeanIntercept; -import io.ebean.bean.ObjectGraphNode; import io.ebean.bean.PersistenceContext; import io.ebean.bean.PersistenceContext.WithOption; import io.ebean.cache.ServerCacheManager; @@ -64,8 +63,10 @@ import io.ebean.plugin.SpiServer; import io.ebean.text.csv.CsvReader; import io.ebean.text.json.JsonContext; import io.ebean.util.JdbcClose; +import io.ebeaninternal.api.ExtraMetrics; import io.ebeaninternal.api.LoadBeanRequest; import io.ebeaninternal.api.LoadManyRequest; +import io.ebeaninternal.api.QueryPlanManager; import io.ebeaninternal.api.ScopedTransaction; import io.ebeaninternal.api.SpiBackgroundExecutor; import io.ebeaninternal.api.SpiDtoQuery; @@ -74,6 +75,8 @@ import io.ebeaninternal.api.SpiJsonContext; import io.ebeaninternal.api.SpiLogManager; import io.ebeaninternal.api.SpiQuery; import io.ebeaninternal.api.SpiQuery.Type; +import io.ebeaninternal.api.SpiQueryBindCapture; +import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.api.SpiSqlQuery; import io.ebeaninternal.api.SpiSqlUpdate; import io.ebeaninternal.api.SpiTransaction; @@ -138,7 +141,6 @@ import java.util.Optional; import java.util.Set; import java.util.Spliterator; import java.util.concurrent.Callable; -import java.util.concurrent.ConcurrentHashMap; import java.util.function.Consumer; import java.util.function.Function; import java.util.function.Predicate; @@ -162,6 +164,10 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { private final TransactionManager transactionManager; + private final QueryPlanManager queryPlanManager; + + private final ExtraMetrics extraMetrics; + private final DataTimeZone dataTimeZone; /** @@ -256,6 +262,8 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { this.serverCacheManager = cache; this.databasePlatform = config.getDatabasePlatform(); this.backgroundExecutor = config.getBackgroundExecutor(); + this.queryPlanManager = config.getQueryPlanManager(); + this.extraMetrics = config.getExtraMetrics(); this.serverName = serverConfig.getName(); this.lazyLoadBatchSize = serverConfig.getLazyLoadBatchSize(); @@ -2385,7 +2393,6 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { return Collections.emptySet(); } - /** * Returns a set of properties if saving the bean will violate the unique constraints (defined by given properties). */ @@ -2430,6 +2437,7 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { relationalQueryEngine.visitMetrics(visitor); persister.visitMetrics(visitor); } + extraMetrics.visitMetrics(visitor); visitor.visitEnd(); } @@ -2447,4 +2455,9 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { } return request.getPlans(); } + + @Override + public SpiQueryBindCapture createQueryBindCapture(SpiQueryPlan plan) { + return queryPlanManager.createBindCapture(plan); + } } diff --git a/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java b/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java index f7623916b..5ebcf4d74 100644 --- a/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java +++ b/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java @@ -23,6 +23,8 @@ import io.ebean.event.readaudit.ReadAuditLogger; import io.ebean.event.readaudit.ReadAuditPrepare; import io.ebean.plugin.Plugin; import io.ebean.plugin.SpiServer; +import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.QueryPlanManager; import io.ebeaninternal.api.SpiBackgroundExecutor; import io.ebeaninternal.api.SpiEbeanServer; import io.ebeaninternal.api.SpiJsonContext; @@ -64,9 +66,15 @@ import io.ebeaninternal.server.persist.DefaultPersister; import io.ebeaninternal.server.persist.platform.MultiValueBind; import io.ebeaninternal.server.persist.platform.PostgresMultiValueBind; import io.ebeaninternal.server.query.CQueryEngine; +import io.ebeaninternal.server.query.CQueryPlanManager; import io.ebeaninternal.server.query.DefaultOrmQueryEngine; import io.ebeaninternal.server.query.DefaultRelationalQueryEngine; import io.ebeaninternal.server.query.DtoQueryEngine; +import io.ebeaninternal.server.query.QueryPlanLogger; +import io.ebeaninternal.server.query.QueryPlanLoggerExplain; +import io.ebeaninternal.server.query.QueryPlanLoggerOracle; +import io.ebeaninternal.server.query.QueryPlanLoggerPostgres; +import io.ebeaninternal.server.query.QueryPlanLoggerSqlServer; import io.ebeaninternal.server.readaudit.DefaultReadAuditLogger; import io.ebeaninternal.server.readaudit.DefaultReadAuditPrepare; import io.ebeaninternal.server.text.json.DJsonContext; @@ -164,8 +172,10 @@ public class InternalConfiguration { private final SpiLogManager logManager; + private final ExtraMetrics extraMetrics = new ExtraMetrics(); + InternalConfiguration(boolean online, ClusterManager clusterManager, SpiBackgroundExecutor backgroundExecutor, - ServerConfig serverConfig, BootupClasses bootupClasses) { + ServerConfig serverConfig, BootupClasses bootupClasses) { this.online = online; this.serverConfig = serverConfig; @@ -242,6 +252,10 @@ public class InternalConfiguration { return clockService; } + public ExtraMetrics getExtraMetrics() { + return extraMetrics; + } + /** * Check if this is a SpiServerPlugin and if so 'collect' it to give the complete list * later on the DefaultServer for late call to configure(). @@ -433,8 +447,8 @@ public class InternalConfiguration { TransactionManagerOptions options = new TransactionManagerOptions(notifyL2CacheInForeground, serverConfig, scopeManager, clusterManager, backgroundExecutor, - indexUpdateProcessor, beanDescriptorManager, dataSource(), profileHandler(), logManager, - tableModState, cacheNotify, clockService); + indexUpdateProcessor, beanDescriptorManager, dataSource(), profileHandler(), logManager, + tableModState, cacheNotify, clockService); if (serverConfig.isExplicitTransactionBeginMode()) { return new ExplicitTransactionManager(options); @@ -527,7 +541,7 @@ public class InternalConfiguration { } private boolean isMySql(Platform platform) { - return platform.base() == Platform.MYSQL; + return platform.base() == Platform.MYSQL; } public DataTimeZone getDataTimeZone() { @@ -636,4 +650,28 @@ public class InternalConfiguration { return new DefaultServerCacheManager(builder); } + + public QueryPlanManager getQueryPlanManager() { + if (!serverConfig.isCollectQueryPlans()) { + return QueryPlanManager.NOOP; + } + long threshold = serverConfig.getCollectQueryPlanThresholdMicros(); + return new CQueryPlanManager(threshold, queryPlanLogger(databasePlatform.getPlatform())); + } + + /** + * Returns the logger to log query plans for the given platform. + */ + QueryPlanLogger queryPlanLogger(Platform platform) { + switch (platform.base()) { + case POSTGRES: + return new QueryPlanLoggerPostgres(extraMetrics); + case SQLSERVER: + return new QueryPlanLoggerSqlServer(extraMetrics); + case ORACLE: + return new QueryPlanLoggerOracle(extraMetrics); + default: + return new QueryPlanLoggerExplain(extraMetrics); + } + } } diff --git a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java index 32b8294e6..af8647a3d 100644 --- a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java +++ b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java @@ -1714,19 +1714,14 @@ public class BeanDescriptor implements BeanType, STreeType { /** * Trim query plans not used since the passed in epoch time. */ - List trimQueryPlans(long unusedSince) { - - List list = new ArrayList<>(); - + void trimQueryPlans(long unusedSince) { Iterator it = queryPlanCache.values().iterator(); while (it.hasNext()) { CQueryPlan queryPlan = it.next(); if (queryPlan.getLastQueryTime() < unusedSince) { it.remove(); - list.add(queryPlan); } } - return list; } /** diff --git a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java index 9ec66ea38..4370dd651 100644 --- a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java +++ b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java @@ -244,17 +244,14 @@ public class BeanDescriptorManager implements BeanDescriptorMap { * Run periodic trim of query plans. */ public void scheduleBackgroundTrim() { - backgroundExecutor.executePeriodically(this::trimQueryPlans, 30L, TimeUnit.SECONDS); + backgroundExecutor.executePeriodically(this::trimQueryPlans, 60L, TimeUnit.SECONDS); } private void trimQueryPlans() { long lastUsed = System.currentTimeMillis() - (queryPlanTTLSeconds * 1000L); for (BeanDescriptor descriptor : immutableDescriptorList) { if (!descriptor.isEmbedded()) { - List trimmedPlans = descriptor.trimQueryPlans(lastUsed); - if (!trimmedPlans.isEmpty()) { - logger.trace("trimmed {} query plans for type:{}", trimmedPlans.size(), descriptor.getName()); - } + descriptor.trimQueryPlans(lastUsed); } } } diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java b/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java index 4ba444012..a2d934b29 100644 --- a/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java +++ b/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java @@ -1,13 +1,15 @@ package io.ebeaninternal.server.query; import io.ebean.meta.QueryPlanRequest; +import io.ebeaninternal.api.SpiQueryBindCapture; +import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; -class CQueryBindCapture { +class CQueryBindCapture implements SpiQueryBindCapture { private static final double multiplier = 1.3d; - private final CQueryPlan cQueryPlan; + private final SpiQueryPlan queryPlan; private final QueryPlanLogger planLogger; private BindCapture bindCapture; @@ -17,16 +19,18 @@ class CQueryBindCapture { private long lastBindCapture; - CQueryBindCapture(CQueryPlan cQueryPlan, QueryPlanLogger planLogger) { - this.cQueryPlan = cQueryPlan; + CQueryBindCapture(SpiQueryPlan queryPlan, QueryPlanLogger planLogger, long thresholdMicros) { + this.queryPlan = queryPlan; this.planLogger = planLogger; + this.thresholdMicros = thresholdMicros; } /** * Return true if we should capture the bind values for this query. */ - boolean collectFor(long timeMicros) { - return (bindCapture == null || timeMicros > thresholdMicros); + @Override + public boolean collectFor(long timeMicros) { + return timeMicros > thresholdMicros && captureCount < 10; } /** @@ -34,23 +38,25 @@ class CQueryBindCapture { * * @param bindCapture The bind values of the query * @param queryTimeMicros The query execution time + * @param startNanos The nanos start of this bind capture */ - void setBind(BindCapture bindCapture, long queryTimeMicros) { + @Override + public void setBind(BindCapture bindCapture, long queryTimeMicros, long startNanos) { synchronized (this) { + this.thresholdMicros = Math.round(queryTimeMicros * multiplier); + this.captureCount++; this.bindCapture = bindCapture; this.queryTimeMicros = queryTimeMicros; - this.thresholdMicros = Math.round(queryTimeMicros * multiplier); - captureCount++; lastBindCapture = System.currentTimeMillis(); + planLogger.addBindTimeSince(startNanos); } } - /** * Collect the query plan using already captured bind values. */ - void collectQueryPlan(QueryPlanRequest request) { - + @Override + public void collectQueryPlan(QueryPlanRequest request) { if (bindCapture == null || request.getSince() > lastBindCapture) { // no bind capture since the last capture return; @@ -58,9 +64,9 @@ class CQueryBindCapture { final BindCapture last = this.bindCapture; - DQueryPlanOutput queryPlan = planLogger.logQueryPlan(request.getConnection(), cQueryPlan, last); + DQueryPlanOutput queryPlan = planLogger.collectQueryPlan(request.getConnection(), this.queryPlan, last); if (queryPlan != null) { - queryPlan.with(queryTimeMicros, captureCount, cQueryPlan.getHash()); + queryPlan.with(queryTimeMicros, captureCount, this.queryPlan.getHash()); request.process(queryPlan); } } diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java b/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java index e8b706ada..6eceac806 100644 --- a/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java +++ b/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java @@ -1,7 +1,6 @@ package io.ebeaninternal.server.query; import io.ebean.ProfileLocation; -import io.ebean.config.ServerConfig; import io.ebean.config.dbplatform.SqlLimitResponse; import io.ebean.meta.MetricType; import io.ebean.meta.QueryPlanRequest; @@ -10,6 +9,8 @@ import io.ebean.metric.TimedMetric; import io.ebeaninternal.api.CQueryPlanKey; import io.ebeaninternal.api.SpiEbeanServer; import io.ebeaninternal.api.SpiQuery; +import io.ebeaninternal.api.SpiQueryBindCapture; +import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.core.OrmQueryRequest; import io.ebeaninternal.server.core.timezone.DataTimeZone; import io.ebeaninternal.server.query.CQueryPlanStats.Snapshot; @@ -47,7 +48,7 @@ import java.util.Set; * for performance tuning. *

*/ -public class CQueryPlan { +public class CQueryPlan implements SpiQueryPlan { private static final Logger logger = LoggerFactory.getLogger(CQueryPlan.class); @@ -98,13 +99,12 @@ public class CQueryPlan { private final Set dependentTables; - private final CQueryBindCapture bindCapture; + private final SpiQueryBindCapture bindCapture; /** * Create a query plan based on a OrmQueryRequest. */ CQueryPlan(OrmQueryRequest request, SqlLimitResponse sqlRes, SqlTree sqlTree, boolean rawSql, String logWhereSql) { - this.server = request.getServer(); this.dataTimeZone = server.getDataTimeZone(); this.beanType = request.getBeanDescriptor().getBeanType(); @@ -124,7 +124,7 @@ public class CQueryPlan { this.encryptedProps = sqlTree.getEncryptedProps(); this.stats = new CQueryPlanStats(this); this.dependentTables = sqlTree.dependentTables(); - this.bindCapture = initBindCapture(server.getServerConfig(), query); + this.bindCapture = initBindCapture(query); this.hash = md5Hash(); } @@ -132,7 +132,6 @@ public class CQueryPlan { * Create a query plan for a raw sql query. */ CQueryPlan(OrmQueryRequest request, String sql, SqlTree sqlTree, boolean rowNumberIncluded, String logWhereSql) { - this.server = request.getServer(); this.dataTimeZone = server.getDataTimeZone(); this.beanType = request.getBeanDescriptor().getBeanType(); @@ -152,7 +151,7 @@ public class CQueryPlan { this.encryptedProps = sqlTree.getEncryptedProps(); this.stats = new CQueryPlanStats(this); this.dependentTables = sqlTree.dependentTables(); - this.bindCapture = initBindCapture(server.getServerConfig(), query); + this.bindCapture = initBindCapture(query); this.hash = md5Hash(); } @@ -166,12 +165,8 @@ public class CQueryPlan { return "orm." + 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())); - } else { - return null; - } + private SpiQueryBindCapture initBindCapture(SpiQuery query) { + return query.getType().isUpdate() ? SpiQueryBindCapture.NOOP : server.createQueryBindCapture(this); } private String location() { @@ -187,14 +182,27 @@ public class CQueryPlan { return beanType + " hash:" + planKey; } + @Override public Class getBeanType() { return beanType; } - public Set getDependentTables() { - return dependentTables; + @Override + public String getName() { + return name; } + @Override + public String getHash() { + return hash; + } + + @Override + public String getSql() { + return sql; + } + + @Override public ProfileLocation getProfileLocation() { return profileLocation; } @@ -203,8 +211,8 @@ public class CQueryPlan { return label; } - public String getName() { - return name; + public Set getDependentTables() { + return dependentTables; } public String getLocation() { @@ -242,10 +250,6 @@ public class CQueryPlan { return asOfTableCount; } - boolean isAutoTuned() { - return autoTuned; - } - /** * Return a key used in audit logging to identify the query. */ @@ -277,14 +281,6 @@ public class CQueryPlan { } } - String getHash() { - return hash; - } - - public String getSql() { - return sql; - } - SqlTree getSqlTree() { return sqlTree; } @@ -347,10 +343,10 @@ public class CQueryPlan { void captureBindForQueryPlan(CQueryPredicates predicates, long executionTimeMicros) { try { + long startNanos = System.nanoTime(); DataBindCapture capture = bindCapture(); predicates.bind(capture); - bindCapture.setBind(capture.bindCapture(), executionTimeMicros); - + bindCapture.setBind(capture.bindCapture(), executionTimeMicros, startNanos); } catch (SQLException e) { logger.error("Error capturing bind values", e); } diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java b/src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java new file mode 100644 index 000000000..9ef20ed78 --- /dev/null +++ b/src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java @@ -0,0 +1,22 @@ +package io.ebeaninternal.server.query; + +import io.ebeaninternal.api.QueryPlanManager; +import io.ebeaninternal.api.SpiQueryBindCapture; +import io.ebeaninternal.api.SpiQueryPlan; + +public class CQueryPlanManager implements QueryPlanManager { + + private final long threshold; + + private final QueryPlanLogger planLogger; + + public CQueryPlanManager(long threshold, QueryPlanLogger planLogger) { + this.threshold = threshold; + this.planLogger = planLogger; + } + + @Override + public SpiQueryBindCapture createBindCapture(SpiQueryPlan queryPlan) { + return new CQueryBindCapture(queryPlan, planLogger, threshold); + } +} diff --git a/src/main/java/io/ebeaninternal/server/query/PlatformQueryPlan.java b/src/main/java/io/ebeaninternal/server/query/PlatformQueryPlan.java deleted file mode 100644 index a0c8927f1..000000000 --- a/src/main/java/io/ebeaninternal/server/query/PlatformQueryPlan.java +++ /dev/null @@ -1,36 +0,0 @@ -package io.ebeaninternal.server.query; - -import io.ebean.annotation.Platform; - -final class PlatformQueryPlan { - - private static final QueryPlanLogger explainLogger = new QueryPlanLoggerExplain(); - - private static final QueryPlanLogger postgresLogger = new QueryPlanLoggerPostgres(); - - private static final QueryPlanLogger sqlServerLogger = new QueryPlanLoggerSqlServer(); - - private static final QueryPlanLogger oracleLogger = new QueryPlanLoggerOracle(); - - /** - * Returns the logger to log query plans for the given platform. - */ - public static QueryPlanLogger getLogger(Platform platform) { - - switch (platform) { - case POSTGRES: - return postgresLogger; - - case SQLSERVER: - case SQLSERVER16: - case SQLSERVER17: - return sqlServerLogger; - - case ORACLE: - return oracleLogger; - - default: - return explainLogger; - } - } -} diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java index 52ebb6f35..3a039346a 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java @@ -1,5 +1,8 @@ package io.ebeaninternal.server.query; +import io.ebean.metric.TimedMetric; +import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -12,9 +15,37 @@ public abstract class QueryPlanLogger { static final Logger queryPlanLog = LoggerFactory.getLogger(QueryPlanLogger.class); - public abstract DQueryPlanOutput logQueryPlan(Connection conn, CQueryPlan plan, BindCapture bind); + private final TimedMetric timeCollection; - DQueryPlanOutput readQueryPlan(CQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { + private final TimedMetric timeBindCapture; + + protected QueryPlanLogger(ExtraMetrics extraMetrics) { + this.timeCollection = extraMetrics.getPlanCollect(); + this.timeBindCapture = extraMetrics.getBindCapture(); + } + + abstract DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind); + + /** + * Add timing for bind capture. + */ + public void addBindTimeSince(long startNanos) { + timeBindCapture.addSinceNanos(startNanos); + } + + /** + * Collect the DB query plan. + */ + public DQueryPlanOutput collectQueryPlan(Connection conn, SpiQueryPlan plan, BindCapture bind) { + long startNanos = System.nanoTime(); + try { + return collect(conn, plan, bind); + } finally { + timeCollection.addSinceNanos(startNanos); + } + } + + DQueryPlanOutput readQueryPlan(SpiQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { StringBuilder sb = new StringBuilder(); for (int i = 1; i <= rset.getMetaData().getColumnCount(); i++) { sb.append(rset.getMetaData().getColumnLabel(i)).append("\t"); @@ -25,11 +56,11 @@ public abstract class QueryPlanLogger { return createPlan(plan, bind.toString(), sb.toString()); } - DQueryPlanOutput createPlan(CQueryPlan plan, String bind, String planString) { + DQueryPlanOutput createPlan(SpiQueryPlan plan, String bind, String planString) { return new DQueryPlanOutput(plan.getBeanType(), plan.getName(), plan.getSql(), bind, planString, plan.getProfileLocation()); } - DQueryPlanOutput readQueryPlanBasic(CQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { + DQueryPlanOutput readQueryPlanBasic(SpiQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { StringBuilder sb = new StringBuilder(); readPlanData(sb, rset); return createPlan(plan, bind.toString(), sb.toString().trim()); @@ -41,7 +72,7 @@ public abstract class QueryPlanLogger { for (int i = 1; i <= rset.getMetaData().getColumnCount(); i++) { sb.append(rset.getString(i)).append("\t"); } - sb.setLength(sb.length()-1); + sb.setLength(sb.length() - 1); } } } diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java index ee7f19f28..786c874c0 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java @@ -1,19 +1,25 @@ package io.ebeaninternal.server.query; +import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiQueryPlan; +import io.ebeaninternal.server.type.bindcapture.BindCapture; + import java.sql.Connection; import java.sql.PreparedStatement; import java.sql.ResultSet; import java.sql.SQLException; -import io.ebeaninternal.server.type.bindcapture.BindCapture; - /** * A QueryPlanLogger that prefixes "EXPLAIN " to the query. This works for Postgres, H2 and MySql. */ public class QueryPlanLoggerExplain extends QueryPlanLogger { + public QueryPlanLoggerExplain(ExtraMetrics extraMetrics) { + super(extraMetrics); + } + @Override - public DQueryPlanOutput logQueryPlan(Connection conn, CQueryPlan plan, BindCapture bind) { + public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { try (PreparedStatement explainStmt = conn.prepareStatement("EXPLAIN " + plan.getSql())) { bind.prepare(explainStmt, conn); diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java index 48e8a860f..f4ff22025 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java @@ -1,6 +1,8 @@ package io.ebeaninternal.server.query; +import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; import java.sql.Connection; @@ -16,8 +18,12 @@ import java.sql.Statement; */ public class QueryPlanLoggerOracle extends QueryPlanLogger { + public QueryPlanLoggerOracle(ExtraMetrics extraMetrics) { + super(extraMetrics); + } + @Override - public DQueryPlanOutput logQueryPlan(Connection conn, CQueryPlan plan, BindCapture bind) { + public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { try (Statement stmt = conn.createStatement()) { try (PreparedStatement explainStmt = conn.prepareStatement("EXPLAIN PLAN FOR " + plan.getSql())) { diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java index 5b5cbf887..b36ed011c 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java @@ -1,5 +1,7 @@ package io.ebeaninternal.server.query; +import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; import java.sql.Connection; @@ -12,8 +14,12 @@ import java.sql.SQLException; */ public class QueryPlanLoggerPostgres extends QueryPlanLogger { + public QueryPlanLoggerPostgres(ExtraMetrics extraMetrics) { + super(extraMetrics); + } + @Override - public DQueryPlanOutput logQueryPlan(Connection conn, CQueryPlan plan, BindCapture bind) { + public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { String explain = "explain analyze " + plan.getSql(); try (PreparedStatement explainStmt = conn.prepareStatement(explain)) { diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java index e3e402f97..90afa320b 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java @@ -1,5 +1,7 @@ package io.ebeaninternal.server.query; +import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; import java.sql.Connection; @@ -16,8 +18,12 @@ import java.sql.Statement; */ public class QueryPlanLoggerSqlServer extends QueryPlanLogger { + public QueryPlanLoggerSqlServer(ExtraMetrics extraMetrics) { + super(extraMetrics); + } + @Override - public DQueryPlanOutput logQueryPlan(Connection conn, CQueryPlan plan, BindCapture bind) { + public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { try (Statement stmt = conn.createStatement()) { stmt.execute("set statistics xml on"); diff --git a/src/test/java/io/ebean/config/ServerConfigTest.java b/src/test/java/io/ebean/config/ServerConfigTest.java index c9c20d6d5..b54851686 100644 --- a/src/test/java/io/ebean/config/ServerConfigTest.java +++ b/src/test/java/io/ebean/config/ServerConfigTest.java @@ -72,7 +72,7 @@ public class ServerConfigTest { props.setProperty("enabledL2Regions", "r0,users,orgs"); props.setProperty("caseSensitiveCollation", "false"); props.setProperty("loadModuleInfo", "true"); - + props.setProperty("collectQueryPlanThresholdMicros", "10000"); serverConfig.loadFromProperties(props); @@ -93,6 +93,7 @@ public class ServerConfigTest { assertEquals(PlatformConfig.DbUuid.BINARY, serverConfig.getPlatformConfig().getDbUuid()); assertEquals(JsonConfig.DateTime.MILLIS, serverConfig.getJsonDateTime()); assertEquals(JsonConfig.Date.MILLIS, serverConfig.getJsonDate()); + assertEquals(10000, serverConfig.getCollectQueryPlanThresholdMicros()); assertEquals("r0,users,orgs", serverConfig.getEnabledL2Regions()); @@ -138,6 +139,7 @@ public class ServerConfigTest { assertEquals(JsonConfig.Date.ISO8601, serverConfig.getJsonDate()); assertTrue(serverConfig.getPlatformConfig().isCaseSensitiveCollation()); assertFalse(serverConfig.isAutoLoadModuleInfo()); + assertEquals(Long.MAX_VALUE, serverConfig.getCollectQueryPlanThresholdMicros()); } @Test diff --git a/src/test/java/io/ebeaninternal/api/TDSpiEbeanServer.java b/src/test/java/io/ebeaninternal/api/TDSpiEbeanServer.java index 0009d202f..1b7f209e5 100644 --- a/src/test/java/io/ebeaninternal/api/TDSpiEbeanServer.java +++ b/src/test/java/io/ebeaninternal/api/TDSpiEbeanServer.java @@ -974,4 +974,9 @@ public class TDSpiEbeanServer implements SpiEbeanServer { public Set checkUniqueness(Object bean, Transaction transaction) { return Collections.emptySet(); } + + @Override + public SpiQueryBindCapture createQueryBindCapture(SpiQueryPlan queryPlan) { + return null; + } } diff --git a/src/test/java/org/tests/query/finder/TestCustomerFinder.java b/src/test/java/org/tests/query/finder/TestCustomerFinder.java index 6bba1f694..2423206e7 100644 --- a/src/test/java/org/tests/query/finder/TestCustomerFinder.java +++ b/src/test/java/org/tests/query/finder/TestCustomerFinder.java @@ -190,8 +190,9 @@ public class TestCustomerFinder extends BaseTestCase { } QueryPlanRequest request = new QueryPlanRequest(); - List plans = server().getMetaInfoManager().collectQueryPlans(request); + assertThat(plans).isNotEmpty(); + for (MetaQueryPlan plan : plans) { System.out.println(plan); } diff --git a/src/test/resources/ebean.properties b/src/test/resources/ebean.properties index e08f0f8a0..4caa3f7c7 100644 --- a/src/test/resources/ebean.properties +++ b/src/test/resources/ebean.properties @@ -27,7 +27,7 @@ datasource.default=h2 ebean.dumpMetricsOnShutdown=true ebean.dumpMetricsOptions=sql,hash - +ebean.collectQueryPlanThresholdMicros=1000 ebean.collectQueryPlans=true ebean.autoReadOnlyDataSource=true From 8a263d243c06be324b6147eed6eae4496e6b8f72 Mon Sep 17 00:00:00 2001 From: rob bygrave Date: Tue, 24 Dec 2019 00:29:46 +1300 Subject: [PATCH 2/2] Refactor for query plan capture with initial threshold micros - part 2 --- .../java/io/ebean/meta/MetaInfoManager.java | 22 +++-- .../java/io/ebean/meta/QueryPlanInit.java | 67 ++++++++++++++ .../java/io/ebean/meta/QueryPlanRequest.java | 89 ++++++------------- .../api/NoopQueryBindCapture.java | 3 +- .../api/NoopQueryPlanManager.java | 11 +++ .../ebeaninternal/api/QueryPlanManager.java | 10 +++ .../io/ebeaninternal/api/SpiDbQueryPlan.java | 15 ++++ .../api/SpiQueryBindCapture.java | 12 ++- .../io/ebeaninternal/api/SpiQueryPlan.java | 14 +++ .../server/core/DefaultMetaInfoManager.java | 10 ++- .../server/core/DefaultServer.java | 33 +++---- .../server/core/InternalConfiguration.java | 12 +-- .../server/deploy/BeanDescriptor.java | 10 ++- .../server/deploy/BeanDescriptorManager.java | 13 ++- .../server/query/CQueryBindCapture.java | 40 +++++---- .../server/query/CQueryPlan.java | 30 ++++--- .../server/query/CQueryPlanManager.java | 75 +++++++++++++++- .../server/query/CQueryPlanRequest.java | 86 ++++++++++++++++++ .../server/query/DQueryPlanOutput.java | 13 +-- .../server/query/QueryPlanLogger.java | 41 ++------- .../server/query/QueryPlanLoggerExplain.java | 12 +-- .../server/query/QueryPlanLoggerOracle.java | 12 +-- .../server/query/QueryPlanLoggerPostgres.java | 13 +-- .../query/QueryPlanLoggerSqlServer.java | 13 +-- .../query/finder/TestCustomerFinder.java | 2 +- 25 files changed, 431 insertions(+), 227 deletions(-) create mode 100644 src/main/java/io/ebean/meta/QueryPlanInit.java create mode 100644 src/main/java/io/ebeaninternal/api/SpiDbQueryPlan.java create mode 100644 src/main/java/io/ebeaninternal/server/query/CQueryPlanRequest.java diff --git a/src/main/java/io/ebean/meta/MetaInfoManager.java b/src/main/java/io/ebean/meta/MetaInfoManager.java index cf51d47e0..546f27591 100644 --- a/src/main/java/io/ebean/meta/MetaInfoManager.java +++ b/src/main/java/io/ebean/meta/MetaInfoManager.java @@ -33,11 +33,6 @@ public interface MetaInfoManager { */ List collectMetricsAsData(); - /** - * Collect query plans. - */ - List collectQueryPlans(QueryPlanRequest request); - /** * Visit the metrics resetting and collecting/reporting as desired. */ @@ -54,4 +49,21 @@ public interface MetaInfoManager { */ void resetAllMetrics(); + /** + * Initiate query plan collection by turning on "bind capture" on matching query plans. + *

+ * Also refer to ServerConfig collectQueryPlans that needs to be set to true + * and collectQueryPlanThresholdMicros which is a global defaults that can also + * initiate query plan capture. + * + * @return The query plans that have had bind capture turned on by this request. + */ + List queryPlanInit(QueryPlanInit initRequest); + + /** + * Collect query plans in the foreground. + */ + List queryPlanCollectNow(QueryPlanRequest request); + + } diff --git a/src/main/java/io/ebean/meta/QueryPlanInit.java b/src/main/java/io/ebean/meta/QueryPlanInit.java new file mode 100644 index 000000000..3c19caa39 --- /dev/null +++ b/src/main/java/io/ebean/meta/QueryPlanInit.java @@ -0,0 +1,67 @@ +package io.ebean.meta; + +import java.util.HashSet; +import java.util.Set; + +/** + * Initiate query plan collection for plans by their hash or all query plans. + */ +public class QueryPlanInit { + + private boolean all; + + private Set hashes = new HashSet<>(); + + private long thresholdMicros; + + /** + * Return true if this initiates bind collection on all query plans. + */ + public boolean isAll() { + return all; + } + + /** + * Set to true to initiate bind collection on all query plans. + */ + public void setAll(boolean all) { + this.all = all; + } + + /** + * Return the query execution time threshold which must be exceeded to initiate + * query plan collection. + */ + public long getThresholdMicros() { + return thresholdMicros; + } + + /** + * Set the query execution time threshold which must be exceeded to initiate + * query plan collection. + */ + public void setThresholdMicros(long thresholdMicros) { + this.thresholdMicros = thresholdMicros; + } + + /** + * Return true if the query plan should be initiated based on it's hash. + */ + public boolean includeHash(String hash) { + return all || hashes.contains(hash); + } + + /** + * Return the specific hashes that we want to collect query plans on. + */ + public Set getHashes() { + return hashes; + } + + /** + * Set the specific hashes that we want to collect query plans on. + */ + public void setHashes(Set hashes) { + this.hashes = hashes; + } +} diff --git a/src/main/java/io/ebean/meta/QueryPlanRequest.java b/src/main/java/io/ebean/meta/QueryPlanRequest.java index 6f678c892..3510b30cc 100644 --- a/src/main/java/io/ebean/meta/QueryPlanRequest.java +++ b/src/main/java/io/ebean/meta/QueryPlanRequest.java @@ -1,97 +1,66 @@ package io.ebean.meta; -import java.sql.Connection; -import java.util.ArrayList; -import java.util.List; -import java.util.Set; - /** * Request used to capture query plans. */ public class QueryPlanRequest { - private final List plans = new ArrayList<>(); - - private Connection connection; - - private boolean store; - private long since; - private Set> includedBeanTypes; + private int maxCount; - private Set includedLabels; - - public List getPlans() { - return plans; - } + private long maxTimeMillis; /** - * Return the connection to use to capture the query plans. - */ - public Connection getConnection() { - return connection; - } - - /** - * Set the connection to use to capture the query plans. - */ - public void setConnection(Connection connection) { - this.connection = connection; - } - - /** - * Return true if the captured query plan is stored. - */ - public boolean isStore() { - return store; - } - - /** - * Set to true to store the captured query plan. - */ - public void setStore(boolean store) { - this.store = store; - } - - /** - * Return the epoch time after which the query plan was capture (to be included). + * Return the epoch time in millis for minimum bind capture time. + *

+ * When set this ensures that the bind values used to get the query plan + * have been around for a while (e.g. 5 mins) and so reasonably represent + * bind values that match the slowest execution for this query plan. */ public long getSince() { return since; } /** - * Set the epoch time after which the query plan was captured. - *

- * This is used to only capture plans that have changed since a given time (like the time of last capture). - *

+ * Set the epoch time (e.g. 5 mins ago) such that the query bind values + * reasonably represent bind values that match the slowest execution for this query plan. * - * @param since The time after which the query plan was captured to be included + * @param since The minimum age of the bind values capture. */ public void setSince(long since) { this.since = since; } /** - * Process consume the query plan. + * Return the maximum number of plans to capture. */ - public void process(MetaQueryPlan plan) { - plans.add(plan); + public int getMaxCount() { + return maxCount; } /** - * Return true if the bean type should be included in the query plan capture. + * Set the maximum number of plans to capture. */ - public boolean includeType(Class beanType) { - return includedBeanTypes == null || includedBeanTypes.isEmpty() || includedBeanTypes.contains(beanType); + public void setMaxCount(int maxCount) { + this.maxCount = maxCount; } /** - * Return true if the label should be included in the query plan capture. + * Return the maximum amount of time we want to use to capture plans. + *

+ * Query plan collection will stop once this time is exceeded. */ - public boolean includeLabel(String label) { - return includedLabels == null || includedLabels.isEmpty() || includedLabels.contains(label); + public long getMaxTimeMillis() { + return maxTimeMillis; } + /** + * Set the maximum amount of time we want to use to capture plans. + *

+ * Query plan collection will stop once this time is exceeded. + */ + public void setMaxTimeMillis(long maxTimeMillis) { + this.maxTimeMillis = maxTimeMillis; + } } diff --git a/src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java b/src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java index e4c747497..2f7162c70 100644 --- a/src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java +++ b/src/main/java/io/ebeaninternal/api/NoopQueryBindCapture.java @@ -1,6 +1,5 @@ package io.ebeaninternal.api; -import io.ebean.meta.QueryPlanRequest; import io.ebeaninternal.server.type.bindcapture.BindCapture; class NoopQueryBindCapture implements SpiQueryBindCapture { @@ -16,7 +15,7 @@ class NoopQueryBindCapture implements SpiQueryBindCapture { } @Override - public void collectQueryPlan(QueryPlanRequest request) { + public void queryPlanInit(long thresholdMicros) { // do nothing } } diff --git a/src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java b/src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java index 7b97d821f..e00ad57f1 100644 --- a/src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java +++ b/src/main/java/io/ebeaninternal/api/NoopQueryPlanManager.java @@ -1,9 +1,20 @@ package io.ebeaninternal.api; +import io.ebean.meta.MetaQueryPlan; +import io.ebean.meta.QueryPlanRequest; + +import java.util.Collections; +import java.util.List; + class NoopQueryPlanManager implements QueryPlanManager { @Override public SpiQueryBindCapture createBindCapture(SpiQueryPlan queryPlan) { return SpiQueryBindCapture.NOOP; } + + @Override + public List collect(QueryPlanRequest request) { + return Collections.emptyList(); + } } diff --git a/src/main/java/io/ebeaninternal/api/QueryPlanManager.java b/src/main/java/io/ebeaninternal/api/QueryPlanManager.java index fea4d1976..f9750c47a 100644 --- a/src/main/java/io/ebeaninternal/api/QueryPlanManager.java +++ b/src/main/java/io/ebeaninternal/api/QueryPlanManager.java @@ -1,5 +1,10 @@ package io.ebeaninternal.api; +import io.ebean.meta.MetaQueryPlan; +import io.ebean.meta.QueryPlanRequest; + +import java.util.List; + /** * Manage query plan capture. */ @@ -11,4 +16,9 @@ public interface QueryPlanManager { * Create the bind capture for the given query plan. */ SpiQueryBindCapture createBindCapture(SpiQueryPlan queryPlan); + + /** + * Collect the database query plans. + */ + List collect(QueryPlanRequest request); } diff --git a/src/main/java/io/ebeaninternal/api/SpiDbQueryPlan.java b/src/main/java/io/ebeaninternal/api/SpiDbQueryPlan.java new file mode 100644 index 000000000..135976f54 --- /dev/null +++ b/src/main/java/io/ebeaninternal/api/SpiDbQueryPlan.java @@ -0,0 +1,15 @@ +package io.ebeaninternal.api; + +import io.ebean.meta.MetaQueryPlan; + +/** + * Internal database query plan being capture. + */ +public interface SpiDbQueryPlan extends MetaQueryPlan { + + /** + * Extend with queryTimeMicros and captureCount. + */ + SpiDbQueryPlan with(long queryTimeMicros, long captureCount); + +} diff --git a/src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java b/src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java index 9088f54ad..636b6689c 100644 --- a/src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java +++ b/src/main/java/io/ebeaninternal/api/SpiQueryBindCapture.java @@ -20,12 +20,16 @@ public interface SpiQueryBindCapture { boolean collectFor(long timeMicros); /** - * Set the bind capture and the related query execution time. + * Set the captured bind values that we can use later to collect a query plan. + * + * @param bindCapture The bind values of the query + * @param queryTimeMicros The query execution time + * @param startNanos The nanos start of this bind capture */ - void setBind(BindCapture bindCapture, long timeMicros, long startNanos); + void setBind(BindCapture bindCapture, long queryTimeMicros, long startNanos); /** - * Collect the query execution plan usually executing the query to do so. + * Update the threshold micros triggering the bind capture. */ - void collectQueryPlan(QueryPlanRequest request); + void queryPlanInit(long thresholdMicros); } diff --git a/src/main/java/io/ebeaninternal/api/SpiQueryPlan.java b/src/main/java/io/ebeaninternal/api/SpiQueryPlan.java index e06243df8..96a1eade7 100644 --- a/src/main/java/io/ebeaninternal/api/SpiQueryPlan.java +++ b/src/main/java/io/ebeaninternal/api/SpiQueryPlan.java @@ -31,4 +31,18 @@ public interface SpiQueryPlan { * The related profile location. */ ProfileLocation getProfileLocation(); + + /** + * Initiate bind capture with the give threshold. + */ + void queryPlanInit(long thresholdMicros); + + /** + * Return as Database query plan. + * + * @param bind Description of the bind values used + * @param planString The raw database query plan + */ + SpiDbQueryPlan createMeta(String bind, String planString); + } diff --git a/src/main/java/io/ebeaninternal/server/core/DefaultMetaInfoManager.java b/src/main/java/io/ebeaninternal/server/core/DefaultMetaInfoManager.java index 89fb45220..a6a65e19d 100644 --- a/src/main/java/io/ebeaninternal/server/core/DefaultMetaInfoManager.java +++ b/src/main/java/io/ebeaninternal/server/core/DefaultMetaInfoManager.java @@ -9,6 +9,7 @@ import io.ebean.meta.MetaQueryPlan; import io.ebean.meta.MetaTimedMetric; import io.ebean.meta.MetricData; import io.ebean.meta.MetricVisitor; +import io.ebean.meta.QueryPlanInit; import io.ebean.meta.QueryPlanRequest; import io.ebean.meta.ServerMetrics; import io.ebean.meta.ServerMetricsAsJson; @@ -27,8 +28,13 @@ public class DefaultMetaInfoManager implements MetaInfoManager { } @Override - public List collectQueryPlans(QueryPlanRequest request) { - return server.collectQueryPlans(request); + public List queryPlanInit(QueryPlanInit initRequest) { + return server.queryPlanInit(initRequest); + } + + @Override + public List queryPlanCollectNow(QueryPlanRequest request) { + return server.queryPlanCollectNow(request); } @Override diff --git a/src/main/java/io/ebeaninternal/server/core/DefaultServer.java b/src/main/java/io/ebeaninternal/server/core/DefaultServer.java index aa59462c1..023ea3ea3 100644 --- a/src/main/java/io/ebeaninternal/server/core/DefaultServer.java +++ b/src/main/java/io/ebeaninternal/server/core/DefaultServer.java @@ -55,6 +55,7 @@ import io.ebean.event.readaudit.ReadAuditPrepare; import io.ebean.meta.MetaInfoManager; import io.ebean.meta.MetaQueryPlan; import io.ebean.meta.MetricVisitor; +import io.ebean.meta.QueryPlanInit; import io.ebean.meta.QueryPlanRequest; import io.ebean.plugin.BeanType; import io.ebean.plugin.Plugin; @@ -62,7 +63,6 @@ import io.ebean.plugin.Property; import io.ebean.plugin.SpiServer; import io.ebean.text.csv.CsvReader; import io.ebean.text.json.JsonContext; -import io.ebean.util.JdbcClose; import io.ebeaninternal.api.ExtraMetrics; import io.ebeaninternal.api.LoadBeanRequest; import io.ebeaninternal.api.LoadManyRequest; @@ -254,17 +254,13 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { * Create the DefaultServer. */ public DefaultServer(InternalConfiguration config, ServerCacheManager cache) { - this.logManager = config.getLogManager(); this.dtoBeanManager = config.getDtoBeanManager(); this.serverConfig = config.getServerConfig(); - this.metaInfoManager = new DefaultMetaInfoManager(this); this.serverCacheManager = cache; this.databasePlatform = config.getDatabasePlatform(); this.backgroundExecutor = config.getBackgroundExecutor(); - this.queryPlanManager = config.getQueryPlanManager(); this.extraMetrics = config.getExtraMetrics(); - this.serverName = serverConfig.getName(); this.lazyLoadBatchSize = serverConfig.getLazyLoadBatchSize(); this.queryBatchSize = serverConfig.getQueryBatchSize(); @@ -275,10 +271,8 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { this.currentTenantProvider = serverConfig.getCurrentTenantProvider(); this.slowQueryMicros = config.getSlowQueryMicros(); this.slowQueryListener = config.getSlowQueryListener(); - this.beanDescriptorManager = config.getBeanDescriptorManager(); beanDescriptorManager.setEbeanServer(this); - this.updateAllPropertiesInBatch = serverConfig.isUpdateAllPropertiesInBatch(); this.callStackFactory = initCallStackFactory(serverConfig); @@ -299,6 +293,8 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { DocStoreIntegration docStoreComponents = config.createDocStoreIntegration(this); this.transactionManager = config.createTransactionManager(docStoreComponents.updateProcessor()); this.documentStore = docStoreComponents.documentStore(); + this.queryPlanManager = config.initQueryPlanManager(transactionManager.getDataSource()); + this.metaInfoManager = new DefaultMetaInfoManager(this); this.serverPlugins = config.getPlugins(); this.ddlGenerator = new DdlGenerator(this, serverConfig); @@ -2441,23 +2437,16 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer { visitor.visitEnd(); } - public List collectQueryPlans(QueryPlanRequest request) { - Connection connection = null; - try { - connection = getDataSource().getConnection(); - request.setConnection(connection); - beanDescriptorManager.collectQueryPlans(request); - } catch (SQLException e) { - throw new RuntimeException(e); - - } finally { - JdbcClose.close(connection); - } - return request.getPlans(); - } - @Override public SpiQueryBindCapture createQueryBindCapture(SpiQueryPlan plan) { return queryPlanManager.createBindCapture(plan); } + + List queryPlanInit(QueryPlanInit initRequest) { + return beanDescriptorManager.queryPlanInit(initRequest); + } + + List queryPlanCollectNow(QueryPlanRequest request) { + return queryPlanManager.collect(request); + } } diff --git a/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java b/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java index 5ebcf4d74..6930228f6 100644 --- a/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java +++ b/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java @@ -651,12 +651,12 @@ public class InternalConfiguration { return new DefaultServerCacheManager(builder); } - public QueryPlanManager getQueryPlanManager() { + public QueryPlanManager initQueryPlanManager(DataSource dataSource) { if (!serverConfig.isCollectQueryPlans()) { return QueryPlanManager.NOOP; } long threshold = serverConfig.getCollectQueryPlanThresholdMicros(); - return new CQueryPlanManager(threshold, queryPlanLogger(databasePlatform.getPlatform())); + return new CQueryPlanManager(dataSource, threshold, queryPlanLogger(databasePlatform.getPlatform()), extraMetrics); } /** @@ -665,13 +665,13 @@ public class InternalConfiguration { QueryPlanLogger queryPlanLogger(Platform platform) { switch (platform.base()) { case POSTGRES: - return new QueryPlanLoggerPostgres(extraMetrics); + return new QueryPlanLoggerPostgres(); case SQLSERVER: - return new QueryPlanLoggerSqlServer(extraMetrics); + return new QueryPlanLoggerSqlServer(); case ORACLE: - return new QueryPlanLoggerOracle(extraMetrics); + return new QueryPlanLoggerOracle(); default: - return new QueryPlanLoggerExplain(extraMetrics); + return new QueryPlanLoggerExplain(); } } } diff --git a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java index af8647a3d..12b0c2d3e 100644 --- a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java +++ b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptor.java @@ -27,8 +27,9 @@ import io.ebean.event.changelog.ChangeType; import io.ebean.event.readaudit.ReadAuditLogger; import io.ebean.event.readaudit.ReadAuditPrepare; import io.ebean.event.readaudit.ReadEvent; +import io.ebean.meta.MetaQueryPlan; import io.ebean.meta.MetricVisitor; -import io.ebean.meta.QueryPlanRequest; +import io.ebean.meta.QueryPlanInit; import io.ebean.plugin.BeanDocType; import io.ebean.plugin.BeanType; import io.ebean.plugin.ExpressionPath; @@ -1682,10 +1683,11 @@ public class BeanDescriptor implements BeanType, STreeType { return new DeployUpdateParser(this).parse(ormUpdateStatement); } - void collectQueryPlans(QueryPlanRequest request) { + void queryPlanInit(QueryPlanInit request, List list) { for (CQueryPlan queryPlan : queryPlanCache.values()) { - if (request.includeLabel(queryPlan.getLabel())) { - queryPlan.collectQueryPlan(request); + if (request.includeHash(queryPlan.getHash())) { + queryPlan.queryPlanInit(request.getThresholdMicros()); + list.add(queryPlan.createMeta(null, null)); } } } diff --git a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java index 4370dd651..5e97cbfbd 100644 --- a/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java +++ b/src/main/java/io/ebeaninternal/server/deploy/BeanDescriptorManager.java @@ -20,8 +20,9 @@ import io.ebean.event.changelog.ChangeLogFilter; import io.ebean.event.changelog.ChangeLogListener; import io.ebean.event.changelog.ChangeLogPrepare; import io.ebean.event.changelog.ChangeLogRegister; +import io.ebean.meta.MetaQueryPlan; import io.ebean.meta.MetricVisitor; -import io.ebean.meta.QueryPlanRequest; +import io.ebean.meta.QueryPlanInit; import io.ebean.plugin.BeanType; import io.ebean.util.AnnotationUtil; import io.ebeaninternal.api.ConcurrencyMode; @@ -55,7 +56,6 @@ import io.ebeaninternal.server.persist.platform.MultiValueBind; import io.ebeaninternal.server.properties.BeanPropertiesReader; import io.ebeaninternal.server.properties.BeanPropertyAccess; import io.ebeaninternal.server.properties.EnhanceBeanPropertyAccess; -import io.ebeaninternal.server.query.CQueryPlan; import io.ebeaninternal.server.type.ScalarType; import io.ebeaninternal.server.type.ScalarTypeInteger; import io.ebeaninternal.server.type.TypeManager; @@ -1693,12 +1693,12 @@ public class BeanDescriptorManager implements BeanDescriptorMap { } } - public void collectQueryPlans(QueryPlanRequest request) { + public List queryPlanInit(QueryPlanInit request) { + List list = new ArrayList<>(); for (BeanDescriptor desc : immutableDescriptorList) { - if (request.includeType(desc.getBeanType())) { - desc.collectQueryPlans(request); - } + desc.queryPlanInit(request, list); } + return list; } /** @@ -1710,7 +1710,6 @@ public class BeanDescriptorManager implements BeanDescriptorMap { @Override public int compare(BeanDescriptor o1, BeanDescriptor o2) { - return o1.getName().compareTo(o2.getName()); } } diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java b/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java index a2d934b29..30e319ad8 100644 --- a/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java +++ b/src/main/java/io/ebeaninternal/server/query/CQueryBindCapture.java @@ -1,6 +1,6 @@ package io.ebeaninternal.server.query; -import io.ebean.meta.QueryPlanRequest; +import io.ebeaninternal.api.SpiDbQueryPlan; import io.ebeaninternal.api.SpiQueryBindCapture; import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; @@ -9,8 +9,8 @@ class CQueryBindCapture implements SpiQueryBindCapture { private static final double multiplier = 1.3d; + private final CQueryPlanManager manager; private final SpiQueryPlan queryPlan; - private final QueryPlanLogger planLogger; private BindCapture bindCapture; private long queryTimeMicros; @@ -19,9 +19,9 @@ class CQueryBindCapture implements SpiQueryBindCapture { private long lastBindCapture; - CQueryBindCapture(SpiQueryPlan queryPlan, QueryPlanLogger planLogger, long thresholdMicros) { + CQueryBindCapture(CQueryPlanManager manager, SpiQueryPlan queryPlan, long thresholdMicros) { + this.manager = manager; this.queryPlan = queryPlan; - this.planLogger = planLogger; this.thresholdMicros = thresholdMicros; } @@ -33,13 +33,6 @@ class CQueryBindCapture implements SpiQueryBindCapture { return timeMicros > thresholdMicros && captureCount < 10; } - /** - * Set the captured bind values that we can use later to collect a query plan. - * - * @param bindCapture The bind values of the query - * @param queryTimeMicros The query execution time - * @param startNanos The nanos start of this bind capture - */ @Override public void setBind(BindCapture bindCapture, long queryTimeMicros, long startNanos) { synchronized (this) { @@ -48,27 +41,36 @@ class CQueryBindCapture implements SpiQueryBindCapture { this.bindCapture = bindCapture; this.queryTimeMicros = queryTimeMicros; lastBindCapture = System.currentTimeMillis(); - planLogger.addBindTimeSince(startNanos); + manager.notifyBindCapture(this, startNanos); } } + @Override + public void queryPlanInit(long thresholdMicros) { + // effective enable bind capture for this plan + this.thresholdMicros = thresholdMicros; + this.captureCount = 0; + } + /** * Collect the query plan using already captured bind values. */ - @Override - public void collectQueryPlan(QueryPlanRequest request) { - if (bindCapture == null || request.getSince() > lastBindCapture) { + public boolean collectQueryPlan(CQueryPlanRequest request) { + if (bindCapture == null || request.getSince() < lastBindCapture) { // no bind capture since the last capture - return; + return false; } final BindCapture last = this.bindCapture; - DQueryPlanOutput queryPlan = planLogger.collectQueryPlan(request.getConnection(), this.queryPlan, last); + SpiDbQueryPlan queryPlan = manager.collectPlan(request.getConnection(), this.queryPlan, last); if (queryPlan != null) { - queryPlan.with(queryTimeMicros, captureCount, this.queryPlan.getHash()); - request.process(queryPlan); + request.add(queryPlan.with(queryTimeMicros, captureCount)); + // effectively turn off bind capture for this plan + thresholdMicros = Long.MAX_VALUE; + return true; } + return false; } } diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java b/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java index 6eceac806..98c7468dd 100644 --- a/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java +++ b/src/main/java/io/ebeaninternal/server/query/CQueryPlan.java @@ -3,7 +3,6 @@ package io.ebeaninternal.server.query; import io.ebean.ProfileLocation; import io.ebean.config.dbplatform.SqlLimitResponse; import io.ebean.meta.MetricType; -import io.ebean.meta.QueryPlanRequest; import io.ebean.metric.MetricFactory; import io.ebean.metric.TimedMetric; import io.ebeaninternal.api.CQueryPlanKey; @@ -56,8 +55,6 @@ public class CQueryPlan implements SpiQueryPlan { private final SpiEbeanServer server; - private final boolean autoTuned; - private final ProfileLocation profileLocation; private final String location; @@ -114,7 +111,6 @@ public class CQueryPlan implements SpiQueryPlan { this.label = query.getPlanLabel(); this.name = deriveName(label, query.getType()); this.location = location(); - this.autoTuned = query.isAutoTuned(); this.asOfTableCount = query.getAsOfTableCount(); this.sql = sqlRes.getSql(); this.rowNumberIncluded = sqlRes.isIncludesRowNumberColumn(); @@ -141,7 +137,6 @@ public class CQueryPlan implements SpiQueryPlan { this.name = deriveName(label, query.getType()); this.location = location(); this.planKey = buildPlanKey(sql, rowNumberIncluded, logWhereSql); - this.autoTuned = false; this.asOfTableCount = 0; this.sql = sql; this.sqlTree = sqlTree; @@ -151,7 +146,7 @@ public class CQueryPlan implements SpiQueryPlan { this.encryptedProps = sqlTree.getEncryptedProps(); this.stats = new CQueryPlanStats(this); this.dependentTables = sqlTree.dependentTables(); - this.bindCapture = initBindCapture(query); + this.bindCapture = initBindCaptureRaw(sql); this.hash = md5Hash(); } @@ -169,6 +164,10 @@ public class CQueryPlan implements SpiQueryPlan { return query.getType().isUpdate() ? SpiQueryBindCapture.NOOP : server.createQueryBindCapture(this); } + private SpiQueryBindCapture initBindCaptureRaw(String sql) { + return sql.equals(RESULT_SET_BASED_RAW_SQL) ? SpiQueryBindCapture.NOOP : server.createQueryBindCapture(this); + } + private String location() { return (profileLocation == null) ? null : profileLocation.location(); } @@ -219,6 +218,16 @@ public class CQueryPlan implements SpiQueryPlan { return location; } + @Override + public void queryPlanInit(long thresholdMicros) { + bindCapture.queryPlanInit(thresholdMicros); + } + + @Override + public DQueryPlanOutput createMeta(String bind, String planString) { + return new DQueryPlanOutput(getBeanType(), name, hash, sql, profileLocation, bind, planString); + } + public DataReader createDataReader(ResultSet rset) { return new RsetDataReader(dataTimeZone, rset); } @@ -342,8 +351,8 @@ public class CQueryPlan implements SpiQueryPlan { } void captureBindForQueryPlan(CQueryPredicates predicates, long executionTimeMicros) { + final long startNanos = System.nanoTime(); try { - long startNanos = System.nanoTime(); DataBindCapture capture = bindCapture(); predicates.bind(capture); bindCapture.setBind(capture.bindCapture(), executionTimeMicros, startNanos); @@ -351,11 +360,4 @@ public class CQueryPlan implements SpiQueryPlan { logger.error("Error capturing bind values", e); } } - - public void collectQueryPlan(QueryPlanRequest request) { - - if (!getSql().equals(RESULT_SET_BASED_RAW_SQL) && bindCapture != null) { - bindCapture.collectQueryPlan(request); - } - } } diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java b/src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java index 9ef20ed78..68d45e228 100644 --- a/src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java +++ b/src/main/java/io/ebeaninternal/server/query/CQueryPlanManager.java @@ -1,22 +1,89 @@ package io.ebeaninternal.server.query; +import io.ebean.meta.MetaQueryPlan; +import io.ebean.meta.QueryPlanRequest; +import io.ebean.metric.TimedMetric; +import io.ebeaninternal.api.ExtraMetrics; import io.ebeaninternal.api.QueryPlanManager; +import io.ebeaninternal.api.SpiDbQueryPlan; import io.ebeaninternal.api.SpiQueryBindCapture; import io.ebeaninternal.api.SpiQueryPlan; +import io.ebeaninternal.server.type.bindcapture.BindCapture; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import javax.sql.DataSource; +import java.sql.Connection; +import java.sql.SQLException; +import java.util.List; +import java.util.concurrent.ConcurrentHashMap; + +import static java.util.Collections.emptyList; public class CQueryPlanManager implements QueryPlanManager { - private final long threshold; + private static final Logger log = LoggerFactory.getLogger(CQueryPlanManager.class); + + private static final Object dummy = new Object(); + + private final ConcurrentHashMap plans = new ConcurrentHashMap<>(); + + private final DataSource dataSource; + + private final long defaultThreshold; private final QueryPlanLogger planLogger; - public CQueryPlanManager(long threshold, QueryPlanLogger planLogger) { - this.threshold = threshold; + private final TimedMetric timeCollection; + + private final TimedMetric timeBindCapture; + + public CQueryPlanManager(DataSource dataSource, long defaultThreshold, QueryPlanLogger planLogger, ExtraMetrics extraMetrics) { + this.dataSource = dataSource; + this.defaultThreshold = defaultThreshold; this.planLogger = planLogger; + this.timeCollection = extraMetrics.getPlanCollect(); + this.timeBindCapture = extraMetrics.getBindCapture(); } @Override public SpiQueryBindCapture createBindCapture(SpiQueryPlan queryPlan) { - return new CQueryBindCapture(queryPlan, planLogger, threshold); + return new CQueryBindCapture(this, queryPlan, defaultThreshold); + } + + public void notifyBindCapture(CQueryBindCapture planBind, long startNanos) { + plans.put(planBind, dummy); + timeBindCapture.addSinceNanos(startNanos); + } + + @Override + public List collect(QueryPlanRequest request) { + if (plans.isEmpty()) { + return emptyList(); + } + long startNanos = System.nanoTime(); + try { + return collectPlans(request); + } finally { + timeCollection.addSinceNanos(startNanos); + } + } + + private List collectPlans(QueryPlanRequest request) { + try (Connection connection = dataSource.getConnection()) { + CQueryPlanRequest req = new CQueryPlanRequest(connection, request, plans.keySet().iterator()); + while (req.hasNext()) { + req.nextCapture(); + } + return req.getPlans(); + + } catch (SQLException e) { + log.error("Error during query plan collection", e); + return emptyList(); + } + } + + public SpiDbQueryPlan collectPlan(Connection connection, SpiQueryPlan queryPlan, BindCapture last) { + return planLogger.collectPlan(connection, queryPlan, last); } } diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryPlanRequest.java b/src/main/java/io/ebeaninternal/server/query/CQueryPlanRequest.java new file mode 100644 index 000000000..86e15f389 --- /dev/null +++ b/src/main/java/io/ebeaninternal/server/query/CQueryPlanRequest.java @@ -0,0 +1,86 @@ +package io.ebeaninternal.server.query; + +import io.ebean.meta.MetaQueryPlan; +import io.ebean.meta.QueryPlanRequest; + +import java.sql.Connection; +import java.util.ArrayList; +import java.util.Iterator; +import java.util.List; + +/** + * Captures database query plans. + */ +class CQueryPlanRequest { + + private final List plans = new ArrayList<>(); + + private final Connection connection; + private final long since; + private final int maxCount; + private final long maxTime; + private Iterator iterator; + + CQueryPlanRequest(Connection connection, QueryPlanRequest req, Iterator iterator) { + this.connection = connection; + this.iterator = iterator; + this.maxCount = req.getMaxCount(); + long reqSince = req.getSince(); + this.since = (reqSince == 0) ? Long.MAX_VALUE: reqSince; + long maxTimeMillis = req.getMaxTimeMillis(); + this.maxTime = maxTimeMillis > 0 ? System.currentTimeMillis() + maxTimeMillis : 0; + } + + /** + * Return the connection used to collect the db query plan. + */ + Connection getConnection() { + return connection; + } + + /** + * Add the collected query plan. + */ + void add(MetaQueryPlan dbQueryPlan) { + plans.add(dbQueryPlan); + } + + /** + * Return the min epoch time in millis for minimum bind capture age. + */ + long getSince() { + return since; + } + + /** + * Return the captured query plans. + */ + List getPlans() { + return plans; + } + + /** + * Return true to continue database query plan capture. + */ + boolean hasNext() { + return moreByCount() && moreByTime() && iterator.hasNext(); + } + + /** + * Capture the next database query plan. + */ + void nextCapture() { + final CQueryBindCapture next = iterator.next(); + if (next.collectQueryPlan(this)) { + iterator.remove(); + } + } + + private boolean moreByCount() { + return maxCount == 0 || maxCount > plans.size(); + } + + private boolean moreByTime() { + return maxTime == 0 || maxTime > System.currentTimeMillis(); + } +} diff --git a/src/main/java/io/ebeaninternal/server/query/DQueryPlanOutput.java b/src/main/java/io/ebeaninternal/server/query/DQueryPlanOutput.java index f8d734b70..8065a62dc 100644 --- a/src/main/java/io/ebeaninternal/server/query/DQueryPlanOutput.java +++ b/src/main/java/io/ebeaninternal/server/query/DQueryPlanOutput.java @@ -2,11 +2,12 @@ package io.ebeaninternal.server.query; import io.ebean.ProfileLocation; import io.ebean.meta.MetaQueryPlan; +import io.ebeaninternal.api.SpiDbQueryPlan; /** * Captured query plan details. */ -class DQueryPlanOutput implements MetaQueryPlan { +class DQueryPlanOutput implements MetaQueryPlan, SpiDbQueryPlan { private final Class beanType; private final String label; @@ -20,13 +21,14 @@ class DQueryPlanOutput implements MetaQueryPlan { private long queryTimeMicros; private long captureCount; - DQueryPlanOutput(Class beanType, String label, String sql, String bind, String plan, ProfileLocation profileLocation) { + DQueryPlanOutput(Class beanType, String label, String hash, String sql, ProfileLocation profileLocation, String bind, String plan) { this.beanType = beanType; this.label = label; + this.hash = hash; this.sql = sql; + this.profileLocation = profileLocation; this.bind = bind; this.plan = plan; - this.profileLocation = profileLocation; } @Override @@ -104,9 +106,10 @@ class DQueryPlanOutput implements MetaQueryPlan { /** * Additionally set the query execution time and the number of bind captures. */ - void with(long queryTimeMicros, long captureCount, String hash) { + @Override + public DQueryPlanOutput with(long queryTimeMicros, long captureCount) { this.queryTimeMicros = queryTimeMicros; this.captureCount = captureCount; - this.hash = hash; + return this; } } diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java index 3a039346a..53bd01f94 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLogger.java @@ -1,7 +1,6 @@ package io.ebeaninternal.server.query; -import io.ebean.metric.TimedMetric; -import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiDbQueryPlan; import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; import org.slf4j.Logger; @@ -15,37 +14,9 @@ public abstract class QueryPlanLogger { static final Logger queryPlanLog = LoggerFactory.getLogger(QueryPlanLogger.class); - private final TimedMetric timeCollection; + abstract SpiDbQueryPlan collectPlan(Connection conn, SpiQueryPlan plan, BindCapture bind); - private final TimedMetric timeBindCapture; - - protected QueryPlanLogger(ExtraMetrics extraMetrics) { - this.timeCollection = extraMetrics.getPlanCollect(); - this.timeBindCapture = extraMetrics.getBindCapture(); - } - - abstract DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind); - - /** - * Add timing for bind capture. - */ - public void addBindTimeSince(long startNanos) { - timeBindCapture.addSinceNanos(startNanos); - } - - /** - * Collect the DB query plan. - */ - public DQueryPlanOutput collectQueryPlan(Connection conn, SpiQueryPlan plan, BindCapture bind) { - long startNanos = System.nanoTime(); - try { - return collect(conn, plan, bind); - } finally { - timeCollection.addSinceNanos(startNanos); - } - } - - DQueryPlanOutput readQueryPlan(SpiQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { + SpiDbQueryPlan readQueryPlan(SpiQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { StringBuilder sb = new StringBuilder(); for (int i = 1; i <= rset.getMetaData().getColumnCount(); i++) { sb.append(rset.getMetaData().getColumnLabel(i)).append("\t"); @@ -56,11 +27,11 @@ public abstract class QueryPlanLogger { return createPlan(plan, bind.toString(), sb.toString()); } - DQueryPlanOutput createPlan(SpiQueryPlan plan, String bind, String planString) { - return new DQueryPlanOutput(plan.getBeanType(), plan.getName(), plan.getSql(), bind, planString, plan.getProfileLocation()); + SpiDbQueryPlan createPlan(SpiQueryPlan plan, String bind, String planString) { + return plan.createMeta(bind, planString); } - DQueryPlanOutput readQueryPlanBasic(SpiQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { + SpiDbQueryPlan readQueryPlanBasic(SpiQueryPlan plan, BindCapture bind, ResultSet rset) throws SQLException { StringBuilder sb = new StringBuilder(); readPlanData(sb, rset); return createPlan(plan, bind.toString(), sb.toString().trim()); diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java index 786c874c0..6f89c138a 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerExplain.java @@ -1,6 +1,6 @@ package io.ebeaninternal.server.query; -import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiDbQueryPlan; import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; @@ -14,23 +14,17 @@ import java.sql.SQLException; */ public class QueryPlanLoggerExplain extends QueryPlanLogger { - public QueryPlanLoggerExplain(ExtraMetrics extraMetrics) { - super(extraMetrics); - } - @Override - public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { - + public SpiDbQueryPlan collectPlan(Connection conn, SpiQueryPlan plan, BindCapture bind) { try (PreparedStatement explainStmt = conn.prepareStatement("EXPLAIN " + plan.getSql())) { bind.prepare(explainStmt, conn); try (ResultSet rset = explainStmt.executeQuery()) { return readQueryPlan(plan, bind, rset); } - } catch (SQLException e) { queryPlanLog.error("Could not log query plan", e); + return null; } - return null; } } diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java index f4ff22025..2d2f4702f 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerOracle.java @@ -1,7 +1,7 @@ package io.ebeaninternal.server.query; -import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiDbQueryPlan; import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; @@ -18,13 +18,8 @@ import java.sql.Statement; */ public class QueryPlanLoggerOracle extends QueryPlanLogger { - public QueryPlanLoggerOracle(ExtraMetrics extraMetrics) { - super(extraMetrics); - } - @Override - public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { - + public SpiDbQueryPlan collectPlan(Connection conn, SpiQueryPlan plan, BindCapture bind) { try (Statement stmt = conn.createStatement()) { try (PreparedStatement explainStmt = conn.prepareStatement("EXPLAIN PLAN FOR " + plan.getSql())) { bind.prepare(explainStmt, conn); @@ -33,11 +28,10 @@ public class QueryPlanLoggerOracle extends QueryPlanLogger { try (ResultSet rset = stmt.executeQuery("select plan_table_output from table(dbms_xplan.display())")) { return readQueryPlan(plan, bind, rset); } - } catch (SQLException e) { queryPlanLog.error("Could not log query plan", e); + return null; } - return null; } } diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java index b36ed011c..596f33bc0 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerPostgres.java @@ -1,6 +1,6 @@ package io.ebeaninternal.server.query; -import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiDbQueryPlan; import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; @@ -14,24 +14,17 @@ import java.sql.SQLException; */ public class QueryPlanLoggerPostgres extends QueryPlanLogger { - public QueryPlanLoggerPostgres(ExtraMetrics extraMetrics) { - super(extraMetrics); - } - @Override - public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { - + public SpiDbQueryPlan collectPlan(Connection conn, SpiQueryPlan plan, BindCapture bind) { String explain = "explain analyze " + plan.getSql(); try (PreparedStatement explainStmt = conn.prepareStatement(explain)) { bind.prepare(explainStmt, conn); try (ResultSet rset = explainStmt.executeQuery()) { return readQueryPlanBasic(plan, bind, rset); } - } catch (SQLException e) { queryPlanLog.error("Could not log query plan: " + explain, e); - throw new IllegalStateException("Failed to obtain explain plan: " + explain, e); + return null; } } - } diff --git a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java index 90afa320b..6657448e2 100644 --- a/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java +++ b/src/main/java/io/ebeaninternal/server/query/QueryPlanLoggerSqlServer.java @@ -1,6 +1,6 @@ package io.ebeaninternal.server.query; -import io.ebeaninternal.api.ExtraMetrics; +import io.ebeaninternal.api.SpiDbQueryPlan; import io.ebeaninternal.api.SpiQueryPlan; import io.ebeaninternal.server.type.bindcapture.BindCapture; @@ -18,13 +18,8 @@ import java.sql.Statement; */ public class QueryPlanLoggerSqlServer extends QueryPlanLogger { - public QueryPlanLoggerSqlServer(ExtraMetrics extraMetrics) { - super(extraMetrics); - } - @Override - public DQueryPlanOutput collect(Connection conn, SpiQueryPlan plan, BindCapture bind) { - + public SpiDbQueryPlan collectPlan(Connection conn, SpiQueryPlan plan, BindCapture bind) { try (Statement stmt = conn.createStatement()) { stmt.execute("set statistics xml on"); stmt.execute("begin transaction"); @@ -47,14 +42,14 @@ public class QueryPlanLoggerSqlServer extends QueryPlanLogger { } catch (SQLException e) { queryPlanLog.error("Could not log query plan", e); - + return null; } finally { stmt.execute("set statistics xml off"); } } catch (SQLException e) { queryPlanLog.error("Could not log query plan", e); + return null; } - return null; } } diff --git a/src/test/java/org/tests/query/finder/TestCustomerFinder.java b/src/test/java/org/tests/query/finder/TestCustomerFinder.java index 2423206e7..74be274b6 100644 --- a/src/test/java/org/tests/query/finder/TestCustomerFinder.java +++ b/src/test/java/org/tests/query/finder/TestCustomerFinder.java @@ -190,7 +190,7 @@ public class TestCustomerFinder extends BaseTestCase { } QueryPlanRequest request = new QueryPlanRequest(); - List plans = server().getMetaInfoManager().collectQueryPlans(request); + List plans = server().getMetaInfoManager().queryPlanCollectNow(request); assertThat(plans).isNotEmpty(); for (MetaQueryPlan plan : plans) {