Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add automatic analysis from JMC #85

Draft
wants to merge 2 commits into
base: main
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
40 changes: 40 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What does that score mean?

Taking a step back, I'm still trying to wrap my head around the capabilities of the JMC rules. Are there other real-world examples coming to mind which would show the power of that feature?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Each rule can generate a score between 0-100. It roughly translates to the risk rating of a problem that has been detected. 0 being least likely to cause an issue to 100 being most likely to be problem. The score implementation is specific to the Rule that is triggered.

e.g. for the ExceptionRule it is a score based on number of exceptions per second : https://github.com/openjdk/jmc/blob/master/core/org.openjdk.jmc.flightrecorder.rules.jdk/src/main/java/org/openjdk/jmc/flightrecorder/rules/jdk/exceptions/ExceptionRule.java#L109

For the SockertWriteRule, it is score calculated from the maximum duration of all socket writes: https://github.com/openjdk/jmc/blob/master/core/org.openjdk.jmc.flightrecorder.rules.jdk/src/main/java/org/openjdk/jmc/flightrecorder/rules/jdk/io/SocketWriteRule.java#L135

This assertion allows users who are familiar with the Rules to assert that risk scores did not cross a certain threshold

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, I see. Aren't we back to relying on characteristics of the environment then though? E.g. Exceptions per second might differ on the general performance and load of the machine running the test. So I'm wondering how stable/portable such test would be.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe they were poor examples, I think some of the rules will be dependent on environment and others not. At present all the rules available from JMC are loaded. Maybe I could curate a list of Rules that do not rely on environment and only load them?

}
```

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
Expand Down
6 changes: 6 additions & 0 deletions pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,7 @@
<maven.compiler.parameters>true</maven.compiler.parameters>
<quarkus.platform.version>2.3.0.Final</quarkus.platform.version>
<version.surefire.plugin>3.0.0-M5</version.surefire.plugin>
<jmc.version>8.0.1</jmc.version>
</properties>

<scm>
Expand Down Expand Up @@ -113,6 +114,11 @@
<type>pom</type>
<scope>provided</scope>
</dependency>
<dependency>
<groupId>org.openjdk.jmc</groupId>
<artifactId>flightrecorder.rules.jdk</artifactId>
<version>${jmc.version}</version>
</dependency>
</dependencies>

<build>
Expand Down
63 changes: 57 additions & 6 deletions src/main/java/org/moditect/jfrunit/JfrEvents.java
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -63,6 +67,8 @@ public class JfrEvents {
private Recording recording;
private boolean capturing;

private AtomicInteger analysisCounter = new AtomicInteger(0);

public JfrEvents() {
}

Expand Down Expand Up @@ -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;
Expand All @@ -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);
Expand All @@ -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.
*/
Expand Down Expand Up @@ -293,16 +321,39 @@ private List<EventConfiguration> matchEventTypes(List<EventConfiguration> 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";
}
}

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<IResult> 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);
}
}
}
171 changes: 171 additions & 0 deletions src/main/java/org/moditect/jfrunit/JmcAutomaticAnalysisAssert.java
Original file line number Diff line number Diff line change
@@ -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<JmcAutomaticAnalysisAssert, List<IResult>> {

private IResult foundResult;
private static final String LS = System.getProperty("line.separator");

public JmcAutomaticAnalysisAssert(List<IResult> results) {
super(results, JmcAutomaticAnalysisAssert.class);
}

public static JmcAutomaticAnalysisAssert assertThat(List<IResult> results) {
return new JmcAutomaticAnalysisAssert(results);
}

public JmcAutomaticAnalysisAssert doesNotContain(Class<? extends IRule> expectedRule) {
return findRule(expectedRule, true, "JMC Analysis result contains rule of type <%s>");
}

public JmcAutomaticAnalysisAssert contains(Class<? extends IRule> expectedRule) {
return findRule(expectedRule);
}

private JmcAutomaticAnalysisAssert findRule(Class<? extends IRule> expectedRule) {
return findRule(expectedRule, false, "No JMC Analysis result rule of type <%s>");
}

private JmcAutomaticAnalysisAssert findRule(Class<? extends IRule> expectedRule, boolean negate, String failureMsg) {
isNotNull();

Optional<IResult> 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<? extends IRule> expectedRule, Severity expectedSeverity) {
Optional<IResult> 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<? extends IRule> 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<? extends IRule> rule) {
actual
.stream()
.filter(result -> result.getRule().equals(rule)).forEach(filtered -> actual.remove(filtered));
return this;
}

public JmcAutomaticAnalysisAssert haveSeverityGreaterThan(Severity expectedSeverity) {
List<IResult> 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<IResult> 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<IResult> filterBySeverity(Severity expectedSeverity, BiFunction<Severity, Severity, Boolean> severityComparator) {
return actual
.stream()
.filter(result -> severityComparator.apply(expectedSeverity, result.getSeverity()))
.collect(Collectors.toList());
}

private Optional<IResult> findResult(Class<? extends IRule> expectedRule) {
return actual.stream()
.filter(re -> re.getRule().getClass().equals(expectedRule))
.findFirst();

}
}
Loading