From 2b4a3f969a2c69ac1eb3e4555336f260b2932155 Mon Sep 17 00:00:00 2001 From: John OHara Date: Wed, 16 Dec 2020 11:32:01 +0000 Subject: [PATCH] Add automatic analysis from JMC. Provide some example assertions wrt rules that have fired and tests based on severity --- README.md | 40 ++++++ pom.xml | 6 + .../org/moditect/jfrunit/JfrAnalysis.java | 85 ++++++++++++ .../moditect/jfrunit/JfrAnalysisAssert.java | 124 ++++++++++++++++++ .../moditect/jfrunit/JfrAnalysisResults.java | 38 ++++++ .../java/org/moditect/jfrunit/JfrEvents.java | 42 +++++- .../org/moditect/jfrunit/JfrUnitTest.java | 37 +++++- 7 files changed, 368 insertions(+), 4 deletions(-) create mode 100644 src/main/java/org/moditect/jfrunit/JfrAnalysis.java create mode 100644 src/main/java/org/moditect/jfrunit/JfrAnalysisAssert.java create mode 100644 src/main/java/org/moditect/jfrunit/JfrAnalysisResults.java diff --git a/README.md b/README.md index 4c0c4f1..709c8af 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 dev.morling.jfrunit.*; + +import static dev.morling.jfrunit.JfrEventsAssert.*; +import static dev.morling.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/JfrAnalysis.java b/src/main/java/org/moditect/jfrunit/JfrAnalysis.java new file mode 100644 index 0000000..3c8d7ae --- /dev/null +++ b/src/main/java/org/moditect/jfrunit/JfrAnalysis.java @@ -0,0 +1,85 @@ +/* + * 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.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 JfrAnalysis { + + private static final System.Logger LOGGER = System.getLogger(JfrAnalysis.class.getName()); + + public static List analysisRecording(String fileName, Severity minSeverity) { + return JfrAnalysis.analysisRecording(fileName, minSeverity, false); + } + + public static List analysisRecording(String fileName, Severity minSeverity, boolean verbose) { + 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; + } + + // 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) { + // TODO: further results processing + analysisResults.add(result); + } + } + return analysisResults; + } + catch (Throwable t) { + System.err.println("Got exception when creating report for " + fileName); //$NON-NLS-1$ + throw t; + } + } +} diff --git a/src/main/java/org/moditect/jfrunit/JfrAnalysisAssert.java b/src/main/java/org/moditect/jfrunit/JfrAnalysisAssert.java new file mode 100644 index 0000000..db8021b --- /dev/null +++ b/src/main/java/org/moditect/jfrunit/JfrAnalysisAssert.java @@ -0,0 +1,124 @@ +/* + * 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.Optional; + +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 JfrAnalysisAssert extends AbstractAssert { + + private IResult foundResult; + + public JfrAnalysisAssert(JfrAnalysisResults results) { + super(results, JfrAnalysisAssert.class); + } + + public static JfrAnalysisAssert assertThat(JfrAnalysisResults results) { + return new JfrAnalysisAssert(results); + } + + public JfrAnalysisAssert doesNotContain(Class expectedRule) { + return findRule(expectedRule, true, "JMC Analysis result contains rule of type <%s>"); + } + + public JfrAnalysisAssert contains(Class expectedRule) { + return findRule(expectedRule); + } + + private JfrAnalysisAssert findRule(Class expectedRule) { + return findRule(expectedRule, false, "No JMC Analysis result rule of type <%s>"); + } + + private JfrAnalysisAssert findRule(Class expectedRule, boolean negate, String failureMsg) { + isNotNull(); + + Optional optionalIResult = actual.getResults().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 JfrAnalysisAssert 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 JfrAnalysisAssert scoresLessThan(Class expectedRule, double expectedScore) { + + findRule(expectedRule); + + return scoresLessThan(expectedScore); + } + + public JfrAnalysisAssert 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; + + } + + private Optional findResult(Class expectedRule) { + return actual.getResults().stream() + .filter(re -> re.getRule().getClass().equals(expectedRule)) + .findFirst(); + + } +} diff --git a/src/main/java/org/moditect/jfrunit/JfrAnalysisResults.java b/src/main/java/org/moditect/jfrunit/JfrAnalysisResults.java new file mode 100644 index 0000000..2b145ba --- /dev/null +++ b/src/main/java/org/moditect/jfrunit/JfrAnalysisResults.java @@ -0,0 +1,38 @@ +/* + * 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 org.openjdk.jmc.flightrecorder.rules.IResult; + +public class JfrAnalysisResults { + private List results; + + public JfrAnalysisResults(List analysisRecording) { + this.results = analysisRecording; + } + + public List getResults() { + return this.results; + } + + public int size() { + return this.results.size(); + } +} diff --git a/src/main/java/org/moditect/jfrunit/JfrEvents.java b/src/main/java/org/moditect/jfrunit/JfrEvents.java index 7a55124..3ed21bf 100644 --- a/src/main/java/org/moditect/jfrunit/JfrEvents.java +++ b/src/main/java/org/moditect/jfrunit/JfrEvents.java @@ -39,6 +39,7 @@ import org.moditect.jfrunit.EnableEvent.StacktracePolicy; import org.moditect.jfrunit.internal.SyncEvent; +import org.openjdk.jmc.flightrecorder.rules.Severity; import jdk.jfr.Configuration; import jdk.jfr.EventSettings; @@ -63,6 +64,8 @@ public class JfrEvents { private Recording recording; private boolean capturing; + private JfrAnalysisResults analysis = null; + public JfrEvents() { } @@ -104,8 +107,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 +118,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 +137,25 @@ void stopRecordingEvents() { } } + private Path getRecordingFilePath() 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(); + return dumpDir.resolve(fileName); + } + + void dumpRecording(Path jfrPath) throws IOException { + recording.dump(jfrPath); + } + /** * Ensures all previously emitted events have been consumed. */ @@ -305,4 +326,19 @@ private String getDumpFileName() { private String getDefaultDumpFileName() { return testMethod.getDeclaringClass().getName() + "-" + testMethod.getName() + ".jfr"; } + + public JfrAnalysisResults automaticAnalysis() { + if (analysis == null) { + try { + Path recordingPath = getRecordingFilePath(); + dumpRecording(recordingPath); + + analysis = new JfrAnalysisResults(JfrAnalysis.analysisRecording(recordingPath.toAbsolutePath().toString(), Severity.INFO)); + } + catch (IOException | URISyntaxException e) { + LOGGER.log(Level.WARNING, "Unable to analyse jfr recording: " + e.getLocalizedMessage()); + } + } + return analysis; + } } diff --git a/src/test/java/org/moditect/jfrunit/JfrUnitTest.java b/src/test/java/org/moditect/jfrunit/JfrUnitTest.java index d5462a4..06fdc8e 100644 --- a/src/test/java/org/moditect/jfrunit/JfrUnitTest.java +++ b/src/test/java/org/moditect/jfrunit/JfrUnitTest.java @@ -18,12 +18,18 @@ package org.moditect.jfrunit; import java.time.Duration; +import java.util.stream.Collectors; import org.junit.jupiter.api.DisplayName; import org.junit.jupiter.api.Test; +import org.openjdk.jmc.flightrecorder.rules.Severity; +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; import static org.moditect.jfrunit.ExpectedEvent.event; +import static org.moditect.jfrunit.JfrAnalysisAssert.assertThat; import static org.moditect.jfrunit.JfrEventsAssert.assertThat; @JfrEventTest @@ -66,7 +72,7 @@ public void shouldHaveGcAndSleepEventsWithDefaultConfiguration() throws Exceptio event("jdk.ThreadSleep").with("time", Duration.ofMillis(50))); assertThat(jfrEvents.filter( - event("jdk.GarbageCollection").with("cause", "System.gc()"))) + event("jdk.GarbageCollection").with("cause", "System.gc()")).collect(Collectors.toList())) .hasSize(1); } @@ -138,4 +144,33 @@ public void doNotCaptureTraceWhenDisabledWithStackTracePolicyExcluded() { assertThat(jfrEvents).contains(event("jfrunit.test.StackTraceDisabledSampleEvent").hasNot("stackTrace")); } + + @Test + @EnableConfiguration("profile") + public void automatedAnalysis() throws Exception { + + System.gc(); + Thread.sleep(1000); + + jfrEvents.awaitEvents(); + + JfrAnalysisResults analysisResults = jfrEvents.automaticAnalysis(); + + assertNotNull(analysisResults); + + assertThat(analysisResults.size()).isGreaterThan(0); + + // 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); + + } }