Nuxeo Server

Monitoring Slow NXQL Queries

This page is scheduled for review and update. Check back soon for updated content!

It is possible to easily pinpoint slow NXQL. If you want trace all the queries that take more than 100ms:

  1. Add the following line in your nuxeo.conf:

    • For VCS:

      org.nuxeo.vcs.query.log_min_duration_ms=100
      
      
    • For DBS (since Nuxeo Platform 8.3): 

      org.nuxeo.dbs.query.log_min_duration_ms=100
      
      
  2. Activate the log for session you use (VCS or DBS) at the INFO level. Here an example of lib/log4j.xml to get them in a separate file:

    • For VCS:

      <category name="org.nuxeo.ecm.core.storage.sql.SessionImpl" additivity="false">
          <priority value="INFO" />
          <appender-ref ref="SLOW" />
      </category>
      <appender name="SLOW" class="org.apache.log4j.FileAppender">
          <errorHandler class="org.apache.log4j.helpers.OnlyOnceErrorHandler" />
          <param name="File" value="${nuxeo.log.dir}/slow-query.log" />
          <param name="Append" value="false" />
          <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d{ISO8601} %-5p [%t][%c] %m%X%n" />
          </layout>
      </appender>
      
    • For DBS (since Nuxeo Platform 8.3):

      <category name="org.nuxeo.ecm.core.storage.dbs.DBSSession" additivity="false">
          <priority value="INFO" />
          <appender-ref ref="SLOW" />
      </category>
      <appender name="SLOW" class="org.apache.log4j.FileAppender">
          <errorHandler class="org.apache.log4j.helpers.OnlyOnceErrorHandler" />
          <param name="File" value="${nuxeo.log.dir}/slow-query.log" />
          <param name="Append" value="false" />
          <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%d{ISO8601} %-5p [%t][%c] %m%X%n" />
          </layout>
      </appender>
      

To get the slowest queries:

$ grep duration_ms log/slow-query.log | sed -e's/^[^\t]*\t//g' -e 's/{.*$//g' |sort -nr | head

802.89  QueryFilter(principal=system, limit=0, offset=0)        query   SELECT * FROM Document WHERE ....
12.87   QueryFilter(principal=bob, limit=0, offset=0)        queryAndFetch   Select DISTINCT ecm:uuid...
10.12   QueryFilter(principal=system, limit=50, offset=0) count total results UNLIMITED query   SELECT * FROM Document WHERE ...
5.35    QueryFilter(principal=Administrator, limit=20, offset=0) count total results up to 20   query   SELECT * FROM ...

When configuring the log priority to TRACE a debug stack trace is available in the log so you got the code path.

 


Related Documentation
 

We'd love to hear your thoughts!

All fields required