Skip to content

Commit

Permalink
8312525: New test runtime/os/TestTrimNative.java#trimNative is failin…
Browse files Browse the repository at this point in the history
…g: did not see the expected RSS reduction

Reviewed-by: mdoerr
Backport-of: ad34be1f329edc8e7155983835cc70d733c014b8
  • Loading branch information
shipilev committed Aug 25, 2023
1 parent f667b35 commit 3c426c7
Show file tree
Hide file tree
Showing 2 changed files with 43 additions and 10 deletions.
4 changes: 4 additions & 0 deletions src/hotspot/os/linux/trimCHeapDCmd.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@
*/

#include "precompiled.hpp"
#include "logging/log.hpp"
#include "runtime/os.inline.hpp"
#include "trimCHeapDCmd.hpp"
#include "utilities/debug.hpp"
Expand All @@ -42,6 +43,9 @@ void TrimCLibcHeapDCmd::execute(DCmdSource source, TRAPS) {
const char sign = sc.after < sc.before ? '-' : '+';
_output->print_cr("RSS+Swap: " PROPERFMT "->" PROPERFMT " (%c" PROPERFMT ")",
PROPERFMTARGS(sc.before), PROPERFMTARGS(sc.after), sign, PROPERFMTARGS(delta));
// Also log if native trim log is active
log_info(trimnative)("Manual Trim: " PROPERFMT "->" PROPERFMT " (%c" PROPERFMT ")",
PROPERFMTARGS(sc.before), PROPERFMTARGS(sc.after), sign, PROPERFMTARGS(delta));
} else {
_output->print_cr("(no details available).");
}
Expand Down
49 changes: 39 additions & 10 deletions test/hotspot/jtreg/runtime/os/TestTrimNative.java
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,16 @@
* @run driver TestTrimNative trimNative
*/

/*
* @test id=trimNativeStrict
* @requires (os.family=="linux") & !vm.musl
* @modules java.base/jdk.internal.misc
* @library /test/lib
* @build jdk.test.whitebox.WhiteBox
* @run driver jdk.test.lib.helpers.ClassFileInstaller jdk.test.whitebox.WhiteBox
* @run main/manual TestTrimNative trimNativeStrict
*/

/*
* @test id=trimNativeHighInterval
* @summary High interval trimming should not even kick in for short program runtimes
Expand All @@ -56,6 +66,17 @@
* @run driver TestTrimNative trimNativeLowInterval
*/

/*
* @test id=trimNativeLowIntervalStrict
* @summary Very low (sub-second) interval, nothing should explode (stricter test, manual mode)
* @requires (os.family=="linux") & !vm.musl
* @modules java.base/jdk.internal.misc
* @library /test/lib
* @build jdk.test.whitebox.WhiteBox
* @run driver jdk.test.lib.helpers.ClassFileInstaller jdk.test.whitebox.WhiteBox
* @run main/manual TestTrimNative trimNativeLowIntervalStrict
*/

/*
* @test id=testOffByDefault
* @summary Test that trimming is disabled by default
Expand Down Expand Up @@ -161,9 +182,10 @@ private static void checkExpectedLogMessages(OutputAnalyzer output, boolean expe
* @param output
* @param minTrimsExpected min number of periodic trim lines expected in UL log
* @param maxTrimsExpected min number of periodic trim lines expected in UL log
* @param strict: if true, expect RSS to go down; if false, just look for trims without looking at RSS.
*/
private static void parseOutputAndLookForNegativeTrim(OutputAnalyzer output, int minTrimsExpected,
int maxTrimsExpected) {
int maxTrimsExpected, boolean strict) {
output.reportDiagnosticSummary();
List<String> lines = output.asLines();
Pattern pat = Pattern.compile(".*\\[trimnative\\] Periodic Trim \\(\\d+\\): (\\d+)([BKMG])->(\\d+)([BKMG]).*");
Expand All @@ -188,7 +210,8 @@ private static void parseOutputAndLookForNegativeTrim(OutputAnalyzer output, int
throw new RuntimeException("We found fewer (periodic) trim lines in UL log than expected (expected at least " + minTrimsExpected +
", found " + numTrimsFound + ").");
}
if (maxTrimsExpected > 0) {
System.out.println("Found " + numTrimsFound + " trims. Ok.");
if (strict && maxTrimsExpected > 0) {
// This is very fuzzy. Test program malloced X bytes, then freed them again and trimmed. But the log line prints change in RSS.
// Which, of course, is influenced by a lot of other factors. But we expect to see *some* reasonable reduction in RSS
// due to trimming.
Expand All @@ -203,6 +226,8 @@ private static void parseOutputAndLookForNegativeTrim(OutputAnalyzer output, int
if (rssReductionTotal < expectedMinimalReduction) {
throw new RuntimeException("We did not see the expected RSS reduction in the UL log. Expected (with fudge)" +
" to see at least a combined reduction of " + expectedMinimalReduction + ".");
} else {
System.out.println("Found high enough RSS reduction from trims: " + rssReductionTotal);
}
}
}
Expand Down Expand Up @@ -238,8 +263,11 @@ public static void main(String[] args) throws Exception {
throw new RuntimeException("Argument error");
}

boolean strictTesting = args[0].endsWith("Strict");

switch (args[0]) {
case "trimNative": {
case "trimNative":
case "trimNativeStrict": {
long trimInterval = 500; // twice per second
long ms1 = System.currentTimeMillis();
OutputAnalyzer output = runTestWithOptions(
Expand All @@ -253,7 +281,7 @@ public static void main(String[] args) throws Exception {

long maxTrimsExpected = runtime_ms / trimInterval;
long minTrimsExpected = maxTrimsExpected / 2;
parseOutputAndLookForNegativeTrim(output, (int) minTrimsExpected, (int) maxTrimsExpected);
parseOutputAndLookForNegativeTrim(output, (int) minTrimsExpected, (int) maxTrimsExpected, strictTesting);
} break;

case "trimNativeHighInterval": {
Expand All @@ -263,16 +291,17 @@ public static void main(String[] args) throws Exception {
);
checkExpectedLogMessages(output, true, Integer.MAX_VALUE);
// We should not see any trims since the interval would prevent them
parseOutputAndLookForNegativeTrim(output, 0, 0);
parseOutputAndLookForNegativeTrim(output, 0, 0, strictTesting);
} break;

case "trimNativeLowInterval": {
case "trimNativeLowInterval":
case "trimNativeLowIntervalStrict": {
OutputAnalyzer output = runTestWithOptions(
new String[] { "-XX:+UnlockExperimentalVMOptions", "-XX:TrimNativeHeapInterval=1" },
new String[] { TestTrimNative.Tester.class.getName(), "0" }
);
checkExpectedLogMessages(output, true, 1);
parseOutputAndLookForNegativeTrim(output, 1, 3000);
parseOutputAndLookForNegativeTrim(output, 1, 3000, strictTesting);
} break;

case "testOffOnNonCompliantPlatforms": {
Expand All @@ -281,7 +310,7 @@ public static void main(String[] args) throws Exception {
new String[] { "-version" }
);
checkExpectedLogMessages(output, false, 0);
parseOutputAndLookForNegativeTrim(output, 0, 0);
parseOutputAndLookForNegativeTrim(output, 0, 0, strictTesting);
// The following output is expected to be printed with warning level, so it should not need -Xlog
output.shouldContain("[warning][trimnative] Native heap trim is not supported on this platform");
} break;
Expand All @@ -292,13 +321,13 @@ public static void main(String[] args) throws Exception {
new String[] { "-version" }
);
checkExpectedLogMessages(output, false, 0);
parseOutputAndLookForNegativeTrim(output, 0, 0);
parseOutputAndLookForNegativeTrim(output, 0, 0, strictTesting);
} break;

case "testOffByDefault": {
OutputAnalyzer output = runTestWithOptions(null, new String[] { "-version" } );
checkExpectedLogMessages(output, false, 0);
parseOutputAndLookForNegativeTrim(output, 0, 0);
parseOutputAndLookForNegativeTrim(output, 0, 0, strictTesting);
} break;

default:
Expand Down

1 comment on commit 3c426c7

@openjdk-notifier
Copy link

Choose a reason for hiding this comment

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

Please sign in to comment.