LATEST VERSION: 8.2.7 - CHANGELOG
Pivotal GemFire® v8.2

Query Debugging

Query Debugging

You can debug a specific query at the query level by adding the <trace> keyword before the query string that you want to debug.

Here is an example:
<trace> select * from /exampleRegion
You can also write:
<TRACE> select * from /exampleRegion
When the query is executed, GemFire will log a message in $GEMFIRE_DIR/system.log with the following information:
[info 2011/08/29 11:24:35.472 PDT CqServer <main> tid=0x1] Query Executed in 9.619656 ms; rowCount = 99; indexesUsed(0) "select *  from /exampleRegion" 
If you want to enable debugging for all queries, you can enable query execution logging by setting a System property on the command line during start-up:
gfsh>start server --name=server_name -–J=-Dgemfire.Query.VERBOSE=true
Or you can set the property programmatically:
System.setProperty("gemfire.Query.VERBOSE","true");
As an example, let us say you have an EmployeeRegion that that contains Employee objects as values and the objects have public fields in them like ID and status.
Employee.java
Class Employee {
 public int ID;
 public String status;
 - - - - - -
 - - - - - -
}
In addition, you have created the following indexes for the region:
<index name="sampleIndex-1">
<functional from-clause="/test " expression="ID"/>
</index>
<index name="sampleIndex-2">
<functional from-clause="/test " expression="status"/>
</index>
After you have set gemfire.Query.VERBOSE to "true", you could see the following debug messages in the logs after running queries on the EmployeeRegion or its indexes:
  • If indexes are not used in the query execution, you would see a debug message like this:
    [info 2011/08/29 11:24:35.472 PDT CqServer <main> tid=0x1] Query Executed in 9.619656 ms; rowCount = 99; indexesUsed(0) "select * from /test k where ID > 0 and status='active'"
  • When single index is used in query execution, you might see a debug message like this:
    [info 2011/08/29 11:24:35.472 PDT CqServer <main> tid=0x1] Query Executed in 101.43499 ms; rowCount = 199; indexesUsed(1):sampleIndex-1(Results: 199) "select count *   from /test k where ID > 0"
  • When multiple indexes are used by a query, you might see a debug message like this:
    [info 2011/08/29 11:24:35.472 PDT CqServer <main> tid=0x1] Query Executed in 79.43847 ms; rowCount = 199; indexesUsed(2):sampleIndex-2(Results: 100),sampleIndex-1(Results: 199) "select * from /test k where ID > 0 OR status='active'"
In above log messages, the following information is provided:
  • "rowCount" represents ResultSet size for the query.
  • "indexesUsed(\n) " shows n indexes were used for finding the results of the query.
  • Each index name and its corresponding results are reported respectively.
  • The log can be identified with the original query string itself appended in the end.