Troubleshooting Slow Queries in AEM


Statement: Slow Query Classifications


Solution :



Slow Query Classifications



There are 3 main classifications of slow queries in AEM, listed by severity:
  1. Index-less queries
    • Queries that do not resolve to an index and traverse the JCR's contents to collect results
  2. Poorly restricted (or scoped) queries
    • Queries that resolve to an index, but must traverse all index entries to collect results
  3. Large result set queries
    • Queries that return very large numbers of results.

Note: 
  • The first 2 classifications of queries (index-less and poorly restricted) are slow, because they force the Oak query engine to inspect each potential result (content node or index entry) to identify which belong in the actual result set. 
  • In AEM 6.3, by default, when a traversal of 100,000 is reached, the query fails and throws an exception. 
  • This limit does not exist by default in AEM versions prior to AEM 6.3, but can be set via the Apache Jackrabbit Query Engine Settings OSGi configuration and QueryEngineSettings JMX bean (property LimitReads).

1. Detecting Index-less Queries



During Development



Explain all queries and ensure their query plans do not contain the /* traverse explanation in them. Example traversing query plan:
  • PLAN: [nt:unstructured] as [a] /* traverse "/content//*" where ([a].[unindexedProperty] = 'some value') and (isdescendantnode([a], [/content])) */


Post-Deployment



  • Monitor the error.log for index-less traversal queries:
    • *INFO* org.apache.jackrabbit.oak.query.QueryImpl Traversal query (query without index) ... ; consider creating and index
    • This message is only logged if no index is available, and if the query potentially traverses many nodes. Messages are not logged if an index is available, but amount to traversing is small, and thus fast.
  • Visit the AEM Query Performance operations console and Explain slow queries looking for traversal or no index query explanations.

Query Performance



The Query Performance page allows the analysis of the slowest queries performed by the system. This information is provided by the repository in a JMX Mbean. 
In Jackrabbit, the com.adobe.granite.QueryStat JMX Mbean provides this information, while in the Oak repository, it is offered by org.apache.jackrabbit.oak.QueryStats.
The page displays:
  • The time when the query was made
  • The language of the query
  • The number of times the query was issued
  • The statement of the query
  • The duration in milliseconds


chlimage_1


Explain Query



For any given query, Oak attempts to figure out the best way to execute based on the Oak indexes defined in the repository under the oak:index node.
 Depending on the query, different indexes may be chosen by Oak. Understanding how Oak is executing a query is the first step to optimizing the query.
The Explain Query is a tool that explains how Oak is executing a query. It can be accessed by going to Tools - Operations - Diagnosis from the AEM Welcome Screen, then clicking on Query Performance and switching over to the Explain Querytab.
Features
  • Supports the Xpath, JCR-SQL and JCR-SQL2 query languages
  • Reports the actual execution time of the provided query
  • Detects slow queries and warns about queries that could be potentially slow
  • Reports the Oak index used to execute the query
  • Displays the actual Oak Query engine explanation
  • Provides click-to-load list of Slow and Popular queries
Once you are in the Explain Query UI, all you need to do in order to use it is enter the query and press the Explain button:


chlimage_1


The first entry in the Query Explanation section is the actual explanation. The explanation will show the type of index that was used to execute the query.
The second entry is the execution plan.
Ticking the Include execution time box before running the query will also show the amount of time the query was executed in, allowing for more information that can be used for optimizing the indexes for your application or deployment.

chlimage_1

Detecting Poorly Restricted Queries

During Development



Explain all queries and ensure they resolve to an index tuned to match the query's property restrictions.
  • Ideal query plan coverage has indexRules for all property restrictions, and at a minimum for the tightest property restrictions in the query.
  • Queries that sort results, should resolve to a Lucene Property Index with index rules for the sorted by properties that set orderable=true.

For example, the default cqPageLucene does not have an index rule for jcr:content/cq:tags


Before adding the cq:tags index rule
  • cq:tags Index Rule
    • Does not exist out of the box
  • Query Builder query
    • type=cq:Page
      property=jcr:content/cq:tags
      property.value=my:tag
  • Query plan
    • [cq:Page] as [a] /* lucene:cqPageLucene(/oak:index/cqPageLucene) *:* where [a].[jcr:content/cq:tags] = 'my:tag' */
This query resolves to the cqPageLucene index, but because no property index rule exists for jcr:content or cq:tags, when this restriction is evaluated, every record in the cqPageLucene index is checked to determine a match. This means that if the index contains 1 million cq:Page nodes, then 1 million records are checked to determine the result set.
After adding the cq:tags index rule
  • cq:tags Index Rule
    • /oak:index/cqPageLucene/indexRules/cq:Page/properties/cqTags
      @name=jcr:content/cq:tags
      @propertyIndex=true
  • Query Builder query
    • type=cq:Page
      property=jcr:content/cq:tags
      property.value=myTagNamespace:myTag
  • Query plan
    • [cq:Page] as [a] /* lucene:cqPageLucene(/oak:index/cqPageLucene) jcr:content/cq:tags:my:tag where [a].[jcr:content/cq:tags] = 'my:tag' */
The addition of the indexRule for jcr:content/cq:tags in the cqPageLucene index allows cq:tags data to be stored in an optimized way.
When a query with the jcr:content/cq:tags restriction is performed, the index can look up results by value. That means that if 100 cq:Page nodes have myTagNamespace:myTag as a value, only those 100 results are returned, and the other 999,000 are excluded from the restriction checks, improving performance by a factor of 10,000.

Post-Deployment



  • Monitor the error.log for travesal queries:
    • *WARN* org.apache.jackrabbit.oak.spi.query.Cursors$TraversingCursor Traversed ### nodes ... consider creating an index or changing the query
  • Visit the AEM Query Performance operations console and Explain slow queries looking for query plans that do not resolve query property restrictions to index property rules.


Detecting Large Result Set Queries


During Development


Set low threshholds for oak.queryLimitInMemory (eg. 10000) and oak.queryLimitReads (eg. 5000) and optimize the expensive query when hitting an UnsupportedOperationException saying “The query read more than x nodes..."

Post-Deployment


  • Monitor the logs for queries triggering large node traversal or large heap memory consumption :
    • *WARN* ... java.lang.UnsupportedOperationException: The query read or traversed more than 100000 nodes. To avoid affecting other tasks, processing was stopped.
    • Optimize the query to reduce the number of traversed nodes
  • Monitor the logs for queries triggering large heap memory consumption :
    • *WARN* ... java.lang.UnsupportedOperationException: The query read more than 500000 nodes in memory. To avoid running out of memory, processing was stopped
    • Optimize the query to reduce the heap memory consumption
For AEM 6.0 - 6.2 versions, you can tune the threshold for node traversal via JVM parameters in the AEM start script to prevent large queries from overloading the environment. The recommended values are :
  • -Doak.queryLimitInMemory=500000
  • -Doak.queryLimitReads=100000
In AEM 6.3, the above 2 parameters are preconfigured by default, and can be modified via the OSGi QueryEngineSettings.

Query Development Tools

Adobe Supported

Community Supported


  • Oak Index Definition Generator
    • Generate optimal Lucence Property Index from XPath or JCR-SQL2 query statements.
  • AEM Chrome Plug-in
    • Google Chrome web browser extension that exposes per-request log data, including executed queries and their query plans, in the browser's dev tools console.
    • Requires Sling Log Tracer 1.0.2+ to be installed and enabled on AEM.

No comments:

Post a Comment