JTReg test fail - java/nio/Buffer/DirectBufferAllocTest.java

[ben-walsh]

Regression observed with the 11.0.2 RC1 build ...

Test https://github.com/ibmruntimes/openj9-openjdk-jdk11/blob/openj9/test/jdk/java/nio/Buffer/DirectBufferAllocTest.java is failing intermittently with the following ...

STDOUT:
Allocating direct ByteBuffers with capacity 1048576 bytes, using 8 threads for 5 seconds...
STDERR:
java.lang.RuntimeException: Errors encountered!
	at DirectBufferAllocTest.main(DirectBufferAllocTest.java:157)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
	at java.base/java.lang.Thread.run(Thread.java:825)
	Suppressed: java.lang.OutOfMemoryError: Direct buffer memory
		at java.base/java.nio.Bits.reserveMemory(Bits.java:175)
		at java.base/java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123)
		at java.base/java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:317)
		at DirectBufferAllocTest.lambda$main$0(DirectBufferAllocTest.java:126)
		at DirectBufferAllocTest$$Lambda$16.00000000F2D5FD80.call(Unknown Source)
		at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
		at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
		at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
		... 1 more

A 100x run showed a 20% failure rate - https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/915.

A 100x run with -Xint showed a 23% failure rate - https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/919.

I have kicked off a further 100x run with -Xint at https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/923.

This intermittently failure has not been observed in the nightly Windows builds. To double check, I have kicked off a 100x run with -Xint at https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/922.

This intermittently failure has not been observed on any non-Windows platform.

[pshipton]

Not sure this is a release blocker, but I have added it to the 0.12 milestone for now.
@ben-walsh does this test pass reliably on the 0.11 release build? i.e. is it really a regression?

@DanHeidinga

@pdbain-ibm can you please take a look.

[pdbain-ibm]

Will do.

[ben-walsh]

@pshipton

I meant regression compared to the nightly builds. I have kicked off https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/927 to get a data point to compare against previous release.

Having looked with Andrew L at what added the relevant code to Bits.java (https://bugs.openjdk.java.net/browse/JDK-6857566), the slower the test machine, the more likely the OOM will get triggered during the test. Given the likely variably of CPU resource allocated to the test machine during a 100x run - I suspect it is just the case that, on top of that, Windows is slower than the other OSes. Unless there is something particularly less efficient in our memory allocation on Windows compared to other OSes.

I have also kicked off https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/924 to compare against Linux with same build level.

It is probably worth re-prioritising this issue once those results are in.

UPDATE : Also kicked off https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/928 to compare against last nightly.

[pdbain-ibm]

@ben-walsh could you please also test with -Xgcpolicy:optthruput --verbose:gc?

@dmitripivkine would you kindly review this?

Looking at the log file, we see: run main/othervm -XX:MaxDirectMemorySize=128m DirectBufferAllocTest, Allocating direct ByteBuffers with capacity 1048576 bytes, using 8 threads for 5 seconds. We will exhaust the pool after 128 allocations, or 16 allocations per thread.

[dmitripivkine]

DBB uses object Finalization to release memory (needs to run sun.misc.Cleaner). If Finalizer thread(s) can not be executed fast/often enough the Native OOM possible

[ben-walsh]

Kicked off https://ci.adoptopenjdk.net/view/work%20in%20progress/job/SXA-BenWalsh-Grinder/19 with the requested -Xgcpolicy:optthruput -verbose:gc

[pshipton]

As this is not a new failure, I've removed it from the 0.12 milestone plan.

[ben-walsh]

https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/927/consoleText - 100x -Xint against last release build shows a 37% failure rate.

https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/924/consoleText - 100x -Xint against RC1 build on Linux shows a 0% failure rate.

https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/928/consoleText - 100x -Xint against latest nightly - 30% failure rate but UNINTERESTING RESULT - due to adoptium/temurin-build#869, it wrongly tested against RC1 build again.

[ben-walsh]

Kicked off https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/933 to force 100x -Xint test against latest nightly.

[ben-walsh]

https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/933/consoleText - 100x -Xint against latest nightly - 25% failure rate.

[ben-walsh]

This has just cropped up on MacOS too - https://ci.adoptopenjdk.net/view/Test_openjdk/job/openjdk11_j9_openjdktest_x86-64_macos/168/testReport/junit/java_nio_Buffer_DirectBufferAllocTest/java/DirectBufferAllocTest

Kicked off 100x -Xint against latest nightly of MacOS - https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/948

[ben-walsh]

https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/948 - showed a 0% failure rate.
Running a 400x - https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/970.

[ben-walsh]

Also observed on Nightly Linux PPC - https://ci.adoptopenjdk.net/view/Test_openjdk/job/openjdk11_j9_openjdktest_ppc64le_linux/131/testReport/junit/java_nio_Buffer_DirectBufferAllocTest/java/DirectBufferAllocTest

[ben-walsh]

Adjusting title to reflect platform breadth.

[adamfarley]

Issue still appears to occur: https://ci.adoptopenjdk.net/job/Test_openjdk14_hs_sanity.openjdk_ppc64_aix/111

[pshipton]

@adamfarley your link is for a Hotspot build. If the problems also occurs with HS, seems like a problem with the test itself.

[adamfarley]

My mistake. Will open an openjdk-tests issue.

If the fix for that issue also results in 0% failures on j9, I'll come back and close this.