diff --git a/src/main/java/io/ebean/config/ServerConfig.java b/src/main/java/io/ebean/config/ServerConfig.java
index 94add84eb..5462fbabb 100644
--- a/src/main/java/io/ebean/config/ServerConfig.java
+++ b/src/main/java/io/ebean/config/ServerConfig.java
@@ -439,6 +439,16 @@ public class ServerConfig {
*/
private boolean disableL2Cache;
+ /**
+ * The time in millis used to determine when a query is alerted for being slow.
+ */
+ private long slowQueryMillis;
+
+ /**
+ * The listener for processing slow query events.
+ */
+ private SlowQueryListener slowQueryListener;
+
/**
* Construct a Server Configuration for programmatically creating an EbeanServer.
*/
@@ -446,6 +456,34 @@ public class ServerConfig {
}
+ /**
+ * Return the slow query time in millis.
+ */
+ public long getSlowQueryMillis() {
+ return slowQueryMillis;
+ }
+
+ /**
+ * Set the slow query time in millis.
+ */
+ public void setSlowQueryMillis(long slowQueryMillis) {
+ this.slowQueryMillis = slowQueryMillis;
+ }
+
+ /**
+ * Return the slow query event listener.
+ */
+ public SlowQueryListener getSlowQueryListener() {
+ return slowQueryListener;
+ }
+
+ /**
+ * Set the slow query event listener.
+ */
+ public void setSlowQueryListener(SlowQueryListener slowQueryListener) {
+ this.slowQueryListener = slowQueryListener;
+ }
+
/**
* Put a service object into configuration such that it can be passed to a plugin.
*
@@ -2534,6 +2572,7 @@ public class ServerConfig {
dbTypeConfig.setGeometrySRID(srid);
}
+ slowQueryMillis = p.getLong("slowQueryMillis", slowQueryMillis);
docStoreOnly = p.getBoolean("docStoreOnly", docStoreOnly);
disableL2Cache = p.getBoolean("disableL2Cache", disableL2Cache);
explicitTransactionBeginMode = p.getBoolean("explicitTransactionBeginMode", explicitTransactionBeginMode);
diff --git a/src/main/java/io/ebean/config/SlowQueryEvent.java b/src/main/java/io/ebean/config/SlowQueryEvent.java
new file mode 100644
index 000000000..6afd71502
--- /dev/null
+++ b/src/main/java/io/ebean/config/SlowQueryEvent.java
@@ -0,0 +1,59 @@
+package io.ebean.config;
+
+import io.ebean.bean.ObjectGraphNode;
+
+/**
+ * Slow query event.
+ */
+public class SlowQueryEvent {
+
+ private final String sql;
+
+ private final long timeMillis;
+
+ private final int rowCount;
+
+ private final ObjectGraphNode originNode;
+
+ /**
+ * Construct with the SQL and execution time in millis.
+ */
+ public SlowQueryEvent(String sql, long timeMillis, int rowCount, ObjectGraphNode originNode) {
+ this.sql = sql;
+ this.timeMillis = timeMillis;
+ this.rowCount = rowCount;
+ this.originNode = originNode;
+ }
+
+ /**
+ * Return the SQL for the slow query.
+ */
+ public String getSql() {
+ return sql;
+ }
+
+ /**
+ * Return the execution time in millis.
+ */
+ public long getTimeMillis() {
+ return timeMillis;
+ }
+
+ /**
+ * Return the total row count associated with the query.
+ */
+ public int getRowCount() {
+ return rowCount;
+ }
+
+ /**
+ * Return the origin point for the root query.
+ *
+ * Typically the originNode.getOriginQueryPoint().getFirstStackElement() provides the stack line that
+ * shows the code that invoked the query.
+ *
+ */
+ public ObjectGraphNode getOriginNode() {
+ return originNode;
+ }
+}
diff --git a/src/main/java/io/ebean/config/SlowQueryListener.java b/src/main/java/io/ebean/config/SlowQueryListener.java
new file mode 100644
index 000000000..19231d854
--- /dev/null
+++ b/src/main/java/io/ebean/config/SlowQueryListener.java
@@ -0,0 +1,13 @@
+package io.ebean.config;
+
+/**
+ * Listener for slow query events.
+ */
+@FunctionalInterface
+public interface SlowQueryListener {
+
+ /**
+ * Process a slow query event.
+ */
+ void process(SlowQueryEvent event);
+}
diff --git a/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java b/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java
index 7bd6d64ee..8cf77b69a 100644
--- a/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java
+++ b/src/main/java/io/ebeaninternal/api/SpiEbeanServer.java
@@ -205,4 +205,9 @@ public interface SpiEbeanServer extends EbeanServer, BeanLoader, BeanCollectionL
* Return the DataTimeZone to use when reading/writing timestamps via JDBC.
*/
DataTimeZone getDataTimeZone();
+
+ /**
+ * Check for slow query event.
+ */
+ void slowQueryCheck(long executionTimeMicros, int rowCount, SpiQuery query);
}
diff --git a/src/main/java/io/ebeaninternal/server/core/DefaultServer.java b/src/main/java/io/ebeaninternal/server/core/DefaultServer.java
index 3292e5022..2ea0ac091 100644
--- a/src/main/java/io/ebeaninternal/server/core/DefaultServer.java
+++ b/src/main/java/io/ebeaninternal/server/core/DefaultServer.java
@@ -20,8 +20,6 @@ import io.ebean.SqlRow;
import io.ebean.SqlUpdate;
import io.ebean.Transaction;
import io.ebean.TransactionCallback;
-import io.ebean.TxCallable;
-import io.ebean.TxRunnable;
import io.ebean.TxScope;
import io.ebean.Update;
import io.ebean.UpdateQuery;
@@ -43,6 +41,8 @@ import io.ebean.config.TenantMode;
import io.ebean.config.dbplatform.DatabasePlatform;
import io.ebean.dbmigration.DdlGenerator;
import io.ebean.event.BeanPersistController;
+import io.ebean.config.SlowQueryEvent;
+import io.ebean.config.SlowQueryListener;
import io.ebean.event.readaudit.ReadAuditLogger;
import io.ebean.event.readaudit.ReadAuditPrepare;
import io.ebean.meta.MetaInfoManager;
@@ -205,6 +205,10 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer {
private final boolean collectQueryStatsByNode;
+ private final long slowQueryMicros;
+
+ private final SlowQueryListener slowQueryListener;
+
/**
* Cache used to collect statistics based on ObjectGraphNode (used to highlight lazy loading origin points).
*/
@@ -230,6 +234,8 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer {
this.encryptKeyManager = serverConfig.getEncryptKeyManager();
this.defaultPersistenceContextScope = serverConfig.getPersistenceContextScope();
this.currentTenantProvider = serverConfig.getCurrentTenantProvider();
+ this.slowQueryMicros = config.getSlowQueryMicros();
+ this.slowQueryListener = config.getSlowQueryListener();
this.beanDescriptorManager = config.getBeanDescriptorManager();
beanDescriptorManager.setEbeanServer(this);
@@ -2221,4 +2227,12 @@ public final class DefaultServer implements SpiServer, SpiEbeanServer {
}
}
+ @Override
+ public void slowQueryCheck(long timeMicros, int rowCount, SpiQuery query) {
+ if (timeMicros > slowQueryMicros) {
+ if (slowQueryListener != null) {
+ slowQueryListener.process(new SlowQueryEvent(query.getGeneratedSql(), timeMicros / 1000L, rowCount, query.getParentNode()));
+ }
+ }
+ }
}
diff --git a/src/main/java/io/ebeaninternal/server/core/DefaultSlowQueryListener.java b/src/main/java/io/ebeaninternal/server/core/DefaultSlowQueryListener.java
new file mode 100644
index 000000000..e6e02833e
--- /dev/null
+++ b/src/main/java/io/ebeaninternal/server/core/DefaultSlowQueryListener.java
@@ -0,0 +1,26 @@
+package io.ebeaninternal.server.core;
+
+import io.ebean.bean.ObjectGraphNode;
+import io.ebean.config.SlowQueryEvent;
+import io.ebean.config.SlowQueryListener;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+/**
+ * Default slow query listener implementation that logs a warning message.
+ */
+class DefaultSlowQueryListener implements SlowQueryListener {
+
+ private static final Logger log = LoggerFactory.getLogger("io.ebean.SlowQuery");
+
+ @Override
+ public void process(SlowQueryEvent event) {
+
+ String firstStack = "";
+ ObjectGraphNode node = event.getOriginNode();
+ if (node != null) {
+ firstStack = node.getOriginQueryPoint().getFirstStackElement();
+ }
+ log.warn("Slow query warning - millis:{} rows:{} caller[{}] sql[{}]", event.getTimeMillis(), event.getRowCount(), firstStack, event.getSql());
+ }
+}
diff --git a/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java b/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java
index bc8c19964..2141012d9 100644
--- a/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java
+++ b/src/main/java/io/ebeaninternal/server/core/InternalConfiguration.java
@@ -8,6 +8,7 @@ import io.ebean.config.ExternalTransactionManager;
import io.ebean.config.ServerConfig;
import io.ebean.config.dbplatform.DatabasePlatform;
import io.ebean.config.dbplatform.DbHistorySupport;
+import io.ebean.config.SlowQueryListener;
import io.ebean.event.changelog.ChangeLogListener;
import io.ebean.event.changelog.ChangeLogPrepare;
import io.ebean.event.changelog.ChangeLogRegister;
@@ -432,4 +433,30 @@ public class InternalConfiguration {
public ServerCacheManager cache() {
return new DefaultCacheAdapter(cacheManager);
}
+
+ /**
+ * Return the slow query warning limit in micros.
+ */
+ long getSlowQueryMicros() {
+ long millis = serverConfig.getSlowQueryMillis();
+ return (millis < 1) ? Long.MAX_VALUE : millis * 1000L;
+ }
+
+ /**
+ * Return the SlowQueryListener with a default that logs a warning message.
+ */
+ SlowQueryListener getSlowQueryListener() {
+ long millis = serverConfig.getSlowQueryMillis();
+ if (millis < 1) {
+ return null;
+ }
+ SlowQueryListener listener = serverConfig.getSlowQueryListener();
+ if (listener == null) {
+ listener = serverConfig.service(SlowQueryListener.class);
+ if (listener == null) {
+ listener = new DefaultSlowQueryListener();
+ }
+ }
+ return listener;
+ }
}
diff --git a/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java b/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java
index 778f2a480..71242c64b 100644
--- a/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java
+++ b/src/main/java/io/ebeaninternal/server/core/OrmQueryRequest.java
@@ -597,4 +597,11 @@ public final class OrmQueryRequest extends BeanRequest implements BeanQueryRe
public Object getTenantId() {
return (transaction == null) ? null : transaction.getTenantId();
}
+
+ /**
+ * Check for slow query event.
+ */
+ public void slowQueryCheck(long executionTimeMicros, int rowCount) {
+ ebeanServer.slowQueryCheck(executionTimeMicros, rowCount, query);
+ }
}
diff --git a/src/main/java/io/ebeaninternal/server/query/CQuery.java b/src/main/java/io/ebeaninternal/server/query/CQuery.java
index fdb0dd692..eca6e71ec 100644
--- a/src/main/java/io/ebeaninternal/server/query/CQuery.java
+++ b/src/main/java/io/ebeaninternal/server/query/CQuery.java
@@ -36,7 +36,6 @@ import java.util.ArrayList;
import java.util.Collection;
import java.util.List;
import java.util.Map;
-import java.util.concurrent.TimeUnit;
/**
* An object that represents a SqlSelect statement.
@@ -561,16 +560,28 @@ public class CQuery implements DbReadContext, CancelableQuery {
return collection;
}
+ /**
+ * Update execution stats and check for slow query.
+ */
void updateExecutionStatistics() {
- try {
- long exeNano = System.nanoTime() - startNano;
- executionTimeMicros = TimeUnit.NANOSECONDS.toMicros(exeNano);
+ updateStatistics();
+ request.slowQueryCheck(executionTimeMicros, rowCount);
+ }
+ /**
+ * Update execution stats but skip slow query check as expected large query.
+ */
+ void updateExecutionStatisticsIterator() {
+ updateStatistics();
+ }
+
+ private void updateStatistics() {
+ try {
+ executionTimeMicros = (System.nanoTime() - startNano) / 1000L;
if (autoTuneProfiling) {
profilingListener.collectQueryInfo(objectGraphNode, loadedBeanCount, executionTimeMicros);
}
queryPlan.executionTime(loadedBeanCount, executionTimeMicros, objectGraphNode);
-
} catch (Exception e) {
logger.error("Error updating execution statistics", e);
}
diff --git a/src/main/java/io/ebeaninternal/server/query/CQueryFetchSingleAttribute.java b/src/main/java/io/ebeaninternal/server/query/CQueryFetchSingleAttribute.java
index 91be22f35..088fba985 100644
--- a/src/main/java/io/ebeaninternal/server/query/CQueryFetchSingleAttribute.java
+++ b/src/main/java/io/ebeaninternal/server/query/CQueryFetchSingleAttribute.java
@@ -50,7 +50,7 @@ class CQueryFetchSingleAttribute {
private String bindLog;
- private int executionTimeMicros;
+ private long executionTimeMicros;
private int rowCount;
@@ -91,20 +91,17 @@ class CQueryFetchSingleAttribute {
long startNano = System.nanoTime();
try {
-
prepareExecute();
List