You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-commits@jackrabbit.apache.org by th...@apache.org on 2023/06/30 14:24:43 UTC
[jackrabbit-oak] 01/01: OAK-10333 Improved logging for queries that that traverse more than 10'000 nodes
This is an automated email from the ASF dual-hosted git repository.
thomasm pushed a commit to branch OAK-10333
in repository https://gitbox.apache.org/repos/asf/jackrabbit-oak.git
commit 6016723174ee13d3d3911dc53258bacb333ab16b
Author: Thomas Mueller <th...@apache.org>
AuthorDate: Fri Jun 30 16:24:29 2023 +0200
OAK-10333 Improved logging for queries that that traverse more than 10'000 nodes
---
.../oak/plugins/index/cursor/TraversingCursor.java | 13 +++++++++----
.../index/property/strategy/ContentMirrorStoreStrategy.java | 12 +++++++++---
.../jackrabbit/oak/plugins/index/lucene/LuceneIndex.java | 7 ++++++-
.../oak/plugins/index/search/spi/query/FulltextIndex.java | 7 ++++++-
4 files changed, 30 insertions(+), 9 deletions(-)
diff --git a/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/cursor/TraversingCursor.java b/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/cursor/TraversingCursor.java
index cb1b8762f5..6bf7840193 100644
--- a/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/cursor/TraversingCursor.java
+++ b/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/cursor/TraversingCursor.java
@@ -159,10 +159,15 @@ class TraversingCursor extends AbstractCursor {
readCount++;
if (readCount % 1000 == 0) {
- FilterIterators.checkReadLimit(readCount, settings);
- String caller = IndexUtils.getCaller(this.settings.getIgnoredClassNamesInCallTrace());
- LOG.warn("Traversed {} nodes with filter {} called by {}; consider creating an index or changing the query" ,
- readCount, filter, caller);
+ if (readCount == 20000) {
+ LOG.warn("Traversed {} nodes with filter {}; consider creating an index or changing the query",
+ readCount, filter, new Exception("call stack"));
+ } else {
+ FilterIterators.checkReadLimit(readCount, settings);
+ String caller = IndexUtils.getCaller(this.settings.getIgnoredClassNamesInCallTrace());
+ LOG.warn("Traversed {} nodes with filter {} called by {}; consider creating an index or changing the query",
+ readCount, filter, caller);
+ }
}
NodeState node = entry.getNodeState();
diff --git a/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/property/strategy/ContentMirrorStoreStrategy.java b/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/property/strategy/ContentMirrorStoreStrategy.java
index 3f2346d93e..35b56348a5 100644
--- a/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/property/strategy/ContentMirrorStoreStrategy.java
+++ b/oak-core/src/main/java/org/apache/jackrabbit/oak/plugins/index/property/strategy/ContentMirrorStoreStrategy.java
@@ -457,9 +457,15 @@ public class ContentMirrorStoreStrategy implements IndexStoreStrategy {
readCount++;
if (readCount % TRAVERSING_WARN == 0) {
FilterIterators.checkReadLimit(readCount, settings);
- String caller = IndexUtils.getCaller(settings.getIgnoredClassNamesInCallTrace());
- LOG.warn("Index-Traversed {} nodes ({} index entries) using index {} with filter {}, caller {}",
- readCount, intermediateNodeReadCount, indexName, filter, caller);
+ if (readCount == 2 * TRAVERSING_WARN) {
+ LOG.warn("Index-Traversed {} nodes ({} index entries) using index {} with filter {}",
+ readCount, intermediateNodeReadCount, indexName, filter,
+ new Exception("call stack"));
+ } else {
+ String caller = IndexUtils.getCaller(settings.getIgnoredClassNamesInCallTrace());
+ LOG.warn("Index-Traversed {} nodes ({} index entries) using index {} with filter {}, caller {}",
+ readCount, intermediateNodeReadCount, indexName, filter, caller);
+ }
}
return;
} else {
diff --git a/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndex.java b/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndex.java
index 389c90ba59..045f47fd6e 100644
--- a/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndex.java
+++ b/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndex.java
@@ -1180,7 +1180,12 @@ public class LuceneIndex implements AdvanceFulltextQueryIndex {
readCount++;
if (readCount % TRAVERSING_WARNING == 0) {
Cursors.checkReadLimit(readCount, settings);
- LOG.warn("Index-Traversed {} nodes with filter {}", readCount, filter);
+ if (readCount == 2 * TRAVERSING_WARNING) {
+ LOG.warn("Index-Traversed {} nodes with filter {}", readCount, filter,
+ new Exception("call stack"));
+ } else {
+ LOG.warn("Index-Traversed {} nodes with filter {}", readCount, filter);
+ }
}
return currentRow.path;
}
diff --git a/oak-search/src/main/java/org/apache/jackrabbit/oak/plugins/index/search/spi/query/FulltextIndex.java b/oak-search/src/main/java/org/apache/jackrabbit/oak/plugins/index/search/spi/query/FulltextIndex.java
index a7e4d06813..c0807ad676 100644
--- a/oak-search/src/main/java/org/apache/jackrabbit/oak/plugins/index/search/spi/query/FulltextIndex.java
+++ b/oak-search/src/main/java/org/apache/jackrabbit/oak/plugins/index/search/spi/query/FulltextIndex.java
@@ -429,7 +429,12 @@ public abstract class FulltextIndex implements AdvancedQueryIndex, QueryIndex, N
readCount++;
if (readCount % TRAVERSING_WARNING == 0) {
Cursors.checkReadLimit(readCount, settings);
- log.warn("Index-Traversed {} nodes with filter {}", readCount, plan.getFilter());
+ if (readCount == 2 * TRAVERSING_WARNING) {
+ log.warn("Index-Traversed {} nodes with filter {}", readCount, plan.getFilter(),
+ new Exception("call stack"));
+ } else {
+ log.warn("Index-Traversed {} nodes with filter {}", readCount, plan.getFilter());
+ }
}
return currentRow.path;
}