From 8a605e963e5e793849b2bc61085f446e996abfb4 Mon Sep 17 00:00:00 2001 From: Robert Toyonaga Date: Mon, 29 Sep 2025 17:51:56 -0400 Subject: [PATCH 1/3] correct log text for JFR perf tests --- .../threshold.conf | 38 +++---- .../graalvm/tests/integration/utils/Logs.java | 99 +++++++++++++------ 2 files changed, 90 insertions(+), 47 deletions(-) diff --git a/apps/jfr-native-image-performance/threshold.conf b/apps/jfr-native-image-performance/threshold.conf index af208264..1048b726 100644 --- a/apps/jfr-native-image-performance/threshold.conf +++ b/apps/jfr-native-image-performance/threshold.conf @@ -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 diff --git a/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java b/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java index 78af7234..a03a13d1 100644 --- a/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java +++ b/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java @@ -47,6 +47,9 @@ * @author Michal Karm Babacek */ 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; @@ -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; @@ -110,44 +113,66 @@ public static void checkThreshold(Apps app, Mode mode, long executableSizeKb, lo ((mode != Mode.NONE) ? "." + mode : ""); final List 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); } } @@ -172,8 +197,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); } } @@ -185,8 +216,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); } } @@ -198,8 +235,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); } } From 32c99c0d30d72550012201b974fb04b5c6bcdcce Mon Sep 17 00:00:00 2001 From: Robert Toyonaga Date: Mon, 29 Sep 2025 17:57:10 -0400 Subject: [PATCH 2/3] text spacing --- .../graalvm/tests/integration/utils/Logs.java | 28 ++++++++----------- 1 file changed, 12 insertions(+), 16 deletions(-) diff --git a/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java b/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java index a03a13d1..82b3ab79 100644 --- a/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java +++ b/testsuite/src/it/java/org/graalvm/tests/integration/utils/Logs.java @@ -115,7 +115,6 @@ public static void checkThreshold(Apps app, Mode mode, long executableSize, long 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, @@ -123,56 +122,53 @@ public static void checkThreshold(Apps app, Mode mode, long executableSize, long ((mode == Mode.DIFF_JVM || mode == Mode.DIFF_NATIVE) ? "overhead is" : "is ") + executableSize + " kB, which is over " + executableSizeThreshold + " kB threshold by " + percentageValOverTh(executableSize, executableSizeThreshold) + "%.", false); - } else if (app.thresholdProperties.containsKey(key + PERCENT_prefix)){ + } 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("executableSize was to be checked, but there is no " + key + KB_prefix+ " or"+ key + PERCENT_prefix +" 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"; - 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 " + timeToFirstOKRequestThreshold + " ms threshold by " + percentageValOverTh(timeToFirstOKRequest, timeToFirstOKRequestThreshold) + "%.", true); - } else if(app.thresholdProperties.containsKey(key + PERCENT_prefix)) { + } 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 + MS_prefix + " or" + key + PERCENT_prefix + " in " + properties); + LOGGER.error("timeToFirstOKRequest was to be checked, but there is no " + key + MS_prefix + " or " + key + PERCENT_prefix + " in " + properties); } } if (rss != SKIP) { final String key = propPrefix + ".RSS.threshold"; - - if (app.thresholdProperties.containsKey(key + KB_prefix)){ + 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 " + 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)){ + } 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); + LOGGER.error("rss was to be checked, but there is no " + key + KB_prefix + " or " + key + PERCENT_prefix + " in " + properties); } } @@ -204,7 +200,7 @@ public static void checkThreshold(Apps app, Mode mode, long executableSize, long mean + "% more than the control, which is over " + meanThreshold + " % threshold.", true); } else { - LOGGER.error("mean was to be checked, but there is no " + key + " or" + key + PERCENT_prefix +" in " + properties); + LOGGER.error("mean was to be checked, but there is no " + key + " or " + key + PERCENT_prefix + " in " + properties); } } @@ -216,14 +212,14 @@ public static void checkThreshold(Apps app, Mode mode, long executableSize, long "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)) { + } 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 + " or" + key + PERCENT_prefix + " in " + properties); + LOGGER.error("p99 was to be checked, but there is no " + key + " or " + key + PERCENT_prefix + " in " + properties); } } @@ -235,14 +231,14 @@ public static void checkThreshold(Apps app, Mode mode, long executableSize, long "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)) { + } 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 + " or" + key + PERCENT_prefix + "in " + properties); + LOGGER.error("p90 was to be checked, but there is no " + key + " or " + key + PERCENT_prefix + "in " + properties); } } From d089e0d47b471b3b2133594a752e9618d0034889 Mon Sep 17 00:00:00 2001 From: Robert Toyonaga Date: Mon, 29 Sep 2025 20:06:49 -0400 Subject: [PATCH 3/3] update readme --- README.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/README.md b/README.md index 449743f0..7f4c4e86 100644 --- a/README.md +++ b/README.md @@ -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: