Skip to content

Correct log text for JFR perf test thresholds #373

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.

Sign up for GitHub

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

Open
wants to merge 3 commits into
base: master
Choose a base branch
from
Open

Correct log text for JFR perf test thresholds #373

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
8a605e9
correct log text for JFR perf tests
roberttoyonaga Sep 29, 2025
32c99c0
text spacing
roberttoyonaga Sep 29, 2025
d089e0d
update readme
roberttoyonaga Sep 30, 2025
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
6 changes: 6 additions & 0 deletions README.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -138,6 +138,12 @@ e.g.
linux.jvm.time.to.finish.threshold.ms=6924
linux.native.time.to.finish.threshold.ms=14525
```
Most thresholds are defined as absolute values. However, there are some thresholds that are percentages. These types of thresholds are used for tests where two versions are compared against eachother. This means the % difference between the versions must not exceed the defined threshold. Such cases look like the example below.

```
linux.diff_native.RSS.threshold.percent=35
linux.diff_native.executable.size.threshold.percent=20
```

The current `.conf` format enhances `.properties` format with the power of using the
annotation strings, see:
Expand Down
38 changes: 19 additions & 19 deletions apps/jfr-native-image-performance/threshold.conf
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,23 +1,23 @@
linux.diff_native.time.to.first.ok.request.threshold.ms=80
linux.diff_native.RSS.threshold.kB=35
linux.diff_native.executable.size.threshold.kB=20
linux.diff_native.p50.latency=50
linux.diff_native.mean.latency=50
linux.diff_native.p90.latency=78
linux.diff_native.time.to.first.ok.request.threshold.percent=80
linux.diff_native.RSS.threshold.percent=35
linux.diff_native.executable.size.threshold.percent=20
linux.diff_native.p50.latency.percent=50
linux.diff_native.mean.latency.percent=50
linux.diff_native.p90.latency.percent=78

macos.diff_native.time.to.first.ok.request.threshold.ms=40
macos.diff_native.RSS.threshold.kB=38
macos.diff_native.executable.size.threshold.kB=0
macos.diff_native.p50.latency=30
macos.diff_native.mean.latency=30
macos.diff_native.p90.latency=30
macos.diff_native.time.to.first.ok.request.threshold.percent=40
macos.diff_native.RSS.threshold.percent=38
macos.diff_native.executable.size.threshold.percent=0
macos.diff_native.p50.latency.percent=30
macos.diff_native.mean.latency.percent=30
macos.diff_native.p90.latency.percent=30

linux.container.diff_native.time.to.first.ok.request.threshold.ms=80
linux.container.diff_native.RSS.threshold.kB=50
linux.container.diff_native.executable.size.threshold.kB=20
linux.container.diff_native.p50.latency=80
linux.container.diff_native.mean.latency=50
linux.container.diff_native.p90.latency=100
linux.container.diff_native.time.to.first.ok.request.threshold.percent=80
linux.container.diff_native.RSS.threshold.percent=50
linux.container.diff_native.executable.size.threshold.percent=20
linux.container.diff_native.p50.latency.percent=80
linux.container.diff_native.mean.latency.percent=50
linux.container.diff_native.p90.latency.percent=100

@IfQuarkusVersion(min ="3.7.0")
linux.container.diff_native.RSS.threshold.kB=57
linux.container.diff_native.RSS.threshold.percent=57
95 changes: 67 additions & 28 deletions testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,9 @@
* @author Michal Karm Babacek <[email protected]>
*/
public class Logs {
private static final String KB_prefix = ".kB";
private static final String MS_prefix = ".ms";
private static final String PERCENT_prefix = ".percent";
private static final Logger LOGGER = Logger.getLogger(Logs.class.getName());
private static final Pattern WARN_ERROR_DETECTION_PATTERN = Pattern.compile("(?i:.*(ERROR|SEVERE|WARN|No such file|Not found|unknown).*)");
public static final long SKIP = -1L;
Expand Down Expand Up @@ -95,12 +98,12 @@ public String toString() {
}
}

public static void checkThreshold(Apps app, Mode mode, long executableSizeKb, long rssKb, long timeToFirstOKRequest,
public static void checkThreshold(Apps app, Mode mode, long executableSize, long rss, long timeToFirstOKRequest,
long timeToFinishMs, long mean, long p50, long p90) {

final Path properties = Path.of(BASE_DIR, app.dir, "threshold.conf");
if (app.thresholdProperties.isEmpty() &&
(executableSizeKb != SKIP || rssKb != SKIP || timeToFirstOKRequest != SKIP || timeToFinishMs != SKIP)) {
(executableSize != SKIP || rss != SKIP || timeToFirstOKRequest != SKIP || timeToFinishMs != SKIP)) {
LOGGER.warn("It seem there is no " +properties +
". Skipping checking thresholds.");
return;
Expand All @@ -110,44 +113,62 @@ public static void checkThreshold(Apps app, Mode mode, long executableSizeKb, lo
((mode != Mode.NONE) ? "." + mode : "");
final List<String> failures = new ArrayList<>();

if (executableSizeKb != SKIP) {
final String key = propPrefix + ".executable.size.threshold.kB";
if (app.thresholdProperties.containsKey(key)) {
long executableSizeThresholdKb = app.thresholdProperties.get(key);
assertThreshold(failures, executableSizeKb <= executableSizeThresholdKb,
if (executableSize != SKIP) {
final String key = propPrefix + ".executable.size.threshold";
if (app.thresholdProperties.containsKey(key + KB_prefix)) {
long executableSizeThreshold = app.thresholdProperties.get(key + KB_prefix);
assertThreshold(failures, executableSize <= executableSizeThreshold,
"Application " + app + (mode != null ? " in mode " + mode : "") + " executable size " +
((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? "overhead is" : "is ") +
executableSizeKb + " kB, which is over " +
executableSizeThresholdKb + " kB threshold by " + percentageValOverTh(executableSizeKb, executableSizeThresholdKb) + "%.", false);
executableSize + " kB, which is over " +
executableSizeThreshold + " kB threshold by " + percentageValOverTh(executableSize, executableSizeThreshold) + "%.", false);
} else if (app.thresholdProperties.containsKey(key + PERCENT_prefix)) {
long executableSizeThreshold = app.thresholdProperties.get(key + PERCENT_prefix);
assertThreshold(failures, executableSize <= executableSizeThreshold,
"Application " + app + (mode != null ? " in mode " + mode : "") + " executable size " +
executableSize + " % more than the control, which is over the " +
executableSizeThreshold + " % threshold", false);
} else {
LOGGER.error("executableSizeKb was to be checked, but there is no " + key + " in " + properties);
LOGGER.error("executableSize was to be checked, but there is no " + key + KB_prefix+ " or " + key + PERCENT_prefix + " in " + properties);
}
}

if (timeToFirstOKRequest != SKIP) {
final String key = propPrefix + ".time.to.first.ok.request.threshold.ms";
if (app.thresholdProperties.containsKey(key)) {
long timeToFirstOKRequestThresholdMs = app.thresholdProperties.get(key);
assertThreshold(failures, timeToFirstOKRequest <= timeToFirstOKRequestThresholdMs,
final String key = propPrefix + ".time.to.first.ok.request.threshold";
if (app.thresholdProperties.containsKey(key + MS_prefix)) {
long timeToFirstOKRequestThreshold = app.thresholdProperties.get(key + MS_prefix);
assertThreshold(failures, timeToFirstOKRequest <= timeToFirstOKRequestThreshold,
"Application " + app + (mode != null ? " in mode " + mode : "") +
" took " + timeToFirstOKRequest + " ms " + ((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? "more " : "") +
"to get the first OK request, which is over " +
timeToFirstOKRequestThresholdMs + " ms threshold by " + percentageValOverTh(timeToFirstOKRequest, timeToFirstOKRequestThresholdMs) + "%.", true);
timeToFirstOKRequestThreshold + " ms threshold by " + percentageValOverTh(timeToFirstOKRequest, timeToFirstOKRequestThreshold) + "%.", true);
} else if (app.thresholdProperties.containsKey(key + PERCENT_prefix)) {
long timeToFirstOKRequestThreshold = app.thresholdProperties.get(key + PERCENT_prefix);
assertThreshold(failures, timeToFirstOKRequest <= timeToFirstOKRequestThreshold,
"Application " + app + (mode != null ? " in mode " + mode : "") +
" took " + timeToFirstOKRequest + " % longer than the control to get the first OK request, which is over " +
timeToFirstOKRequestThreshold + " % threshold", true);
} else {
LOGGER.error("timeToFirstOKRequest was to be checked, but there is no " + key + " in " + properties);
LOGGER.error("timeToFirstOKRequest was to be checked, but there is no " + key + MS_prefix + " or " + key + PERCENT_prefix + " in " + properties);
}
}

if (rssKb != SKIP) {
final String key = propPrefix + ".RSS.threshold.kB";
if (app.thresholdProperties.containsKey(key)) {
long rssThresholdKb = app.thresholdProperties.get(key);
assertThreshold(failures, rssKb <= rssThresholdKb,
if (rss != SKIP) {
final String key = propPrefix + ".RSS.threshold";
if (app.thresholdProperties.containsKey(key + KB_prefix)) {
long rssThreshold = app.thresholdProperties.get(key + KB_prefix);
assertThreshold(failures, rss <= rssThreshold,
"Application " + app + (mode != null ? " in mode " + mode : "") +
" consumed " + rssKb + " kB of RSS memory " + ((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? "more " : "") + ", which is over " +
rssThresholdKb + " kB threshold by " + percentageValOverTh(rssKb, rssThresholdKb) + "%.", false);
} else {
LOGGER.error("rssKb was to be checked, but there is no " + key + " in " + properties);
" consumed " + rss + " kB of RSS memory " + ((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? "more " : "") + ", which is over " +
rssThreshold + " kB threshold by " + percentageValOverTh(rss, rssThreshold) + "%.", false);
} else if (app.thresholdProperties.containsKey(key + PERCENT_prefix)) {
long rssThreshold = app.thresholdProperties.get(key + PERCENT_prefix);
assertThreshold(failures, rss <= rssThreshold,
"Application " + app + (mode != null ? " in mode " + mode : "") +
" consumed " + rss + " % more RSS memory than the control, which is over the " +
rssThreshold + " % threshold", false);
}else {
LOGGER.error("rss was to be checked, but there is no " + key + KB_prefix + " or " + key + PERCENT_prefix + " in " + properties);
}
}

Expand All @@ -172,8 +193,14 @@ public static void checkThreshold(Apps app, Mode mode, long executableSizeKb, lo
"Application " + app + (mode != null ? " in mode " + mode : "") + " has mean response latency " +
mean + ((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? " more" : " ") + ", which is over " +
meanThreshold + " threshold by " + percentageValOverTh(mean, meanThreshold) + "%.", true);
} else if (app.thresholdProperties.containsKey(key + PERCENT_prefix)) {
long meanThreshold = app.thresholdProperties.get(key + PERCENT_prefix);
assertThreshold(failures, mean <= meanThreshold,
"Application " + app + (mode != null ? " in mode " + mode : "") + " has mean response latency " +
mean + "% more than the control, which is over " +
meanThreshold + " % threshold.", true);
} else {
LOGGER.error("mean was to be checked, but there is no " + key + " in " + properties);
LOGGER.error("mean was to be checked, but there is no " + key + " or " + key + PERCENT_prefix + " in " + properties);
}
}

Expand All @@ -185,8 +212,14 @@ public static void checkThreshold(Apps app, Mode mode, long executableSizeKb, lo
"Application " + app + (mode != null ? " in mode " + mode : "") + " has p50 response latency " +
p50 + ((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? " more" : "") + ", which is over " +
p50Threshold + " threshold by " + percentageValOverTh(p50, p50Threshold) + "%.", true);
} else if (app.thresholdProperties.containsKey(key + PERCENT_prefix)) {
long p50Threshold = app.thresholdProperties.get(key + PERCENT_prefix);
assertThreshold(failures, p50 <= p50Threshold,
"Application " + app + (mode != null ? " in mode " + mode : "") + " has p50 response latency " +
p50 + "% more than the control, which is over " +
p50Threshold + " % threshold", true);
} else {
LOGGER.error("p99 was to be checked, but there is no " + key + " in " + properties);
LOGGER.error("p99 was to be checked, but there is no " + key + " or " + key + PERCENT_prefix + " in " + properties);
}
}

Expand All @@ -198,8 +231,14 @@ public static void checkThreshold(Apps app, Mode mode, long executableSizeKb, lo
"Application " + app + (mode != null ? " in mode " + mode : "") + " has p90 response latency " +
p90 + ((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? " more" : "") + ", which is over " +
p90Threshold + " threshold by " + percentageValOverTh(p90, p90Threshold) + "%.", true);
} else if (app.thresholdProperties.containsKey(key + PERCENT_prefix)) {
long p90Threshold = app.thresholdProperties.get(key + PERCENT_prefix);
assertThreshold(failures, p90 <= p90Threshold,
"Application " + app + (mode != null ? " in mode " + mode : "") + " has p90 response latency " +
p90 + " % more than the control, which is over " +
p90Threshold + " % threshold", true);
} else {
LOGGER.error("p90 was to be checked, but there is no " + key + " in " + properties);
LOGGER.error("p90 was to be checked, but there is no " + key + " or " + key + PERCENT_prefix + "in " + properties);
}
}

Expand Down
Loading