diff --git a/README.md b/README.md index 4c0c4f1..f527eb8 100644 --- a/README.md +++ b/README.md @@ -135,10 +135,50 @@ As you can see you can use custom DSL when checking the expected state. * The `RecordedEvent` itself is extended with dynamic properties so you can just use `event.time` or `event.bytesWritten` etc. This might be handy when you need an aggregation like this `jfrEvents['jdk.FileWrite']*.bytesWritten.sum() == expectedBytes` +## Automatic Analysis + + +Java Mission Control provides an Automatic Analysis tool that performs pattern analysis on recorded JFR events to determine common performance issues with Java applications. + +It is possible to write assertions against the Automatic Analysis results to verify that unit tests against common performance issues: + +```java +import org.moditect.jfrunit.*; + +import static org.moditect.jfrunit.JfrEventsAssert.*; +import static org.moditect.jfrunit.ExpectedEvent.*; + +@Test +@EnableConfiguration("profile") +public void automaticAnalysisTest() throws Exception { + System.gc(); + Thread.sleep(1000); + + jfrEvents.awaitEvents(); + + JfrAnalysisResults analysisResults = jfrEvents.automaticAnalysis(); + + //Inspect rules that fired + assertThat(analysisResults).contains(FullGcRule.class); + assertThat(analysisResults).doesNotContain(HeapDumpRule.class); + + //Inspect severity of rule + assertThat(analysisResults).hasSeverity(FullGcRule.class, Severity.WARNING); + + //Inspect score of rule + assertThat(analysisResults) + .contains(FullGcRule.class) + .scoresLessThan(80); + } +``` + +A full list of JMC Analysis rules can be found [here](https://docs.oracle.com/en/java/java-components/jdk-mission-control/8/jmc-flightrecorder-rules-jdk/org.openjdk.jmc.flightrecorder.rules.jdk/module-summary.html). + ## Build This project requires OpenJDK 14 or later for its build. Apache Maven is used for the build. + Run the following to build the project: ```shell diff --git a/pom.xml b/pom.xml index 0651887..20edc7e 100644 --- a/pom.xml +++ b/pom.xml @@ -49,6 +49,7 @@ true 2.3.0.Final 3.0.0-M5 + 8.0.1 @@ -113,6 +114,11 @@ pom provided + + org.openjdk.jmc + flightrecorder.rules.jdk + ${jmc.version} + diff --git a/src/main/java/org/moditect/jfrunit/JfrEvents.java b/src/main/java/org/moditect/jfrunit/JfrEvents.java index 7a55124..7d9107f 100644 --- a/src/main/java/org/moditect/jfrunit/JfrEvents.java +++ b/src/main/java/org/moditect/jfrunit/JfrEvents.java @@ -32,13 +32,17 @@ import java.util.Queue; import java.util.concurrent.ConcurrentLinkedQueue; import java.util.concurrent.CountDownLatch; +import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicLong; import java.util.function.Predicate; import java.util.regex.Pattern; import java.util.stream.Stream; import org.moditect.jfrunit.EnableEvent.StacktracePolicy; +import org.moditect.jfrunit.internal.JmcAutomaticAnalysis; import org.moditect.jfrunit.internal.SyncEvent; +import org.openjdk.jmc.flightrecorder.rules.IResult; +import org.openjdk.jmc.flightrecorder.rules.Severity; import jdk.jfr.Configuration; import jdk.jfr.EventSettings; @@ -63,6 +67,8 @@ public class JfrEvents { private Recording recording; private boolean capturing; + private AtomicInteger analysisCounter = new AtomicInteger(0); + public JfrEvents() { } @@ -104,8 +110,7 @@ void stopRecordingEvents() { LOGGER.log(Level.WARNING, "'" + testSourceUri.getScheme() + "' is not a valid file system, dumping recording to a temporary location."); } - String fileName = getDumpFileName(); - Path recordingPath = dumpDir.resolve(fileName); + Path recordingPath = getRecordingFilePath(); LOGGER.log(Level.INFO, "Stop recording: " + recordingPath); capturing = false; @@ -116,7 +121,7 @@ void stopRecordingEvents() { catch (IOException ex) { LOGGER.log(Level.WARNING, "Could not dump to: " + recordingPath, ex); String defaultFileName = getDefaultDumpFileName(); - if (!defaultFileName.equals(fileName)) { + if (!defaultFileName.equals(recordingPath.getFileName().toString())) { // perhaps the FS was not able to handle special characters recordingPath = dumpDir.resolve(defaultFileName); LOGGER.log(Level.INFO, "Retrying dump: " + recordingPath); @@ -135,6 +140,29 @@ void stopRecordingEvents() { } } + private Path getRecordingFilePath() throws URISyntaxException, IOException { + return getRecordingFilePath(null); + } + + private Path getRecordingFilePath(String suffix) throws URISyntaxException, IOException { + URI testSourceUri = testMethod.getDeclaringClass().getProtectionDomain().getCodeSource().getLocation().toURI(); + Path dumpDir; + try { + dumpDir = Files.createDirectories(Path.of(testSourceUri).getParent().resolve("jfrunit")); + + } + catch (FileSystemNotFoundException e) { + dumpDir = Files.createTempDirectory(null); + LOGGER.log(Level.WARNING, "'" + testSourceUri.getScheme() + "' is not a valid file system, dumping recording to a temporary location."); + } + String fileName = getDumpFileName(suffix); + return dumpDir.resolve(fileName); + } + + void dumpRecording(Path jfrPath) throws IOException { + recording.dump(jfrPath); + } + /** * Ensures all previously emitted events have been consumed. */ @@ -293,9 +321,9 @@ private List matchEventTypes(List enable return allEvents; } - private String getDumpFileName() { + private String getDumpFileName(String suffix) { if (dumpFileName == null) { - return getDefaultDumpFileName(); + return getDefaultDumpFileName(suffix); } else { return dumpFileName.endsWith(".jfr") ? dumpFileName : dumpFileName + ".jfr"; @@ -303,6 +331,29 @@ private String getDumpFileName() { } private String getDefaultDumpFileName() { - return testMethod.getDeclaringClass().getName() + "-" + testMethod.getName() + ".jfr"; + return getDefaultDumpFileName(null); + } + + private String getDefaultDumpFileName(String suffix) { + return testMethod.getDeclaringClass().getName() + "-" + testMethod.getName() + (suffix != null ? "-" + suffix : "") + ".jfr"; + } + + // TODO: Do we move out of JfrEvents? + public List automaticAnalysis() { + try { + awaitEvents(); + + int counter = analysisCounter.getAndIncrement(); + Path recordingPath = getRecordingFilePath("analysis" + (counter != 0 ? "-" + counter : "")); + + LOGGER.log(Level.INFO, "Analysis recording: " + recordingPath.toAbsolutePath()); + dumpRecording(recordingPath); + + return JmcAutomaticAnalysis.analysisRecording(recordingPath.toAbsolutePath().toString(), Severity.INFO); + + } + catch (IOException | URISyntaxException e) { + throw new RuntimeException("Unable to analyse jfr recording", e); + } } } diff --git a/src/main/java/org/moditect/jfrunit/JmcAutomaticAnalysisAssert.java b/src/main/java/org/moditect/jfrunit/JmcAutomaticAnalysisAssert.java new file mode 100644 index 0000000..be774ed --- /dev/null +++ b/src/main/java/org/moditect/jfrunit/JmcAutomaticAnalysisAssert.java @@ -0,0 +1,171 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * + * Copyright 2020 - 2021 The JfrUnit authors. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.moditect.jfrunit; + +import java.util.List; +import java.util.Optional; +import java.util.function.BiFunction; +import java.util.stream.Collectors; + +import org.assertj.core.api.AbstractAssert; +import org.openjdk.jmc.common.unit.IQuantity; +import org.openjdk.jmc.flightrecorder.rules.IResult; +import org.openjdk.jmc.flightrecorder.rules.IRule; +import org.openjdk.jmc.flightrecorder.rules.Severity; +import org.openjdk.jmc.flightrecorder.rules.TypedResult; + +public class JmcAutomaticAnalysisAssert extends AbstractAssert> { + + private IResult foundResult; + private static final String LS = System.getProperty("line.separator"); + + public JmcAutomaticAnalysisAssert(List results) { + super(results, JmcAutomaticAnalysisAssert.class); + } + + public static JmcAutomaticAnalysisAssert assertThat(List results) { + return new JmcAutomaticAnalysisAssert(results); + } + + public JmcAutomaticAnalysisAssert doesNotContain(Class expectedRule) { + return findRule(expectedRule, true, "JMC Analysis result contains rule of type <%s>"); + } + + public JmcAutomaticAnalysisAssert contains(Class expectedRule) { + return findRule(expectedRule); + } + + private JmcAutomaticAnalysisAssert findRule(Class expectedRule) { + return findRule(expectedRule, false, "No JMC Analysis result rule of type <%s>"); + } + + private JmcAutomaticAnalysisAssert findRule(Class expectedRule, boolean negate, String failureMsg) { + isNotNull(); + + Optional optionalIResult = actual.stream() + .filter(re -> re.getRule().getClass().equals(expectedRule)) + .findAny(); + + boolean found = optionalIResult + .isPresent(); + + if (negate ? found : !found) { + failWithMessage(failureMsg, expectedRule.getName()); + } + else { + if (!negate) { + this.foundResult = optionalIResult.get(); + } + } + + return this; + + } + + public JmcAutomaticAnalysisAssert hasSeverity(Class expectedRule, Severity expectedSeverity) { + Optional resultOptional = findResult(expectedRule); + + if (!resultOptional.isPresent()) { + failWithMessage("No analysis type for <%s>", expectedRule.getName()); + } + else { + IResult result = resultOptional.get(); + + if (result.getSeverity().getLimit() < expectedSeverity.getLimit()) { + failWithMessage("Analysis result not required severity <%s>", expectedSeverity); + + } + } + return this; + } + + public JmcAutomaticAnalysisAssert scoresLessThan(Class expectedRule, double expectedScore) { + + findRule(expectedRule); + + return scoresLessThan(expectedScore); + } + + public JmcAutomaticAnalysisAssert scoresLessThan(double expectedScore) { + IQuantity resultScore = this.foundResult.getResult(TypedResult.SCORE); + double score = 0; + if (resultScore != null) { + score = resultScore.doubleValue(); + } + else if (this.foundResult.getSeverity().getLimit() != 0.0d) { + score = this.foundResult.getSeverity().getLimit(); + } + + if (score > expectedScore) { + failWithMessage("Analysis result score exceeds threshold: actual <%.1f>, threshold <%.1f>", score, expectedScore); + } + return this; + + } + + public JmcAutomaticAnalysisAssert removeRuleFromResults(Class rule) { + actual + .stream() + .filter(result -> result.getRule().equals(rule)).forEach(filtered -> actual.remove(filtered)); + return this; + } + + public JmcAutomaticAnalysisAssert haveSeverityGreaterThan(Severity expectedSeverity) { + List filterResults = filterBySeverity(expectedSeverity, (expected, actualSeverity) -> actualSeverity.compareTo(expectedSeverity) < 0); + if (filterResults.size() == 0) { + failWithMessage("Expected to contain severity greater than: " + expectedSeverity.getLocalizedName()); + } + return this; + } + + public JmcAutomaticAnalysisAssert haveSeverityLessThan(Severity expectedSeverity) { + List filterResults = filterBySeverity(expectedSeverity, (expected, actualSeverity) -> actualSeverity.compareTo(expectedSeverity) >= 0); + + if (filterResults.size() > 0) { + StringBuilder reportBuilder = new StringBuilder(); + reportBuilder.append("Analysis result score equals or exceeds threshold: ") + .append(expectedSeverity.getLocalizedName()) + .append(LS).append(LS); + + filterResults.forEach(result -> { + reportBuilder.append(result.getSummary()) + .append(LS) + .append(result.getExplanation()) + .append(LS).append(LS); + }); + failWithMessage(reportBuilder.toString()); + } + return this; + + } + + private List filterBySeverity(Severity expectedSeverity, BiFunction severityComparator) { + return actual + .stream() + .filter(result -> severityComparator.apply(expectedSeverity, result.getSeverity())) + .collect(Collectors.toList()); + } + + private Optional findResult(Class expectedRule) { + return actual.stream() + .filter(re -> re.getRule().getClass().equals(expectedRule)) + .findFirst(); + + } +} diff --git a/src/main/java/org/moditect/jfrunit/internal/JmcAutomaticAnalysis.java b/src/main/java/org/moditect/jfrunit/internal/JmcAutomaticAnalysis.java new file mode 100644 index 0000000..dd1fdae --- /dev/null +++ b/src/main/java/org/moditect/jfrunit/internal/JmcAutomaticAnalysis.java @@ -0,0 +1,86 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * + * Copyright 2020 - 2021 The JfrUnit authors. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ +package org.moditect.jfrunit.internal; + +import java.io.File; +import java.io.IOException; +import java.util.*; +import java.util.concurrent.Future; + +import org.openjdk.jmc.common.item.IItemCollection; +import org.openjdk.jmc.flightrecorder.CouldNotLoadRecordingException; +import org.openjdk.jmc.flightrecorder.JfrLoaderToolkit; +import org.openjdk.jmc.flightrecorder.rules.IResult; +import org.openjdk.jmc.flightrecorder.rules.IRule; +import org.openjdk.jmc.flightrecorder.rules.RuleRegistry; +import org.openjdk.jmc.flightrecorder.rules.Severity; +import org.openjdk.jmc.flightrecorder.rules.util.RulesToolkit; + +public class JmcAutomaticAnalysis { + + private static final System.Logger LOGGER = System.getLogger(JmcAutomaticAnalysis.class.getName()); + + public static List analysisRecording(String fileName, Severity minSeverity) { + try { + File file = new File(fileName); + + IItemCollection events; + try { + events = JfrLoaderToolkit.loadEvents(file); + } + catch (IOException | CouldNotLoadRecordingException e) { + LOGGER.log(System.Logger.Level.ERROR, "Unable to analyse jfr recording: " + e.getLocalizedMessage()); + return null; + } + return analyseEvents(events, minSeverity); + + } + catch (Throwable t) { + System.err.println("Got exception when creating report for " + fileName); //$NON-NLS-1$ + throw t; + } + } + + public static List analyseEvents(IItemCollection events, Severity minSeverity) { + // TODO: Provide configuration + Map> resultFutures = RulesToolkit.evaluateParallel(RuleRegistry.getRules(), events, + null, 0); + List>> resultFutureList = new ArrayList<>(resultFutures.entrySet()); + Collections.sort(resultFutureList, Comparator.comparing(o -> o.getKey().getId())); + + List analysisResults = new ArrayList(); + + for (Map.Entry> resultEntry : resultFutureList) { + IResult result; + try { + result = resultEntry.getValue().get(); + } + catch (Throwable t) { + LOGGER.log(System.Logger.Level.WARNING, "Unable to analyse analysis result: " + t.getLocalizedMessage()); + continue; + } + + if (result != null && result.getSeverity().compareTo(minSeverity) >= 0) { + analysisResults.add(result); + } + } + return analysisResults; + + } + +} diff --git a/src/test/java/org/moditect/jfrunit/JfrUnitTest.java b/src/test/java/org/moditect/jfrunit/JfrUnitTest.java index d5462a4..5475cd1 100644 --- a/src/test/java/org/moditect/jfrunit/JfrUnitTest.java +++ b/src/test/java/org/moditect/jfrunit/JfrUnitTest.java @@ -138,4 +138,5 @@ public void doNotCaptureTraceWhenDisabledWithStackTracePolicyExcluded() { assertThat(jfrEvents).contains(event("jfrunit.test.StackTraceDisabledSampleEvent").hasNot("stackTrace")); } + } diff --git a/src/test/java/org/moditect/jfrunit/JmcAutomaticAnalysisTest.java b/src/test/java/org/moditect/jfrunit/JmcAutomaticAnalysisTest.java new file mode 100644 index 0000000..226093c --- /dev/null +++ b/src/test/java/org/moditect/jfrunit/JmcAutomaticAnalysisTest.java @@ -0,0 +1,92 @@ +/* + * SPDX-License-Identifier: Apache-2.0 + * + * Copyright 2020 - 2021 The JfrUnit authors. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * https://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package org.moditect.jfrunit; + +import java.util.List; + +import javax.el.MethodNotFoundException; + +import org.junit.jupiter.api.Test; +import org.openjdk.jmc.flightrecorder.rules.IResult; +import org.openjdk.jmc.flightrecorder.rules.Severity; +import org.openjdk.jmc.flightrecorder.rules.jdk.general.StackDepthSettingRule; +import org.openjdk.jmc.flightrecorder.rules.jdk.memory.FullGcRule; +import org.openjdk.jmc.flightrecorder.rules.jdk.memory.HeapDumpRule; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.junit.jupiter.api.Assertions.assertNotNull; + +@JfrEventTest +public class JmcAutomaticAnalysisTest { + + public JfrEvents jfrEvents = new JfrEvents(); + + @Test + @EnableConfiguration("profile") + public void automatedAnalysis() throws Exception { + + System.gc(); + Thread.sleep(1000); + + jfrEvents.awaitEvents(); + + List analysisResults = jfrEvents.automaticAnalysis(); + + assertNotNull(analysisResults); + + assertThat(analysisResults.size()).isGreaterThan(0); + + // Inspect rules that fired + JmcAutomaticAnalysisAssert.assertThat(analysisResults).contains(FullGcRule.class); + JmcAutomaticAnalysisAssert.assertThat(analysisResults).doesNotContain(HeapDumpRule.class); + + // Inspect severity of rule + JmcAutomaticAnalysisAssert.assertThat(analysisResults).hasSeverity(FullGcRule.class, Severity.WARNING); + + // Inspect score of rule + JmcAutomaticAnalysisAssert.assertThat(analysisResults) + .contains(FullGcRule.class) + .scoresLessThan(80); + + } + + @Test + @EnableConfiguration("profile") + public void automatedExceptionAnalysis() throws Exception { + + for (int i = 0; i < 20_000; i++) { + try { + throw new MethodNotFoundException(); + } + catch (MethodNotFoundException methodNotFoundException) { + // silently swallow exception + } + } + + List analysisResults = jfrEvents.automaticAnalysis(); + + assertThat(analysisResults.size()).isGreaterThan(0); + + JmcAutomaticAnalysisAssert.assertThat(analysisResults) + .removeRuleFromResults(StackDepthSettingRule.class) + .haveSeverityGreaterThan(Severity.WARNING); + + } + +}