Author: thomasm
Date: Fri May 17 14:28:38 2019
New Revision: 1859436
URL: http://svn.apache.org/viewvc?rev=1859436&view=rev
Log:
OAK-8309 SLOW_QUERY_COUNT don't get updated for each slow query
Added:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/RuntimeNodeTraversalException.java
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/spi/query/SlowQueryMetricTest.java
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/FilterIterators.java
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/ast/SelectorImpl.java
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/stats/QueryStatsData.java
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/ReopenedLuceneIndexTest.java
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/FilterIterators.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/FilterIterators.java?rev=1859436&r1=1859435&r2=1859436&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/FilterIterators.java
(original)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/FilterIterators.java
Fri May 17 14:28:38 2019
@@ -48,7 +48,7 @@ public class FilterIterators {
String message = "The query read more than " +
maxMemoryEntries + " nodes in memory.";
UnsupportedOperationException e = new
UnsupportedOperationException(
- message +
+ message +
" To avoid running out of memory, processing was
stopped.");
LOG.warn(message, e);
throw e;
@@ -60,14 +60,14 @@ public class FilterIterators {
*
* @param count the number of read operations
* @param settings the query engine settings
- * @throws UnsupportedOperationException if the limit was exceeded
+ * @throws RuntimeNodeTraversalException if the limit was exceeded
*/
public static void checkReadLimit(long count, QueryLimits settings) {
long maxReadEntries = settings.getLimitReads();
if (count > maxReadEntries) {
String message = "The query read or traversed more than " +
maxReadEntries + " nodes.";
- UnsupportedOperationException e = new
UnsupportedOperationException(
+ RuntimeNodeTraversalException e = new
RuntimeNodeTraversalException(
message +
" To avoid affecting other tasks, processing was
stopped.");
LOG.warn(message, e);
Added:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/RuntimeNodeTraversalException.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/RuntimeNodeTraversalException.java?rev=1859436&view=auto
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/RuntimeNodeTraversalException.java
(added)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/RuntimeNodeTraversalException.java
Fri May 17 14:28:38 2019
@@ -0,0 +1,27 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.jackrabbit.oak.query;
+
+/**
+ * The exception thrown when traversing too many entries in the result.
+ */
+public class RuntimeNodeTraversalException extends
UnsupportedOperationException {
+
+ public RuntimeNodeTraversalException(String message) {
+ super(message);
+ }
+}
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/ast/SelectorImpl.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/ast/SelectorImpl.java?rev=1859436&r1=1859435&r2=1859436&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/ast/SelectorImpl.java
(original)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/ast/SelectorImpl.java
Fri May 17 14:28:38 2019
@@ -38,8 +38,10 @@ import org.apache.jackrabbit.oak.core.Im
import org.apache.jackrabbit.oak.plugins.memory.PropertyBuilder;
import org.apache.jackrabbit.oak.plugins.tree.TreeUtil;
import org.apache.jackrabbit.oak.query.ExecutionContext;
+import org.apache.jackrabbit.oak.query.QueryEngineSettings;
import org.apache.jackrabbit.oak.query.QueryImpl;
import org.apache.jackrabbit.oak.query.QueryOptions;
+import org.apache.jackrabbit.oak.query.RuntimeNodeTraversalException;
import org.apache.jackrabbit.oak.spi.query.fulltext.FullTextExpression;
import org.apache.jackrabbit.oak.query.index.FilterImpl;
import org.apache.jackrabbit.oak.query.plan.ExecutionPlan;
@@ -56,6 +58,8 @@ import org.apache.jackrabbit.oak.spi.que
import org.apache.jackrabbit.oak.spi.state.NodeState;
import org.apache.jackrabbit.oak.stats.StatsOptions;
import org.apache.jackrabbit.oak.stats.TimerStats;
+import org.apache.jackrabbit.oak.stats.CounterStats;
+import org.apache.jackrabbit.oak.stats.HistogramStats;
import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;
import org.slf4j.Logger;
@@ -75,6 +79,11 @@ public class SelectorImpl extends Source
// The sample rate. Must be a power of 2.
private static final Long TIMER_SAMPLE_RATE =
Long.getLong("oak.query.timerSampleRate", 0x100);
+ private static final long SLOW_QUERY_HISTOGRAM = 1;
+ private static final long TOTAL_QUERY_HISTOGRAM = 0;
+ private static final String SLOW_QUERY_PERCENTILE_METRICS_NAME =
"SLOW_QUERY_PERCENTILE_METRICS";
+ private static final String SLOW_QUERY_COUNT_NAME = "SLOW_QUERY_COUNT";
+
private static long timerSampleCounter;
// TODO possibly support using multiple indexes (using index intersection
/ index merge)
@@ -171,6 +180,8 @@ public class SelectorImpl extends Source
private CachedTree cachedTree;
+ private boolean updateTotalQueryHistogram = true;
+
public SelectorImpl(NodeTypeInfo nodeTypeInfo, String selectorName) {
this.nodeTypeInfo = checkNotNull(nodeTypeInfo);
this.selectorName = checkNotNull(selectorName);
@@ -503,8 +514,15 @@ public class SelectorImpl extends Source
private boolean nextInternal() {
while (cursor != null && cursor.hasNext()) {
scanCount++;
- query.getQueryExecutionStats().scan(1, scanCount,
query.getSettings());
- currentRow = cursor.next();
+ query.getQueryExecutionStats().scan(1, scanCount);
+ try {
+ totalQueryStats(query.getSettings());
+ currentRow = cursor.next();
+ } catch (RuntimeNodeTraversalException e) {
+ addSlowQueryStats(query.getSettings());
+ LOG.warn(e.getMessage() + " for query " +
query.getStatement());
+ throw e;
+ }
if (isParent) {
// we must not check whether the _parent_ is readable
// for joins of type
@@ -541,6 +559,21 @@ public class SelectorImpl extends Source
return false;
}
+ private void totalQueryStats(QueryEngineSettings queryEngineSettings) {
+ if (updateTotalQueryHistogram) {
+ updateTotalQueryHistogram = false;
+ HistogramStats histogramStats =
queryEngineSettings.getStatisticsProvider().getHistogram(SLOW_QUERY_PERCENTILE_METRICS_NAME,
StatsOptions.METRICS_ONLY);
+ histogramStats.update(TOTAL_QUERY_HISTOGRAM);
+ }
+ }
+
+ private void addSlowQueryStats(QueryEngineSettings queryEngineSettings) {
+ HistogramStats histogramStats =
queryEngineSettings.getStatisticsProvider().getHistogram(SLOW_QUERY_PERCENTILE_METRICS_NAME,
StatsOptions.METRICS_ONLY);
+ histogramStats.update(SLOW_QUERY_HISTOGRAM);
+ CounterStats slowQueryCounter =
queryEngineSettings.getStatisticsProvider().getCounterStats(SLOW_QUERY_COUNT_NAME,
StatsOptions.METRICS_ONLY);
+ slowQueryCounter.inc();
+ }
+
private boolean evaluateCurrentRow() {
if (currentRow.isVirtualRow()) {
//null path implies that all checks are already done -- we just
need to pass it through
Modified:
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/stats/QueryStatsData.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/stats/QueryStatsData.java?rev=1859436&r1=1859435&r2=1859436&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/stats/QueryStatsData.java
(original)
+++
jackrabbit/oak/trunk/oak-core/src/main/java/org/apache/jackrabbit/oak/query/stats/QueryStatsData.java
Fri May 17 14:28:38 2019
@@ -17,10 +17,6 @@
package org.apache.jackrabbit.oak.query.stats;
import org.apache.jackrabbit.oak.commons.json.JsopBuilder;
-import org.apache.jackrabbit.oak.query.QueryEngineSettings;
-import org.apache.jackrabbit.oak.stats.CounterStats;
-import org.apache.jackrabbit.oak.stats.HistogramStats;
-import org.apache.jackrabbit.oak.stats.StatsOptions;
public class QueryStatsData {
@@ -47,8 +43,6 @@ public class QueryStatsData {
private long readNanos;
private long maxTimeNanos;
private boolean captureStackTraces;
- private boolean isSlowQuery = false;
- private boolean updateTotalQueryHistogram = true;
public QueryStatsData(String query, String language) {
this.query = query;
@@ -183,22 +177,9 @@ public class QueryStatsData {
maxTimeNanos = Math.max(maxTimeNanos, time);
}
- public void scan(long count, long max, QueryEngineSettings
queryEngineSettings) {
+ public void scan(long count, long max) {
totalRowsScanned += count;
maxRowsScanned = Math.max(maxRowsScanned, max);
- long maxScannedLimit = Math.min(SLOW_QUERY_LIMIT_SCANNED,
queryEngineSettings.getLimitReads());
- if (updateTotalQueryHistogram) {
- updateTotalQueryHistogram = false;
- HistogramStats histogramStats =
queryEngineSettings.getStatisticsProvider().getHistogram(SLOW_QUERY_PERCENTILE_METRICS_NAME,
StatsOptions.METRICS_ONLY);
- histogramStats.update(TOTAL_QUERY_HISTOGRAM);
- }
- if (totalRowsScanned >= maxScannedLimit && !isSlowQuery) {
- isSlowQuery = true;
- HistogramStats histogramStats =
queryEngineSettings.getStatisticsProvider().getHistogram(SLOW_QUERY_PERCENTILE_METRICS_NAME,
StatsOptions.METRICS_ONLY);
- histogramStats.update(SLOW_QUERY_HISTOGRAM);
- CounterStats slowQueryCounter =
queryEngineSettings.getStatisticsProvider().getCounterStats(SLOW_QUERY_COUNT_NAME,
StatsOptions.METRICS_ONLY);
- slowQueryCounter.inc();
- }
}
}
Added:
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/spi/query/SlowQueryMetricTest.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/spi/query/SlowQueryMetricTest.java?rev=1859436&view=auto
==============================================================================
---
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/spi/query/SlowQueryMetricTest.java
(added)
+++
jackrabbit/oak/trunk/oak-core/src/test/java/org/apache/jackrabbit/oak/spi/query/SlowQueryMetricTest.java
Fri May 17 14:28:38 2019
@@ -0,0 +1,142 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing,
+ * software distributed under the License is distributed on an
+ * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+ * KIND, either express or implied. See the License for the
+ * specific language governing permissions and limitations
+ * under the License.
+ */
+package org.apache.jackrabbit.oak.spi.query;
+
+import org.apache.jackrabbit.oak.InitialContent;
+import org.apache.jackrabbit.oak.Oak;
+import org.apache.jackrabbit.oak.api.ContentRepository;
+import org.apache.jackrabbit.oak.api.ContentSession;
+import org.apache.jackrabbit.oak.api.QueryEngine;
+import org.apache.jackrabbit.oak.api.Result;
+import org.apache.jackrabbit.oak.api.ResultRow;
+import org.apache.jackrabbit.oak.api.Root;
+import org.apache.jackrabbit.oak.api.Tree;
+import org.apache.jackrabbit.oak.commons.concurrent.ExecutorCloser;
+import org.apache.jackrabbit.oak.plugins.metric.MetricStatisticsProvider;
+import org.apache.jackrabbit.oak.query.QueryEngineSettings;
+import org.apache.jackrabbit.oak.query.RuntimeNodeTraversalException;
+import org.apache.jackrabbit.oak.spi.security.OpenSecurityProvider;
+import org.apache.jackrabbit.oak.spi.whiteboard.DefaultWhiteboard;
+import org.apache.jackrabbit.oak.spi.whiteboard.Whiteboard;
+import org.apache.jackrabbit.oak.stats.CounterStats;
+import org.apache.jackrabbit.oak.stats.HistogramStats;
+import org.apache.jackrabbit.oak.stats.StatisticsProvider;
+import org.apache.jackrabbit.oak.stats.StatsOptions;
+import org.junit.After;
+import org.junit.Assert;
+import org.junit.Before;
+import org.junit.Test;
+
+import javax.jcr.query.Query;
+import java.lang.management.ManagementFactory;
+import java.text.ParseException;
+import java.util.Collections;
+import java.util.concurrent.Executors;
+import java.util.concurrent.ScheduledExecutorService;
+
+/**
+ * {@code SlowQueryMetricTest} contains slowQuery metrics related tests.
+ */
+public class SlowQueryMetricTest {
+
+ private ContentRepository repository;
+ private ScheduledExecutorService executor =
Executors.newSingleThreadScheduledExecutor();
+ private MetricStatisticsProvider statsProvider =
+ new
MetricStatisticsProvider(ManagementFactory.getPlatformMBeanServer(), executor);
+ private QueryEngineSettings queryEngineSettings = new
QueryEngineSettings(statsProvider);
+
+
+ Oak oak = null;
+
+ @Before
+ public void setUp() {
+ queryEngineSettings.setLimitReads(11);
+ Whiteboard whiteboard = new DefaultWhiteboard();
+ whiteboard.register(StatisticsProvider.class, statsProvider,
Collections.emptyMap());
+ oak = new Oak().with(new OpenSecurityProvider()).with(new
InitialContent()).with(queryEngineSettings).with(whiteboard);
+ repository = oak.createContentRepository();
+ }
+
+ @After
+ public void tearDown() {
+ repository = null;
+ statsProvider.close();
+ new ExecutorCloser(executor).close();
+ }
+
+ private String SLOW_QUERY_COUNT_NAME = "SLOW_QUERY_COUNT";
+ private String SLOW_QUERY_PERCENTILE_METRICS_NAME =
"SLOW_QUERY_PERCENTILE_METRICS";
+
+ @Test
+ public void queryOnStableRevision() throws Exception {
+ long maxReadEntries = 1000;//we check for max traversals for each 1000
node reads, see Cursors.java -> fetchNext()
+ ContentSession s = repository.login(null, null);
+ Root r = s.getLatestRoot();
+ Tree t = r.getTree("/").addChild("test");
+ for (int i = 0; i < maxReadEntries + 1; i++) {
+ t.addChild("node" + i).setProperty("jcr:primaryType", "nt:base");
+ }
+ r.commit();
+ ContentSession s2 = repository.login(null, null);
+ Root r2 = s2.getLatestRoot();
+ CounterStats slowQueryCounter =
queryEngineSettings.getStatisticsProvider().getCounterStats(SLOW_QUERY_COUNT_NAME,
StatsOptions.METRICS_ONLY);
+ HistogramStats histogramStats =
queryEngineSettings.getStatisticsProvider().getHistogram(SLOW_QUERY_PERCENTILE_METRICS_NAME,
StatsOptions.METRICS_ONLY);
+ long totalQueryCount = histogramStats.getCount();
+ long slowQueryCount = slowQueryCounter.getCount();
+ Assert.assertEquals(totalQueryCount, 0);
+ Assert.assertEquals(slowQueryCount, 0);
+
+ Result result = executeQuery(r2, "test/node1//element(*, nt:base)");
+ for (ResultRow rr : result.getRows()) {
+ }
+ totalQueryCount = histogramStats.getCount();
+ slowQueryCount = slowQueryCounter.getCount();
+ Assert.assertEquals(totalQueryCount, 1);
+ Assert.assertEquals(slowQueryCount, 0);
+
+ executeAndAssertSlowQuery(r2, queryEngineSettings);
+ }
+
+ private void executeAndAssertSlowQuery(Root r2, QueryEngineSettings
queryEngineSettings) throws ParseException {
+ Result result = executeQuery(r2, "test//element(*, nt:base)");
+ CounterStats slowQueryCounter =
queryEngineSettings.getStatisticsProvider().getCounterStats(SLOW_QUERY_COUNT_NAME,
StatsOptions.METRICS_ONLY);
+ HistogramStats histogramStats =
queryEngineSettings.getStatisticsProvider().getHistogram(SLOW_QUERY_PERCENTILE_METRICS_NAME,
StatsOptions.METRICS_ONLY);
+ long initialSlowQueryCounter = slowQueryCounter.getCount();
+ long initialHistogramCounter = histogramStats.getCount();
+ try {
+ for (ResultRow rr : result.getRows()) {
+ }
+ } catch (RuntimeNodeTraversalException e) {
+
+ /*
+ count increased by 2. one for being a query and one for being
slow query. Added twice to get histogram percentile info
+ */
+ Assert.assertEquals(histogramStats.getCount(),
initialHistogramCounter + 2);
+ Assert.assertEquals(slowQueryCounter.getCount(),
initialSlowQueryCounter + 1);
+ return;
+ }
+ Assert.fail("Unable to catch max Node Traversal limit breach");
+ }
+
+ private Result executeQuery(Root r2, String queryString) throws
ParseException {
+ Result result = r2.getQueryEngine().executeQuery(queryString,
Query.XPATH,
+ QueryEngine.NO_BINDINGS, QueryEngine.NO_MAPPINGS);
+ return result;
+ }
+}
Modified:
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/ReopenedLuceneIndexTest.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/ReopenedLuceneIndexTest.java?rev=1859436&r1=1859435&r2=1859436&view=diff
==============================================================================
---
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/ReopenedLuceneIndexTest.java
(original)
+++
jackrabbit/oak/trunk/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/ReopenedLuceneIndexTest.java
Fri May 17 14:28:38 2019
@@ -33,6 +33,7 @@ import org.apache.jackrabbit.oak.plugins
import org.apache.jackrabbit.oak.plugins.index.search.IndexDefinition;
import org.apache.jackrabbit.oak.plugins.memory.MemoryNodeStore;
import org.apache.jackrabbit.oak.query.QueryEngineSettings;
+import org.apache.jackrabbit.oak.query.RuntimeNodeTraversalException;
import org.apache.jackrabbit.oak.spi.commit.Observer;
import org.apache.jackrabbit.oak.spi.query.QueryIndexProvider;
import org.apache.jackrabbit.oak.spi.security.OpenSecurityProvider;
@@ -135,7 +136,7 @@ public class ReopenedLuceneIndexTest {
@Test
public void resultSizeAboveLimitCompatV1() throws Exception {
- thrown.expect(UnsupportedOperationException.class);
+ thrown.expect(RuntimeNodeTraversalException.class);
thrown.expectMessage(StringContains.containsString("The query read or
traversed more than " + READ_LIMIT + " nodes. To avoid affecting other tasks,
processing was stopped."));
// Add more data such that the query genuinely supasses query limit
@@ -146,7 +147,7 @@ public class ReopenedLuceneIndexTest {
@Test
public void resultSizeAboveLimitCompatV2() throws Exception {
- thrown.expect(UnsupportedOperationException.class);
+ thrown.expect(RuntimeNodeTraversalException.class);
thrown.expectMessage(StringContains.containsString("The query read or
traversed more than " + READ_LIMIT + " nodes. To avoid affecting other tasks,
processing was stopped."));
// Add more data such that the query genuinely supasses query limit
