JDK-8314426 : runtime/os/TestTrimNative.java is failing on slow machines
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 17,21,22
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • OS: linux
  • Submitted: 2023-08-16
  • Updated: 2023-08-28
  • Resolved: 2023-08-22
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 17 JDK 21 JDK 22
17.0.9Fixed 21.0.1Fixed 22 b12Fixed
Related Reports
Relates :  
Description
Reported by SAP. Both cases look like they could be the result of slow or overloaded test machines.

```
Linuxaarc64  11.8.  :

stdout: [[0.133s][info][trimnative] Periodic native trim enabled (interval: 500 ms)
[0.133s][info][trimnative] Native heap trimmer start
Will spike now...
Done spiking.
GC...
Sleeping...
[0.642s][info][trimnative] Periodic Trim (1): 315M->171M (-144M) 9.717ms
[1.143s][info][trimnative] Periodic Trim (2): 171M->171M (+0B) 0.216ms
[1.643s][info][trimnative] Periodic Trim (3): 171M->171M (+0B) 0.228ms
[2.144s][info][trimnative] Periodic Trim (4): 171M->171M (+0B) 0.226ms
[2.644s][info][trimnative] Periodic Trim (5): 171M->171M (+0B) 0.270ms
[3.144s][info][trimnative] Periodic Trim (6): 171M->171M (+0B) 0.255ms
[3.645s][info][trimnative] Periodic Trim (7): 171M->171M (+0B) 0.221ms
[4.145s][info][trimnative] Periodic Trim (8): 171M->171M (+0B) 0.561ms
[4.646s][info][trimnative] Periodic Trim (9): 171M->171M (+0B) 0.228ms
[5.144s][debug][trimnative] Trim suspended for chunk pool cleaner (1 suspend requests)
[5.144s][debug][trimnative] Trim resumed after chunk pool cleaner
[5.147s][info ][trimnative] Periodic Trim (10): 171M->171M (-716K) 0.558ms
Done.
];
stderr: []
exitValue = 0

java.lang.RuntimeException: 'Native heap trimmer stop' missing from stdout/stderr
       at jdk.test.lib.process.OutputAnalyzer.shouldContain(OutputAnalyzer.java:221)
       at TestTrimNative.checkExpectedLogMessages(TestTrimNative.java:173)
       at TestTrimNative.main(TestTrimNative.java:280)
       at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
       at java.base/java.lang.reflect.Method.invoke(Method.java:580)
       at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
       at java.base/java.lang.Thread.run(Thread.java:1570)
```
 

``` 

runtime/os/TestTrimNative.java#trimNativeLowInterval   15.8  linuxppc64le :

java.lang.RuntimeException: Abnormal high number of periodic trim attempts found (more than 3000). Does the interval setting not work?
       at TestTrimNative.parseOutputAndLookForNegativeTrim(TestTrimNative.java:205)
       at TestTrimNative.main(TestTrimNative.java:304)
       at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
       at java.base/java.lang.reflect.Method.invoke(Method.java:580)
       at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:333)
       at java.base/java.lang.Thread.run(Thread.java:1583)
```

Comments
Fix Request (17u, 21u) Further stabilizes the test. Applies cleanly. Testing passes.
23-08-2023

A pull request was submitted for review. URL: https://git.openjdk.org/jdk17u-dev/pull/1687 Date: 2023-08-23 07:28:08 +0000
23-08-2023

A pull request was submitted for review. URL: https://git.openjdk.org/jdk21u/pull/86 Date: 2023-08-23 07:16:00 +0000
23-08-2023

Changeset: 20e94784 Author: Thomas Stuefe <stuefe@openjdk.org> Date: 2023-08-22 14:00:47 +0000 URL: https://git.openjdk.org/jdk/commit/20e94784c9f7c30e95550c72aedb5e986a153114
22-08-2023

A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/15309 Date: 2023-08-16 14:28:38 +0000
22-08-2023

Here's the log from my jdk-22+11 stress run sighting on linux-x64: $ unzip -l jdk-22+11_linux-x64.8314426.zip Archive: jdk-22+11_linux-x64.8314426.zip Length Date Time Name --------- ---------- ----- ---- 103499 2023-08-19 09:43 jdk-22+11_2/failures.linux-x86_64/TestTrimNative_trimNativeLowInterval.jtr.slowdebug --------- ------- 103499 1 file
21-08-2023