Skip to content

Commit c9ab4f3

Browse files
committed
5608: Include top stack trace frames in errors and exceptions rules
1 parent 25b8e1d commit c9ab4f3

File tree

6 files changed

+104
-28
lines changed

6 files changed

+104
-28
lines changed

core/org.openjdk.jmc.flightrecorder.rules.jdk/src/main/java/org/openjdk/jmc/flightrecorder/rules/jdk/exceptions/ErrorRule.java

Lines changed: 14 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -110,10 +110,14 @@ public class ErrorRule extends AbstractRule {
110110
IQuantity.class);
111111
public static final TypedResult<IQuantity> EXCLUDED_ERRORS = new TypedResult<>("excludedErrors", "Excluded Errors", //$NON-NLS-1$
112112
"The number of errors excluded from the rule evaluation.", UnitLookup.NUMBER, IQuantity.class);
113+
public static final TypedResult<String> MOST_COMMON_ERROR_STACKTRACE = new TypedResult<>(
114+
"mostCommonErrorStacktrace", //$NON-NLS-1$
115+
"Most Common Error Stacktrace", "The most common error stacktrace frames.", UnitLookup.PLAIN_TEXT,
116+
String.class);
113117

114118
private static final Collection<TypedResult<?>> RESULT_ATTRIBUTES = Arrays.<TypedResult<?>> asList(
115119
TypedResult.SCORE, ERROR_COUNT, EXCLUDED_ERRORS, ERROR_RATE, ERROR_WINDOW, MOST_COMMON_ERROR,
116-
MOST_COMMON_ERROR_COUNT);
120+
MOST_COMMON_ERROR_COUNT, MOST_COMMON_ERROR_STACKTRACE);
117121

118122
private static final Map<String, EventAvailability> REQUIRED_EVENTS = RequiredEventsBuilder.create()
119123
.addEventType(JdkTypeIDs.ERRORS_THROWN, EventAvailability.AVAILABLE).build();
@@ -173,17 +177,24 @@ public int compare(
173177
int errorsThrown = errorGrouping.get(errorGrouping.size() - 1).getValue();
174178
double score = RulesToolkit.mapExp100(maxErrorsPerMinute.left.doubleValue(), infoLimit, warnLimit);
175179
String longMessage = Messages.getString(Messages.ErrorRule_TEXT_WARN_LONG);
176-
// FIXME: List some frames of the most common stack trace
177180
if (excludedErrors != null && excludedErrors.longValue() > 0) {
178181
longMessage += " " + Messages.getString(Messages.ErrorRule_TEXT_WARN_EXCLUDED_INFO); //$NON-NLS-1$
179182
}
183+
String stackTraceFrames = ""; //$NON-NLS-1$
184+
if (mostCommonError != null) {
185+
IItemFilter errorTypeFilter = ItemFilters.equals(JdkAttributes.EXCEPTION_THROWNCLASS, mostCommonError);
186+
IItemCollection mostCommonErrorItems = errorItems.apply(errorTypeFilter);
187+
stackTraceFrames = RulesToolkit.getTopNFramesInMostCommonTrace(mostCommonErrorItems, 10);
188+
longMessage += "\n" + Messages.getString(Messages.ErrorRule_TEXT_WARN_MOST_COMMON_STACKTRACE); //$NON-NLS-1$
189+
}
180190
return ResultBuilder.createFor(this, vp).setSeverity(Severity.get(score))
181191
.setSummary(Messages.getString(Messages.ErrorRule_TEXT_WARN)).setExplanation(longMessage)
182192
.addResult(TypedResult.SCORE, UnitLookup.NUMBER_UNITY.quantity(score))
183193
.addResult(ERROR_COUNT, errorCount).addResult(ERROR_WINDOW, maxErrorsPerMinute.right)
184194
.addResult(ERROR_RATE, maxErrorsPerMinute.left).addResult(MOST_COMMON_ERROR, mostCommonError)
185195
.addResult(EXCLUDED_ERRORS, excludedErrors).addResult(TypedResult.ITEM_QUERY, JdkQueries.ERRORS)
186-
.addResult(MOST_COMMON_ERROR_COUNT, UnitLookup.NUMBER_UNITY.quantity(errorsThrown)).build();
196+
.addResult(MOST_COMMON_ERROR_COUNT, UnitLookup.NUMBER_UNITY.quantity(errorsThrown))
197+
.addResult(MOST_COMMON_ERROR_STACKTRACE, stackTraceFrames).build();
187198
}
188199
return ResultBuilder.createFor(this, vp).setSeverity(Severity.OK)
189200
.setSummary(Messages.getString(Messages.ErrorRule_TEXT_OK)).build();

core/org.openjdk.jmc.flightrecorder.rules.jdk/src/main/java/org/openjdk/jmc/flightrecorder/rules/jdk/exceptions/ExceptionRule.java

Lines changed: 37 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,11 @@
4343
import java.util.concurrent.FutureTask;
4444
import java.util.concurrent.RunnableFuture;
4545

46+
import org.openjdk.jmc.common.IMCType;
47+
import org.openjdk.jmc.common.collection.MapToolkit.IntEntry;
4648
import org.openjdk.jmc.common.item.IItemCollection;
49+
import org.openjdk.jmc.common.item.IItemFilter;
50+
import org.openjdk.jmc.common.item.ItemFilters;
4751
import org.openjdk.jmc.common.unit.IQuantity;
4852
import org.openjdk.jmc.common.unit.IRange;
4953
import org.openjdk.jmc.common.unit.QuantityRange;
@@ -92,9 +96,15 @@ public class ExceptionRule implements IRule {
9296
public static final TypedResult<IRange<IQuantity>> EXCEPTION_WINDOW = new TypedResult<>("exceptionsWindow", //$NON-NLS-1$
9397
"Exception Window", "The window during which the highest exception rate was detected.",
9498
UnitLookup.TIMERANGE);
99+
public static final TypedResult<IMCType> MOST_COMMON_EXCEPTION = new TypedResult<>("mostCommonException", //$NON-NLS-1$
100+
"Most Common Exception", "The most common exception thrown.", UnitLookup.CLASS, IMCType.class);
101+
public static final TypedResult<String> MOST_COMMON_EXCEPTION_STACKTRACE = new TypedResult<>(
102+
"mostCommonExceptionStacktrace", "Most Common Exception Stacktrace", //$NON-NLS-1$
103+
"The most common exception stacktrace frames.", UnitLookup.PLAIN_TEXT, String.class);
95104

96-
private static final Collection<TypedResult<?>> RESULT_ATTRIBUTES = Arrays
97-
.<TypedResult<?>> asList(TypedResult.SCORE, EXCEPTION_RATE, EXCEPTION_WINDOW);
105+
private static final Collection<TypedResult<?>> RESULT_ATTRIBUTES = Arrays.<TypedResult<?>> asList(
106+
TypedResult.SCORE, EXCEPTION_RATE, EXCEPTION_WINDOW, MOST_COMMON_EXCEPTION,
107+
MOST_COMMON_EXCEPTION_STACKTRACE);
98108

99109
private IResult getResult(IItemCollection items, IPreferenceValueProvider vp, IResultValueProvider rp) {
100110
long infoLimit = vp.getPreferenceValue(EXCEPTIONS_INFO_LIMIT).clampedLongValueIn(NUMBER_UNITY);
@@ -110,9 +120,31 @@ private IResult getResult(IItemCollection items, IPreferenceValueProvider vp, IR
110120
IRange<IQuantity> window = QuantityRange.createWithEnd(
111121
UnitLookup.EPOCH_NS.quantity(maxExceptionPeriod.start),
112122
UnitLookup.EPOCH_NS.quantity(maxExceptionPeriod.end));
113-
return ResultBuilder.createFor(this, vp).setSeverity(Severity.get(score))
114-
.setSummary(Messages.getString(Messages.ExceptionRule_TEXT_MESSAGE))
115-
.setExplanation(Messages.getString(Messages.ExceptionRule_TEXT_INFO_LONG))
123+
ResultBuilder resultBuilder = ResultBuilder.createFor(this, vp);
124+
String explanation = Messages.getString(Messages.ExceptionRule_TEXT_INFO_LONG);
125+
EventAvailability exceptionsThrownEventAvailability = RulesToolkit.getEventAvailability(items,
126+
JdkTypeIDs.EXCEPTIONS_THROWN);
127+
if (exceptionsThrownEventAvailability == EventAvailability.AVAILABLE) {
128+
IItemCollection exceptionItems = items.apply(JdkFilters.EXCEPTIONS);
129+
List<IntEntry<IMCType>> exceptionGrouping = RulesToolkit.calculateGroupingScore(exceptionItems,
130+
JdkAttributes.EXCEPTION_THROWNCLASS);
131+
IMCType mostCommonException = exceptionGrouping.get(exceptionGrouping.size() - 1).getKey();
132+
explanation = Messages.getString(Messages.ExceptionRule_TEXT_MOST_COMMON_EXCEPTION) + explanation;
133+
resultBuilder.addResult(MOST_COMMON_EXCEPTION, mostCommonException);
134+
String stackTraceFrames = ""; //$NON-NLS-1$
135+
if (mostCommonException != null) {
136+
IItemFilter exceptionTypeFilter = ItemFilters.equals(JdkAttributes.EXCEPTION_THROWNCLASS,
137+
mostCommonException);
138+
IItemCollection mostCommonExceptionItems = exceptionItems.apply(exceptionTypeFilter);
139+
stackTraceFrames = RulesToolkit.getTopNFramesInMostCommonTrace(mostCommonExceptionItems, 10);
140+
}
141+
explanation = Messages.getString(Messages.ExceptionRule_TEXT_MOST_COMMON_EXCEPTION) + explanation + "\n" //$NON-NLS-1$
142+
+ Messages.getString(Messages.ExceptionRule_TEXT_MOST_COMMON_STACKTRACE);
143+
resultBuilder.addResult(MOST_COMMON_EXCEPTION, mostCommonException)
144+
.addResult(MOST_COMMON_EXCEPTION_STACKTRACE, stackTraceFrames);
145+
}
146+
return resultBuilder.setSeverity(Severity.get(score))
147+
.setSummary(Messages.getString(Messages.ExceptionRule_TEXT_MESSAGE)).setExplanation(explanation)
116148
.addResult(TypedResult.SCORE, UnitLookup.NUMBER_UNITY.quantity(score))
117149
.addResult(EXCEPTION_RATE, UnitLookup.NUMBER_UNITY.quantity(exPerSec))
118150
.addResult(TypedResult.ITEM_QUERY, JdkQueries.THROWABLES_STATISTICS)

core/org.openjdk.jmc.flightrecorder.rules.jdk/src/main/java/org/openjdk/jmc/flightrecorder/rules/jdk/messages/internal/Messages.java

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -231,12 +231,15 @@ public class Messages {
231231
public static final String ErrorRule_TEXT_WARN = "ErrorRule_TEXT_WARN"; //$NON-NLS-1$
232232
public static final String ErrorRule_TEXT_WARN_EXCLUDED_INFO = "ErrorRule_TEXT_WARN_EXCLUDED_INFO"; //$NON-NLS-1$
233233
public static final String ErrorRule_TEXT_WARN_LONG = "ErrorRule_TEXT_WARN_LONG"; //$NON-NLS-1$
234+
public static final String ErrorRule_TEXT_WARN_MOST_COMMON_STACKTRACE = "ErrorRule_TEXT_WARN_MOST_COMMON_STACKTRACE"; //$NON-NLS-1$
234235
public static final String ExceptionRule_CONFIG_INFO_LIMIT = "ExceptionRule_CONFIG_INFO_LIMIT"; //$NON-NLS-1$
235236
public static final String ExceptionRule_CONFIG_INFO_LIMIT_LONG = "ExceptionRule_CONFIG_INFO_LIMIT_LONG"; //$NON-NLS-1$
236237
public static final String ExceptionRule_CONFIG_WARN_LIMIT = "ExceptionRule_CONFIG_WARN_LIMIT"; //$NON-NLS-1$
237238
public static final String ExceptionRule_CONFIG_WARN_LIMIT_LONG = "ExceptionRule_CONFIG_WARN_LIMIT_LONG"; //$NON-NLS-1$
238239
public static final String ExceptionRule_RULE_NAME = "ExceptionRule_RULE_NAME"; //$NON-NLS-1$
239240
public static final String ExceptionRule_TEXT_INFO_LONG = "ExceptionRule_TEXT_INFO_LONG"; //$NON-NLS-1$
241+
public static final String ExceptionRule_TEXT_MOST_COMMON_EXCEPTION = "ExceptionRule_TEXT_MOST_COMMON_EXCEPTION"; //$NON-NLS-1$
242+
public static final String ExceptionRule_TEXT_MOST_COMMON_STACKTRACE = "ExceptionRule_TEXT_MOST_COMMON_STACKTRACE"; //$NON-NLS-1$
240243
public static final String ExceptionRule_TEXT_MESSAGE = "ExceptionRule_TEXT_MESSAGE"; //$NON-NLS-1$
241244
public static final String FatalErrorRule_RULE_NAME = "FatalErrorRule_RULE_NAME"; //$NON-NLS-1$
242245
public static final String FatalErrorRule_TEXT_OK = "FatalErrorRule_TEXT_OK"; //$NON-NLS-1$

core/org.openjdk.jmc.flightrecorder.rules.jdk/src/main/resources/org/openjdk/jmc/flightrecorder/rules/jdk/messages/internal/messages.properties

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -232,14 +232,20 @@ ErrorRule_TEXT_WARN=The program generated an average of {errorRate} errors per m
232232
ErrorRule_TEXT_WARN_LONG={errorCount} errors were thrown in total. The most common error was ''{mostCommonError}'', which was thrown {mostCommonErrorCount} times. Investigate the thrown errors to see if they can be avoided. Errors indicate that something went wrong with the code execution and should never be used for flow control.
233233
# {error.exclude.regexp} is a regexp exclude string, {excludedErrors} is a number
234234
ErrorRule_TEXT_WARN_EXCLUDED_INFO=The following regular expression was used to exclude {excludedErrors} errors from this rule: ''{error.exclude.regexp}''.
235+
# {mostCommonErrorStacktrace} is a string.
236+
ErrorRule_TEXT_WARN_MOST_COMMON_STACKTRACE=The most common error stackrace was : \n {mostCommonErrorStacktrace}
235237
ExceptionRule_CONFIG_INFO_LIMIT=Exception rate info limit
236238
ExceptionRule_CONFIG_INFO_LIMIT_LONG=The number of thrown exceptions per second needed to trigger an info notice
237239
ExceptionRule_CONFIG_WARN_LIMIT=Exception rate warning limit
238240
ExceptionRule_CONFIG_WARN_LIMIT_LONG=The number of thrown exceptions per second needed to trigger a warning
239241
ExceptionRule_RULE_NAME=Thrown Exceptions
242+
# {mostCommonException} is an exception class name
243+
ExceptionRule_TEXT_MOST_COMMON_EXCEPTION=The most common exception was ''{mostCommonException}''.
240244
ExceptionRule_TEXT_INFO_LONG=Throwing exceptions is more expensive than normal code execution, which means that they should only be used for exceptional situations. Investigate the thrown exceptions to see if any of them can be avoided with a non-exceptional control flow.
241245
# {exceptionsWindow} is a time range, {exceptionsRate} is a number
242246
ExceptionRule_TEXT_MESSAGE=The program generated {exceptionsRate} exceptions per second during {exceptionsWindow}.
247+
{mostCommonExceptionStacktrace} is a string.
248+
ExceptionRule_TEXT_MOST_COMMON_STACKTRACE=The most common exception stacktrace was : \n {mostCommonExceptionStacktrace}
243249
FatalErrorRule_RULE_NAME=Fatal Errors
244250
FatalErrorRule_TEXT_OK=The JVM shut down in a normal way.
245251
FatalErrorRule_TEXT_INFO=The JVM shut down due to there being no remaining non-daemon Java threads.

core/org.openjdk.jmc.flightrecorder.rules/src/main/java/org/openjdk/jmc/flightrecorder/rules/util/RulesToolkit.java

Lines changed: 32 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -1440,33 +1440,46 @@ public void run() {
14401440
}
14411441

14421442
/**
1443-
* Gets the second frame in the most common stack trace. Useful when showing what called a
1443+
* Gets the top n frame in the most common stack trace. Useful when showing what called a
14441444
* interesting method, like for example java.lang.Integer.valueOf (aka autoboxing)
14451445
*
14461446
* @param items
14471447
* the item collection to build the aggregated stack trace on
1448-
* @return a stack trace frame
1448+
* @return stack trace frames
14491449
*/
1450-
// FIXME: Generalize this a bit, get the top N frames
1451-
public static String getSecondFrameInMostCommonTrace(IItemCollection items) {
1450+
public static String getTopNFramesInMostCommonTrace(IItemCollection items, int n) {
14521451
FrameSeparator sep = new FrameSeparator(FrameSeparator.FrameCategorization.LINE, false);
14531452
StacktraceModel stacktraceModel = new StacktraceModel(false, sep, items);
1454-
Branch firstBranch = stacktraceModel.getRootFork().getBranch(0);
1455-
StacktraceFrame secondFrame = null;
1456-
if (firstBranch.getTailFrames().length > 0) {
1457-
secondFrame = firstBranch.getTailFrames()[0];
1458-
} else if (firstBranch.getEndFork().getBranchCount() > 0) {
1459-
secondFrame = firstBranch.getEndFork().getBranch(0).getFirstFrame();
1460-
} else {
1461-
return null;
1453+
Branch currentBranch = stacktraceModel.getRootFork().getBranch(0);
1454+
List<StacktraceFrame> frames = new ArrayList<>();
1455+
while (currentBranch != null && frames.size() < n) {
1456+
frames.add(currentBranch.getFirstFrame());
1457+
for (StacktraceFrame tf : currentBranch.getTailFrames()) {
1458+
if (frames.size() == n)
1459+
break;
1460+
frames.add(tf);
1461+
}
1462+
if (frames.size() == n)
1463+
break;
1464+
if (currentBranch.getEndFork().getBranchCount() > 0) {
1465+
currentBranch = currentBranch.getEndFork().getBranch(0);
1466+
} else {
1467+
break;
1468+
}
14621469
}
1463-
/*
1464-
* FIXME: Consider defining the method formatting based on preferences.
1465-
*
1466-
* Currently it's a compromise between keeping the length short, but still being able to
1467-
* identify the actual method, even if the line number is a bit incorrect.
1468-
*/
1469-
return StacktraceFormatToolkit.formatFrame(secondFrame.getFrame(), sep, false, false, true, true, true, false);
1470+
int countToPrint = Math.min(n, frames.size());
1471+
List<String> formattedFrames = new ArrayList<>(countToPrint);
1472+
for (int i = 0; i < countToPrint; i++) {
1473+
/*
1474+
* FIXME: Consider defining the method formatting based on preferences.
1475+
*
1476+
* Currently it's a compromise between keeping the length short, but still being able to
1477+
* identify the actual method, even if the line number is a bit incorrect.
1478+
*/
1479+
formattedFrames.add(StacktraceFormatToolkit.formatFrame(frames.get(i).getFrame(), sep, false, false, true,
1480+
true, true, false));
1481+
}
1482+
return String.join("\n", formattedFrames);
14701483
}
14711484

14721485
/**

core/tests/org.openjdk.jmc.flightrecorder.rules.jdk.test/src/main/resources/baseline/JfrRuleBaseline.xml

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6289,7 +6289,18 @@ Enabling the following event types would improve the accuracy of this rule: jdk.
62896289
<id>Errors</id>
62906290
<severity>OK</severity>
62916291
<summary>The program generated an average of 17 errors per minute during 9/24/2015 10:08:14.000 AM – 10:09:14 AM.</summary>
6292-
<explanation>17 errors were thrown in total. The most common error was ''java.lang.NoSuchMethodError'', which was thrown 13 times. Investigate the thrown errors to see if they can be avoided. Errors indicate that something went wrong with the code execution and should never be used for flow control. The following regular expression was used to exclude 381 errors from this rule: ''(com.sun.el.parser.ELParser\$LookaheadSuccess)''.</explanation>
6292+
<explanation>17 errors were thrown in total. The most common error was ''java.lang.NoSuchMethodError'', which was thrown 13 times. Investigate the thrown errors to see if they can be avoided. Errors indicate that something went wrong with the code execution and should never be used for flow control. The following regular expression was used to exclude 381 errors from this rule: ''(com.sun.el.parser.ELParser\$LookaheadSuccess)''.
6293+
The most common error stackrace was :
6294+
java.lang.Error.&amp;lt;init&amp;gt;(String):71
6295+
java.lang.LinkageError.&amp;lt;init&amp;gt;(String):55
6296+
java.lang.IncompatibleClassChangeError.&amp;lt;init&amp;gt;(String):55
6297+
java.lang.NoSuchMethodError.&amp;lt;init&amp;gt;(String):58
6298+
java.io.ObjectStreamClass.hasStaticInitializer(Class):-1
6299+
java.io.ObjectStreamClass.computeDefaultSUID(Class):1743
6300+
java.io.ObjectStreamClass.access$100(Class):72
6301+
java.io.ObjectStreamClass$1.run():250
6302+
java.io.ObjectStreamClass$1.run():248
6303+
java.security.AccessController.doPrivileged(PrivilegedAction):-1</explanation>
62936304
</rule>
62946305
<rule>
62956306
<id>Exceptions</id>

0 commit comments

Comments
 (0)