eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.28k stars 722 forks source link

MacOS aarch64 sun/security/ssl/SSLSocketImpl/SSLSocketLeak.java RuntimeException: Too many open file descriptors #15558

Open JasonFengJ9 opened 2 years ago

JasonFengJ9 commented 2 years ago

Failure link

From an internal build(macaarch64rt8):

openjdk version "11.0.16-ea" 2022-07-19
IBM Semeru Runtime Open Edition 11.0.16.0-m2a (build 11.0.16-ea+7)
Eclipse OpenJ9 VM 11.0.16.0-m2a (build openj9-0.33.0-m2a, JRE 11 Mac OS X aarch64-64-Bit 20220717_97 (JIT enabled, AOT enabled)
OpenJ9   - 124430efb
OMR      - b58aa2708
JCL      - a30303e8b3 based on jdk-11.0.16+7)

Rerun in Grinder - Change TARGET to run only the failed test targets.

Optional info

Failure output (captured from console output)

[2022-07-18T03:52:57.004Z] variation: Mode650
[2022-07-18T03:52:57.004Z] JVM_OPTIONS:  -XX:-UseCompressedOops 

[2022-07-18T03:58:25.596Z] TEST: sun/security/ssl/SSLSocketImpl/SSLSocketLeak.java

[2022-07-18T03:58:25.597Z] STDERR:
[2022-07-18T03:58:25.597Z] java.lang.RuntimeException: Too many open file descriptors. Looks leaky.
[2022-07-18T03:58:25.597Z]  at SSLSocketLeak.main(SSLSocketLeak.java:61)
[2022-07-18T03:58:25.597Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2022-07-18T03:58:25.597Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2022-07-18T03:58:25.597Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2022-07-18T03:58:25.597Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2022-07-18T03:58:25.597Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2022-07-18T03:58:25.597Z]  at java.base/java.lang.Thread.run(Thread.java:840)
[2022-07-18T03:58:25.597Z] 
[2022-07-18T03:58:25.597Z] JavaTest Message: Test threw exception: java.lang.RuntimeException: Too many open file descriptors. Looks leaky.

[2022-07-18T04:03:06.289Z] jdk_security3_1_FAILED

50x internal grinder - passed

JasonFengJ9 commented 2 years ago

Internal build(macaarch64rt6)

openjdk version "11.0.17-ea" 2022-10-18
IBM Semeru Runtime Open Edition 11.0.17.0-m1 (build 11.0.17-ea+4)
Eclipse OpenJ9 VM 11.0.17.0-m1 (build openj9-0.35.0-m1, JRE 11 Mac OS X aarch64-64-Bit 20220901_129 (JIT enabled, AOT enabled)
OpenJ9   - f8c5cbdeb
OMR      - 938f0686f
JCL      - 4e2342f3c4 based on jdk-11.0.17+4)

03:29:38  STDOUT:
03:29:38  FDs at the beginning: 6
03:29:38  FDs in the end: 63

[2022-09-01T07:29:38.469Z] STDERR:
[2022-09-01T07:29:38.469Z] java.lang.RuntimeException: Too many open file descriptors. Looks leaky.
[2022-09-01T07:29:38.469Z]  at SSLSocketLeak.main(SSLSocketLeak.java:61)
[2022-09-01T07:29:38.469Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2022-09-01T07:29:38.469Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2022-09-01T07:29:38.469Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2022-09-01T07:29:38.469Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2022-09-01T07:29:38.469Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2022-09-01T07:29:38.469Z]  at java.base/java.lang.Thread.run(Thread.java:839)

[2022-09-01T07:35:11.746Z] jdk_security3_1_FAILED
pshipton commented 2 years ago

Tentatively tagging as a blocker for amac being removed from EA.

pshipton commented 2 years ago

(20x x 10 grinder)(https://hyc-runtimes-jenkins.swg-devops.com/view/Test_grinder/job/Grinder/27803/) There were only 4 distinct machines used. There was 1 failure on macaarch64rt1.

FDs at the beginning: 4
FDs in the end: 63

Running the test manually on macaarch64rt1, I often get results of

FDs at the beginning: 5
FDs in the end: 9

FDs at the beginning: 5
FDs in the end: 7

also these results

FDs at the beginning: 19
FDs in the end: 7

FDs at the beginning: 12
FDs in the end: 7

FDs at the beginning: 5
FDs in the end: 213

FDs at the beginning: 204
FDs in the end: 7

FDs at the beginning: 5
FDs in the end: 21

The results vary quite a bit. There doesn't seem to be a problem with SSLSockets. If anything, there may be a problem with UnixOperatingSystemMXBean.getOpenFileDescriptorCount().

Temurin seems to always return

FDs at the beginning: 4
FDs in the end: 8

Tagging as VM and setting to the next milestone to investigate getOpenFileDescriptorCount().

knn-k commented 2 years ago

1 failure in an internal Grinder job: 27773 (30x)

[2022-09-19T12:23:36.347Z] STDOUT:
[2022-09-19T12:23:36.347Z] FDs at the beginning: 16
[2022-09-19T12:23:36.347Z] FDs in the end: 74
[2022-09-19T12:23:36.347Z] STDERR:
[2022-09-19T12:23:36.347Z] java.lang.RuntimeException: Too many open file descriptors. Looks leaky.
[2022-09-19T12:23:36.347Z]  at SSLSocketLeak.main(SSLSocketLeak.java:61)
[2022-09-19T12:23:36.347Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2022-09-19T12:23:36.347Z]  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[2022-09-19T12:23:36.347Z]  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2022-09-19T12:23:36.347Z]  at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[2022-09-19T12:23:36.347Z]  at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
[2022-09-19T12:23:36.347Z]  at java.base/java.lang.Thread.run(Thread.java:839)
knn-k commented 2 years ago

I ran sun/security/ssl/SSLSocketImpl/SSLSocketLeak.java with JDK 11 manually 100 times in my local amac environment, and got no failures.

JasonFengJ9 commented 1 year ago

JDK17 m1 build

01:10:27  =JAVA VERSION OUTPUT BEGIN=
01:10:29  openjdk version "17.0.7" 2023-04-18
01:10:29  IBM Semeru Runtime Open Edition 17.0.7.0-m1 (build 17.0.7+2)
01:10:29  Eclipse OpenJ9 VM 17.0.7.0-m1 (build v0.38.0-release-25af2a240, JRE 17 Mac OS X aarch64-64-Bit 20230418_277 (JIT enabled, AOT enabled)
01:10:29  OpenJ9   - 25af2a240
01:10:29  OMR      - 008f97b5c
01:10:29  JCL      - 354bacdb9e2 based on jdk-17.0.7+2)

01:32:59  variation: Mode650
01:32:59  JVM_OPTIONS:  -XX:-UseCompressedOops 

02:01:31  TEST: sun/security/ssl/SSLSocketImpl/SSLSocketLeak.java

02:01:31  STDERR:
02:01:31  java.lang.RuntimeException: Too many open file descriptors. Looks leaky.
02:01:31    at SSLSocketLeak.main(SSLSocketLeak.java:61)
02:01:31    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
02:01:31    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
02:01:31    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
02:01:31    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
02:01:31    at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
02:01:31    at java.base/java.lang.Thread.run(Thread.java:857)
02:01:31  
02:01:31  JavaTest Message: Test threw exception: java.lang.RuntimeException: Too many open file descriptors. Looks leaky.
JasonFengJ9 commented 7 months ago

JDK11 aarch64_mac(macaarch64rt1)

[2024-03-26T16:59:34.773Z] variation: Mode650
[2024-03-26T16:59:34.773Z] JVM_OPTIONS:  -XX:-UseCompressedOops -Xverbosegclog 

[2024-03-26T17:04:49.591Z] TEST: sun/security/ssl/SSLSocketImpl/SSLSocketLeak.java

[2024-03-26T17:04:49.591Z] STDERR:
[2024-03-26T17:04:49.591Z] java.lang.RuntimeException: Too many open file descriptors. Looks leaky.
[2024-03-26T17:04:49.591Z]  at SSLSocketLeak.main(SSLSocketLeak.java:61)

[2024-03-26T17:09:15.698Z] jdk_security3_1_FAILED