Server

Monitoring Slow NXQL Queries

Updated: March 18, 2024

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