search

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 721 forks source link

JTReg test fails : java/io/FileInputStream/UnreferencedFISClosesFd.java and java/io/FileOutputStream/UnreferencedFOSClosesFd.java #3543

Open ben-walsh opened 5 years ago

ben-walsh commented 5 years ago

Both https://github.com/ibmruntimes/openj9-openjdk-jdk11/blob/openj9/test/jdk/java/io/FileInputStream/UnreferencedFISClosesFd.java and https://github.com/ibmruntimes/openj9-openjdk-jdk11/blob/openj9/test/jdk/java/io/FileOutputStream/UnreferencedFOSClosesFd.java are behaving inconsistently ...

Sometimes (~60% of the time) they pass and other times they time out.

The problematic sub-test in both is StreamOverridesFinalizeClose.

When they pass the output looks like this ...

Testing UnreferencedFOSClosesFd$StreamOverridesFinalizeClose
  cleanup: null, alt: java.io.FileOutputStream$AltFinalizer@2492059c, ffd: 8, cf: private jdk.internal.ref.PhantomCleanable java.io.FileDescriptor.cleanup
    fdWeak: java.lang.ref.WeakReference@82607569
    msWeak: java.lang.ref.WeakReference@e34a887e
    altFinalizerWeak: java.lang.ref.WeakReference@93abf91f
    r: null, pending: 3
    r: java.lang.ref.WeakReference@e34a887e, pending: 3
    r: java.lang.ref.WeakReference@82607569, pending: 2
    r: java.lang.ref.WeakReference@93abf91f, pending: 1

... and when they time out the output looks like this ...

Testing UnreferencedFOSClosesFd$StreamOverridesFinalizeClose
  cleanup: null, alt: java.io.FileOutputStream$AltFinalizer@9cf94964, ffd: 8, cf: private jdk.internal.ref.PhantomCleanable java.io.FileDescriptor.cleanup
    fdWeak: java.lang.ref.WeakReference@c6c0f862
    msWeak: java.lang.ref.WeakReference@c47a6dae
    altFinalizerWeak: java.lang.ref.WeakReference@629a3211
    r: null, pending: 3
    r: null, pending: 3
    r: null, pending: 3
    r: null, pending: 3
    <continues repeating until timeout reached>

These core dumps were taken for each test during this repetition ... FIS_javacore.20181105.141217.10362.0001.txt FOS_javacore.20181105.140311.9322.0001.txt

Example log archives for time out of each test ... FailureUnreferencedFOSClosesFd.tar.gz FailureUnreferencedFISClosesFd.tar.gz

Example log archives for passess of each test ... SuccessUnreferencedFOSClosesFd.tar.gz SuccessUnreferencedFISClosesFd.tar.gz

smlambert commented 5 years ago

Test excluded: https://github.com/AdoptOpenJDK/openjdk-tests/pull/667

pdbain-ibm commented 5 years ago

I will investigate.

pdbain-ibm commented 5 years ago

Passing test case:

Testing UnreferencedFISClosesFd$StreamOverridesFinalizeClose
  cleanup: null, alt: java.io.FileInputStream$AltFinalizer@eaaefd7a, ffd: 5, cf: private jdk.internal.ref.PhantomCleanable java.io.FileDescriptor.cleanup
    fdWeak: java.lang.ref.WeakReference@34b8380e
    msWeak: java.lang.ref.WeakReference@3f9388ca
    altFinalizerWeak: java.lang.ref.WeakReference@8db3e025
    r: null, pending: 3
    r: java.lang.ref.WeakReference@3f9388ca, pending: 3
    r: java.lang.ref.WeakReference@34b8380e, pending: 2
    r: java.lang.ref.WeakReference@8db3e025, pending: 1

Failing test case: 

Testing UnreferencedFISClosesFd$StreamOverridesFinalizeClose
  cleanup: null, alt: java.io.FileInputStream$AltFinalizer@f2dc4c25, ffd: 5, cf: private jdk.internal.ref.PhantomCleanable java.io.FileDescriptor.cleanup
    fdWeak: java.lang.ref.WeakReference@f3e3eaf7
    msWeak: java.lang.ref.WeakReference@6756ab53
    altFinalizerWeak: java.lang.ref.WeakReference@c6d6a69b
    r: null, pending: 3
    r: null, pending: 3
    r: null, pending: 3
    r: null, pending: 3
    r: null, pending: 3

Failure rate ~3-5%, always in this spot.

pdbain-ibm commented 5 years ago

Tested with -Xgcpolicy:optthruput, still fails. Tested with -Xint, 200 runs, no failures.

Above tests were on MacOS. Tested on Linux, I get either the above or:

Testing UnreferencedFISClosesFd$StreamOverridesClose
  cleanup: null, alt: java.io.FileInputStream$AltFinalizer@2afd3b5b, ffd: 5, cf: private jdk.internal.ref.PhantomCleanable java.io.FileDescriptor.cleanup
    fdWeak: java.lang.ref.WeakReference@42cf4545
    msWeak: java.lang.ref.WeakReference@f17df7ee
    altFinalizerWeak: java.lang.ref.WeakReference@7abfc6
    r: null, pending: 3
    r: null, pending: 3
    r: null, pending: 3
    r: null, pending: 3
pdbain-ibm commented 5 years ago

Test fails ~50% on Linux X86. Ran several dozen times with -Xint and with -Xjit:count=0 without failure. I also wrapped the mainline in a loop to iterate the test in the same process. It fails on the first iteration or not at all.

pdbain-ibm commented 5 years ago

Discussed with GC team. This appears to be a JIT issue. Attaching the code to run the test like so: javac UnreferencedFISClosesFd.java. issue3543.tar.zip