Skip to content
Permalink
Browse files
OAK-9624 print the name of the calling class invoking a query in some…
… cases (#420)

* OAK-9624 print the name of the calling class invoking a query in some cases

* implement PR feedback

* implement PR feedback

* add unit test
  • Loading branch information
joerghoh committed Nov 26, 2021
1 parent f545723 commit e8af772537fe0fa800ac112dccb916689cc96d02
Showing 13 changed files with 125 additions and 9 deletions.
@@ -16,6 +16,7 @@
*/
package org.apache.jackrabbit.oak.api.jmx;

import org.jetbrains.annotations.NotNull;
import org.osgi.annotation.versioning.ProviderType;

@ProviderType
@@ -140,4 +141,21 @@ void setQueryValidatorPattern(
@Description("Get the query validator data as a JSON string.")
String getQueryValidatorJson();

/**
* Set or remove java package/class names which are ignored from finding the
* invoking class for queries.
*
* It can be either Java package names or fully-qualified class names (package + class name).
*
* @param classNames the class names to be ignored.
*/
@Description("Set or remove Java package / fully qualified class names to ignore in Call Trace analysis")
void setIgnoredClassNamesInCallTrace(
@Description("package or fully qualified class names")
@Name("class names")
@NotNull String[] classNames);

// @Description("Get the Java package / fully qualified class names to ignore when finding the caller of query")
@NotNull
String[] getIgnoredClassNamesInCallTrace();
}
@@ -15,7 +15,7 @@
* limitations under the License.
*/

@Version("4.10.0")
@Version("4.11.0")
package org.apache.jackrabbit.oak.api.jmx;

import org.osgi.annotation.versioning.Version;
@@ -974,6 +974,14 @@ public String toString() {
void setFullTextComparisonWithoutIndex(boolean fullTextComparisonWithoutIndex) {
this.settings.setFullTextComparisonWithoutIndex(fullTextComparisonWithoutIndex);
}

public void setIgnoredClassNamesInCallTrace(@NotNull String[] packageNames) {
settings.setIgnoredClassNamesInCallTrace(packageNames);
}

public @NotNull String[] getIgnoredClassNamesInCallTrace() {
return settings.getIgnoredClassNamesInCallTrace();
}
}

public static class OakDefaultComponents {
@@ -339,7 +339,9 @@ private void fetchNext() {
readCount++;
if (readCount % 1000 == 0) {
FilterIterators.checkReadLimit(readCount, settings);
LOG.warn("Traversed " + readCount + " nodes with filter " + filter + "; consider creating an index or changing the query");
String caller = IndexUtils.getCaller(this.settings.getIgnoredClassNamesInCallTrace());
LOG.warn("Traversed {} nodes with filter {} called by {}; consider creating an index or changing the query" ,
readCount, filter, caller);
}

NodeState node = entry.getNodeState();
@@ -33,6 +33,7 @@
import java.util.Collection;
import java.util.Map;
import java.util.Set;
import java.util.stream.Stream;

import javax.jcr.RepositoryException;

@@ -241,4 +242,37 @@ public static String getAsyncLaneName(NodeState idxState, String indexPath, Prop
}
return null;
}

/**
* Retrieves the calling class and method from the call stack; this is determined by unwinding
* the stack until it finds a combination of full qualified classname + method (separated by ".") which
* do not start with any of the values provided by the ignoredJavaPackages parameters. If the provided
* parameters cover all stack frames, the whole query is considered to be internal, where the
* actual caller doesn't matter (or cannot be determined clearly). In this case a short message
* indicating this is returned.
*
* If the ignoredJavaPackages parameter is null or empty, the caller is not looked up, but
* instead it is assumed, that the feature is not configured; in that case a short messages
* is returned indicating that the feature is not configured.
*
* @param ignoredJavaPackages the java packages or class names
* @return the calling class or another non-null value
*/
@NotNull
public static String getCaller(@Nullable String[] ignoredJavaPackages) {
if (ignoredJavaPackages == null || ignoredJavaPackages.length == 0) {
return "(<function not configured>)";
}

// With java9 we would use https://docs.oracle.com/javase/9/docs/api/java/lang/StackWalker.html
final StackTraceElement[] callStack = Thread.currentThread().getStackTrace();
for (StackTraceElement stackFrame : callStack) {
final String classAndMethod = stackFrame.getClassName() + "." + stackFrame.getMethodName();
if (Stream.of(ignoredJavaPackages).noneMatch(classAndMethod::startsWith)) {
return classAndMethod;
}
}
// if every element is ignored, we assume it's an internal request
return "(internal)";
}
}
@@ -30,6 +30,7 @@
import org.apache.jackrabbit.oak.commons.PathUtils;
import org.apache.jackrabbit.oak.plugins.index.Cursors;
import org.apache.jackrabbit.oak.plugins.index.IndexConstants;
import org.apache.jackrabbit.oak.plugins.index.IndexUtils;
import org.apache.jackrabbit.oak.plugins.index.property.strategy.IndexStoreStrategy;
import org.apache.jackrabbit.oak.spi.filter.PathFilter;
import org.apache.jackrabbit.oak.spi.mount.MountInfoProvider;
@@ -205,11 +206,12 @@ String getName() {
}

Cursor execute() {
QueryLimits settings = filter.getQueryLimits();
if (deprecated) {
LOG.warn("This index is deprecated: {}; it is used for query {}. " +
"Please change the query or the index definitions.", name, filter);
final String caller = IndexUtils.getCaller(settings.getIgnoredClassNamesInCallTrace());
LOG.warn("This index is deprecated: {}; it is used for query {} called by {}. " +
"Please change the query or the index definitions.", name, filter, caller);
}
QueryLimits settings = filter.getQueryLimits();
List<Iterable<String>> iterables = Lists.newArrayList();
for (IndexStoreStrategy s : strategies) {
iterables.add(s.query(filter, name, definition, values));
@@ -28,6 +28,7 @@
import org.apache.jackrabbit.oak.api.PropertyState;
import org.apache.jackrabbit.oak.api.Type;
import org.apache.jackrabbit.oak.commons.PathUtils;
import org.apache.jackrabbit.oak.plugins.index.IndexUtils;
import org.apache.jackrabbit.oak.plugins.index.counter.ApproximateCounter;
import org.apache.jackrabbit.oak.plugins.index.counter.NodeCounterEditor;
import org.apache.jackrabbit.oak.plugins.index.counter.jmx.NodeCounter;
@@ -456,7 +457,9 @@ private void fetchNextPossiblyDuplicate() {
readCount++;
if (readCount % TRAVERSING_WARN == 0) {
FilterIterators.checkReadLimit(readCount, settings);
LOG.warn("Index-Traversed {} nodes ({} index entries) using index {} with filter {}", readCount, intermediateNodeReadCount, indexName, filter);
String caller = IndexUtils.getCaller(settings.getIgnoredClassNamesInCallTrace());
LOG.warn("Index-Traversed {} nodes ({} index entries) using index {} with filter {}, caller {}",
readCount, intermediateNodeReadCount, indexName, filter, caller);
}
return;
} else {
@@ -18,13 +18,16 @@
*/
package org.apache.jackrabbit.oak.query;

import java.util.Arrays;

import org.apache.jackrabbit.oak.api.StrictPathRestriction;
import org.apache.jackrabbit.oak.api.jmx.QueryEngineSettingsMBean;
import org.apache.jackrabbit.oak.query.stats.QueryStatsMBean;
import org.apache.jackrabbit.oak.query.stats.QueryStatsMBeanImpl;
import org.apache.jackrabbit.oak.query.stats.QueryStatsReporter;
import org.apache.jackrabbit.oak.spi.query.QueryLimits;
import org.apache.jackrabbit.oak.stats.StatisticsProvider;
import org.jetbrains.annotations.NotNull;

/**
* Settings of the query engine.
@@ -88,6 +91,8 @@ public class QueryEngineSettings implements QueryEngineSettingsMBean, QueryLimit

private final QueryValidator queryValidator = new QueryValidator();

private String[] classNamesIgnoredInCallTrace = new String[] {};

public QueryEngineSettings() {
statisticsProvider = StatisticsProvider.NOOP;
}
@@ -182,6 +187,14 @@ public String getQueryValidatorJson() {
public QueryValidator getQueryValidator() {
return queryValidator;
}

public void setIgnoredClassNamesInCallTrace(@NotNull String[] packageNames) {
classNamesIgnoredInCallTrace = packageNames;
}

public @NotNull String[] getIgnoredClassNamesInCallTrace() {
return classNamesIgnoredInCallTrace;
}

@Override
public String toString() {
@@ -192,6 +205,7 @@ public String toString() {
", fullTextComparisonWithoutIndex=" + fullTextComparisonWithoutIndex +
", sql2Optimisation=" + sql2Optimisation +
", fastQuerySize=" + fastQuerySize +
", classNamesIgnoredInCallTrace=" + Arrays.toString(classNamesIgnoredInCallTrace) +
'}';
}

@@ -77,6 +77,14 @@ public class QueryEngineSettingsService {
"the queryPaths of the index is taken into account."
)
String getStrictPathRestrictionsForIndexes() default DISABLED_STRICT_PATH_RESTRICTION;

@AttributeDefinition(
name="Fully qualified class names to ignore when finding caller",
description="If non-empty the query engine logs the query statement plus the java package "
+ "which executed this query. This java package is the first package in the call trace "
+ "which does not start with any of the provided fully qualified class names (packagename + classname)"
)
String[] ignoredClassNamesInCallTrace() default {};

}

@@ -122,6 +130,8 @@ private void activate(BundleContext context, Configuration config) {
logMsg(QUERY_FAIL_TRAVERSAL, QueryEngineSettings.OAK_QUERY_FAIL_TRAVERSAL);
}

queryEngineSettings.setIgnoredClassNamesInCallTrace(config.ignoredClassNamesInCallTrace());

boolean fastQuerySizeSysProp = QueryEngineSettings.DEFAULT_FAST_QUERY_SIZE;
boolean fastQuerySizeFromConfig = config.fastQuerySize();
queryEngineSettings.setFastQuerySize(fastQuerySizeFromConfig || fastQuerySizeSysProp);
@@ -28,6 +28,12 @@
import static org.junit.Assert.*;

public class IndexUtilsTest {

// all relevant package TLDs
private static final String[] ALL_CLASSES_IGNORED = new String[] {"org", "com", "sun", "jdk", "java"};

// all packages used with Oak
private static final String[] OAK_CLASSES_IGNORED = new String[] {"org.apache.jackrabbit", "java.lang", "sun.reflect", "jdk"};

@Test
public void asyncName() throws Exception {
@@ -41,4 +47,14 @@ public void asyncName() throws Exception {
assertEquals("async3", IndexUtils.getAsyncLaneName(builder.getNodeState(), "/fooIndex"));
}

@Test
public void getCaller() {
assertNotNull(IndexUtils.getCaller(null));
assertNotNull(IndexUtils.getCaller(new String[0]));

assertEquals("(internal)",IndexUtils.getCaller(ALL_CLASSES_IGNORED));

String caller = IndexUtils.getCaller(OAK_CLASSES_IGNORED);
assertTrue(caller.startsWith("org.junit.runners"));
}
}
@@ -106,7 +106,7 @@ public void deprecated() throws Exception {
propertyIndex.query(f, root);
assertEquals("[[WARN] This index is deprecated: foo; " +
"it is used for query Filter(query=" +
"SELECT * FROM [nt:base], path=*, property=[foo=[x10]]). " +
"SELECT * FROM [nt:base], path=*, property=[foo=[x10]]) called by (<function not configured>). " +
"Please change the query or the index definitions.]", appender.list.toString());

index = rootBuilder.child(INDEX_DEFINITIONS_NAME).child("foo");
@@ -19,6 +19,7 @@
package org.apache.jackrabbit.oak.spi.query;

import org.apache.jackrabbit.oak.api.StrictPathRestriction;
import org.jetbrains.annotations.NotNull;

public interface QueryLimits {

@@ -33,5 +34,13 @@ public interface QueryLimits {
default String getStrictPathRestriction() {
return StrictPathRestriction.DISABLE.name();
}


/**
* Retrieve the java package names / full qualified class names which should be
* ignored when finding the class starting a query
* @return the name of the packages / full qualified class names
*/
default @NotNull String[] getIgnoredClassNamesInCallTrace() {
return new String[] {};
}
}
@@ -18,7 +18,7 @@
/**
* This package contains oak query index related classes.
*/
@Version("1.4.0")
@Version("1.5.0")
package org.apache.jackrabbit.oak.spi.query;

import org.osgi.annotation.versioning.Version;

0 comments on commit e8af772

Please sign in to comment.