From 8a263d243c06be324b6147eed6eae4496e6b8f72 Mon Sep 17 00:00:00 2001 From: rob bygrave Date: Tue, 24 Dec 2019 00:29:46 +1300 Subject: [PATCH] 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) {