in src/main/java/org/apache/sling/tracer/internal/JSONRecording.java [364:410]
public void record(Level level, String logger, FormattingTuple tuple) {
//Assuming in a series of log statement from query package we see 'query'
//and then 'plan' then once both are not null then it means that one query
//execution is complete and we push the entry and reset the state
//This is done as we do not have a definitive way to determine when
//a given query processing is done
attemptQueryEntry();
//TODO Query time. Change Oak to provide this information via some
//dedicated Audit logging such that below reliance on impl details
//can be avoided
String msg = tuple.getMessage();
if (Level.DEBUG == level && msg != null) {
Object[] args = tuple.getArgArray() == null ? EMPTY : tuple.getArgArray();
if (query == null){
if ("org.apache.jackrabbit.oak.query.QueryEngineImpl".equals(logger)
&& msg.contains("Parsing") && args.length == 2){
//LOG.debug("Parsing {} statement: {}", language, statement);
query = nullSafeString(args[1]);
caller = determineCaller();
}
}
//Plan for union query are logged separately
if (plan == null){
if ("org.apache.jackrabbit.oak.query.QueryImpl".equals(logger)
&& msg.startsWith("query plan ")){
//logDebug("query execute " + statement);
if (subPlans == 0) {
plan = msg.substring("query plan ".length());
} else {
subPlans--;
}
} else if ("org.apache.jackrabbit.oak.query.UnionQueryImpl".equals(logger)
&& msg.contains("query union plan") && args.length > 0){
// LOG.debug("query union plan {}", getPlan());
plan = nullSafeString(args[0]);
// Determine number of sub-queries in this UNION query so they can be ignored
int unionCount = count(plan, "*/ union ");
if (unionCount > 0) {
subPlans = unionCount + 1;
}
}
}
}
}