com.day.cq.tagging.Tag.find leads to RuntimeNodeTraversalException
Hi everyone,
On our project, we noticed an issue with some OOTB object - com.day.cq.tagging.Tag.find.
It produces next query:
select [jcr:path], [jcr:score], * from [cq:Taggable] as a where [cq:tags] in('ctt', '/content/cq:tags/default/ctt', 'default:ctt') and isdescendantnode(a, '/')
Query explanation report
Execution plan:
[cq:Taggable] as [a] /* lucene:cqTaggableLucene(/oak:index/cqTaggableLucene) cq:tags:ctt cq:tags:/content/cq:tags/default/ctt cq:tags:default:ctt where ([a].[cq:tags] in('ctt', '/content/cq:tags/default/ctt', 'default:ctt')) and (isdescendantnode([a], [/])) */
Logs:
Parsing JCR-SQL2 statement: explain select [jcr:path], [jcr:score], * from [cq:Taggable] as a where [cq:tags] in('ctt', '/content/cq:tags/default/ctt', 'default:ctt') and isdescendantnode(a, '/')
cost using filter Filter(query=explain select [jcr:path], [jcr:score], * from [cq:Taggable] as a where [cq:tags] in('ctt', '/content/cq:tags/default/ctt', 'default:ctt') and isdescendantnode(a, '/'), path=//*, property=[cq:tags=[in(ctt, /content/cq:tags/default/ctt, default:ctt)]])
cost for reference is Infinity
cost for property is Infinity
cost for nodeType is Infinity
Applicable IndexingRule found IndexRule: cq:Taggable
cost for [/oak:index/ntBaseLucene] of type (lucene-property) with plan [lucene:ntBaseLucene(/oak:index/ntBaseLucene) cq:tags:ctt cq:tags:/content/cq:tags/default/ctt cq:tags:default:ctt sync:(cq:tags in(ctt, /content/cq:tags/default/ctt, default:ctt))] is 804880.00
cost for [/oak:index/cqTaggableLucene] of type (lucene-property) with plan [lucene:cqTaggableLucene(/oak:index/cqTaggableLucene) cq:tags:ctt cq:tags:/content/cq:tags/default/ctt cq:tags:default:ctt] is 266000.00
cost for lucene-property is Infinity
cost for aggregate lucene is Infinity
looking for plans for paths : []
cost for aggregate solr is Infinity
cost for traverse is 1.42519732E8/oak:index/cqTaggableLucene
<cqTaggableLucene
jcr:primaryType="oak:QueryIndexDefinition"
async="[async]"
compatVersion="{Long}2"
evaluatePathRestrictions="{Boolean}true"
excludedPaths="[/var,/etc/replication,/etc/workflow/instances,/jcr:system]"
indexPath="/oak:index/cqTagLucene"
name="cqTaggable"
reindex="{Boolean}false"
type="lucene">
<indexRules jcr:primaryType="nt:unstructured">
<cq:Taggable jcr:primaryType="nt:unstructured">
<properties jcr:primaryType="nt:unstructured">
<tags name="cq:tags" propertyIndex="{Boolean}true" jcr:primaryType="nt:unstructured"/>
</properties>
</cq:Taggable>
</indexRules>
</cqTaggableLucene>
Also, we have the next properties set:
- -Doak.queryLimitInMemory=500000
- -Doak.queryLimitReads=100000
Our repository is too large.
Is it really an OOTB issue or do we have some miss-configuration?
Logs:
04.05.2023 18:19:08.111 *WARN* [sling-threadpool-6c540965-9d80-41f1-86a8-74f8cb14153e-(apache-sling-job-thread-pool)-1-Tag Search Reflection(pit/searchreflectiontag/jobtopic)] org.apache.jackrabbit.oak.plugins.index.search.spi.query.FulltextIndex$FulltextPathCursor Index-Traversed 90000 nodes with filter Filter(query=select [jcr:path], [jcr:score], * from [cq:Taggable] as a where [cq:tags] in('ctt', '/content/cq:tags/default/ctt', 'default:ctt') and isdescendantnode(a, '/') /* xpath: /jcr:root//element(*, cq:Taggable)[ (@cq:tags = 'ctt' or @5644378:tags = '/content/cq:tags/default/ctt' or @5644378:tags = 'default:ctt') ] order by @6655266:score descending */, path=//*, property=[cq:tags=[in(ctt, /content/cq:tags/default/ctt, default:ctt)]])
04.05.2023 18:20:59.857 *WARN* [sling-threadpool-6c540965-9d80-41f1-86a8-74f8cb14153e-(apache-sling-job-thread-pool)-1-Tag Search Reflection(some/jobtopic)] org.apache.jackrabbit.oak.query.FilterIterators The query read or traversed more than 100000 nodes.
org.apache.jackrabbit.oak.query.RuntimeNodeTraversalException: The query read or traversed more than 100000 nodes. To avoid affecting other tasks, processing was stopped.
at org.apache.jackrabbit.oak.query.FilterIterators.checkReadLimit(FilterIterators.java:70) [org.apache.jackrabbit.oak-core:1.22.13]
at org.apache.jackrabbit.oak.plugins.index.Cursors.checkReadLimit(Cursors.java:67) [org.apache.jackrabbit.oak-core:1.22.13]
at org.apache.jackrabbit.oak.plugins.index.search.spi.query.FulltextIndex$FulltextPathCursor$1.next(FulltextIndex.java:411) [org.apache.jackrabbit.oak-lucene:1.22.13]
at org.apache.jackrabbit.oak.plugins.index.search.spi.query.FulltextIndex$FulltextPathCursor$1.next(FulltextIndex.java:392) [org.apache.jackrabbit.oak-lucene:1.22.13]
at com.google.common.collect.Iterators$7.computeNext(Iterators.java:646) [com.adobe.granite.osgi.wrapper.guava:15.0.0.0002]
at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:143) [com.adobe.granite.osgi.wrapper.guava:15.0.0.0002]
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:138) [com.adobe.granite.osgi.wrapper.guava:15.0.0.0002]
at org.apache.jackrabbit.oak.plugins.index.Cursors$PathCursor.hasNext(Cursors.java:216) [org.apache.jackrabbit.oak-core:1.22.13]
at org.apache.jackrabbit.oak.plugins.index.search.spi.query.FulltextIndex$FulltextPathCursor.hasNext(FulltextIndex.java:432) [org.apache.jackrabbit.oak-lucene:1.22.13]
at org.apache.jackrabbit.oak.query.ast.SelectorImpl.nextInternal(SelectorImpl.java:515) [org.apache.jackrabbit.oak-core:1.22.13]
at org.apache.jackrabbit.oak.query.ast.SelectorImpl.next(SelectorImpl.java:508) [org.apache.jackrabbit.oak-core:1.22.13]
at org.apache.jackrabbit.oak.query.QueryImpl$RowIterator.fetchNext(QueryImpl.java:876) [org.apache.jackrabbit.oak-core:1.22.13]
at org.apache.jackrabbit.oak.query.QueryImpl$RowIterator.hasNext(QueryImpl.java:903) [org.apache.jackrabbit.oak-core:1.22.13]
at org.apache.jackrabbit.oak.jcr.query.QueryResultImpl$4.fetch(QueryResultImpl.java:186) [org.apache.jackrabbit.oak-jcr:1.22.13]
at org.apache.jackrabbit.oak.jcr.query.QueryResultImpl$4.next(QueryResultImpl.java:212) [org.apache.jackrabbit.oak-jcr:1.22.13]
at org.apache.jackrabbit.oak.jcr.query.QueryResultImpl$4.next(QueryResultImpl.java:175) [org.apache.jackrabbit.oak-jcr:1.22.13]
at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate$SynchronizedIterator.next(SessionDelegate.java:702) [org.apache.jackrabbit.oak-jcr:1.22.13]
at org.apache.jackrabbit.oak.jcr.query.PrefetchIterator.next(PrefetchIterator.java:88) [org.apache.jackrabbit.oak-jcr:1.22.13]
at org.apache.jackrabbit.commons.iterator.RangeIteratorAdapter.next(RangeIteratorAdapter.java:152) [org.apache.jackrabbit.jackrabbit-jcr-commons:2.20.4]
at org.apache.jackrabbit.commons.iterator.RangeIteratorDecorator.next(RangeIteratorDecorator.java:92) [org.apache.jackrabbit.jackrabbit-jcr-commons:2.20.4]
at org.apache.jackrabbit.commons.iterator.NodeIteratorAdapter.nextNode(NodeIteratorAdapter.java:80) [org.apache.jackrabbit.jackrabbit-jcr-commons:2.20.4]
at com.day.cq.tagging.impl.JcrNodeResourceIterator.seek(JcrNodeResourceIterator.java:90) [com.day.cq.cq-tagging:5.12.6]
at com.day.cq.tagging.impl.JcrNodeResourceIterator.next(JcrNodeResourceIterator.java:75) [com.day.cq.cq-tagging:5.12.6]
at com.day.cq.tagging.impl.JcrNodeResourceIterator.next(JcrNodeResourceIterator.java:38) [com.day.cq.cq-tagging:5.12.6]
at MyServiceImpl.processEvents(MyServiceImpl.java:76) [my-services:1.7.67.0-10502]
at MyTagConsumer.process(MyTagConsumer.java:27) [my-services:1.7.67.0-10502]
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502) [org.apache.sling.event:4.2.24]
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351) [org.apache.sling.event:4.2.24]
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60) [org.apache.sling.event:4.2.24]
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287) [org.apache.sling.event:4.2.24]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)