Search queries take a long time to execute, and the system response time is slow.

One possible cause is that your application is executing long running JCR queries.

Increase the query logging (CRX <= 2.2)

  1. Open crx-quickstart/server/runtime/0/_crx/WEB-INF/log4j.xml for editing
  2. Add the appender configuration below to the top of the xml file:

    <!-- query.log -->
    <appender name="query" class="org.apache.log4j.RollingFileAppender">
      <param name="File" value="crx-quickstart/logs/crx/query.log" />
      <param name="maxFileSize" value="10MB"/>
      <param name="maxBackupIndex" value="20"/>
      <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern"
          value="%d{dd.MM.yyyy HH:mm:ss} *%-5p* [%t] %c{1}: %m (%F, line %L)%n" />
      </layout>
    </appender>
  3. then at the end of the file, add this logger configuration:

    <logger name="org.apache.jackrabbit.core.query.QueryImpl" additivity="false">
      <level value="debug"/>
     <appender-ref ref="query"/>
    </logger>
  4. if you use JCR2 queries (JCR-SQL2 and JCR-JQOM with CRX2.x) also add this logger:

    <logger name="org.apache.jackrabbit.core.query.lucene.join.QueryEngine" additivity="false">
      <level value="debug"/>
     <appender-ref ref="query"/>
    </logger>
  5. Next time the instance is restarted, you should see a new log file query.log under crx-quickstart/logs/crx with messages similar to the following:

    *DEBUG* [0:0:0:0:0:0:0:1%0 [1272608670307] GET /libs/wcm/core/content/pageinfo.json HTTP/1.1] QueryImpl: executed in 0.02 s. (/jcr:root//element(*, cq:Component)) (QueryImpl.java, line 134)
  6. Then run the following command to find the longest running query listed in the query.log using the following command (linux/unix):

    grep "QueryImpl" query.log* | cut -d " " -f 12,14-,1-2 | sort -u -n -k 3
  7. You can also find the longest running query using querylog.jar which you can download at the button of this article. It can be used on all operating systems and sorts logs from QueryImpl and QueryEngine.

    java -Xmx512m -jar querylog.jar query.log > query_sorted.log

As of CRX 2.3, the repository is deployed as a bundle in the OSGi container. It does not run within a web application anymore. The log level can now be changed via the OSGi web console:

  1. Open http://localhost:4502/system/console/configMgr and scroll down to "Apache Sling Logging Logger Configuration" and click it.
  2. In the dialog box, set the log level to Debug and the Logger to org.apache.jackrabbit.core.query.QueryImpl. 
  3. if you use JCR2 queries (JCR-SQL2 and JCR-JQOM) also add logger org.apache.jackrabbit.core.query.lucene.join.QueryEngine.
  4. Click Save.
  5. Now the executed query statements are logged to the error.log file in the same format as in previous CRX versions.

Starting with CRX 2.3, there is an MBean that exposes query statistics. These statistics include the top long running queries. The MBean can be accessed via any JMX client or the built-in client in the OSGi web console: http://localhost:4502/system/console/jmx/com.adobe.granite%3Atype%3DQueryStat

Additional information

To help analyze the problem, it's necessary to know the following information:

  • CRX version, including hot fix version.
  • Operating system, JVM vendor, and version.
  • Thread dumps and Memory dumps / GC logs.
  • Workspace Search Manager configuration

Download

  • querylog.jar.zip: click here to download. Unzip after downloading.

Applies to

CRX 1.4.2

CRX 2.x

This work is licensed under a Creative Commons Attribution-Noncommercial-Share Alike 3.0 Unported License  Twitter™ and Facebook posts are not covered under the terms of Creative Commons.

Legal Notices   |   Online Privacy Policy