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.27k stars 720 forks source link

JTReg test fail : java/util/concurrent/forkjoin/FJExceptionTableLeak.java #3209

Open ben-walsh opened 5 years ago

ben-walsh commented 5 years ago

Test failure at https://github.com/ibmruntimes/openj9-openjdk-jdk11/blob/openj9/test/jdk/java/util/concurrent/forkjoin/FJExceptionTableLeak.java#L103 ...

test FJExceptionTableLeak.exceptionTableCleanup(): failure
java.lang.NullPointerException
    at FJExceptionTableLeak.retainedExceptions(FJExceptionTableLeak.java:103)
    at FJExceptionTableLeak.failedTasks(FJExceptionTableLeak.java:145)
    at FJExceptionTableLeak.exceptionTableCleanup(FJExceptionTableLeak.java:118)
    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 org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:85)
    at org.testng.internal.Invoker.invokeMethod(Invoker.java:639)
    at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:821)
    at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1131)
    at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:125)
    at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:108)
    at org.testng.TestRunner.privateRun(TestRunner.java:773)
    at org.testng.TestRunner.run(TestRunner.java:623)
    at org.testng.SuiteRunner.runTest(SuiteRunner.java:357)
    at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:352)
    at org.testng.SuiteRunner.privateRun(SuiteRunner.java:310)
    at org.testng.SuiteRunner.run(SuiteRunner.java:259)
    at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
    at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
    at org.testng.TestNG.runSuitesSequentially(TestNG.java:1185)
    at org.testng.TestNG.runSuitesLocally(TestNG.java:1110)
    at org.testng.TestNG.run(TestNG.java:1018)
    at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
    at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
    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:115)
    at java.base/java.lang.Thread.run(Thread.java:825)

Digging deeper, execution of this ...

import java.lang.invoke.VarHandle;
import java.lang.invoke.MethodHandles;
import java.util.concurrent.locks.ReentrantLock;
import java.util.concurrent.ForkJoinTask;

public class Test {

   public static void main(String args[]) throws ReflectiveOperationException {

      MethodHandles.Lookup lookup = MethodHandles.privateLookupIn(ForkJoinTask.class, MethodHandles.lookup());
      VarHandle exceptionTableLockHandle = lookup.findStaticVarHandle(ForkJoinTask.class, "exceptionTableLock", ReentrantLock.class);
      ReentrantLock exceptionTableLock = (ReentrantLock) exceptionTableLockHandle.get();
      System.out.println("exceptionTableLock : " + exceptionTableLock);

   }

}

... yields ...

walshbp@bendev:~/jtreg_testing$ /home/walshbp/openjdk11-openj9-binary/jdk-11+28/bin/javac Test.java
walshbp@bendev:~/jtreg_testing$ /home/walshbp/openjdk11-openj9-binary/jdk-11+28/bin/java Test
exceptionTableLock : null
walshbp@bendev:~/jtreg_testing$ /home/walshbp/openjdk11-hotspot-binary/jdk-11/bin/javac Test.java
walshbp@bendev:~/jtreg_testing$ /home/walshbp/openjdk11-hotspot-binary/jdk-11/bin/java Test
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access using Lookup on Test (file:/home/walshbp/jtreg_testing/) to class java.util.concurrent.ForkJoinTask
WARNING: Please consider reporting this to the maintainers of Test
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
exceptionTableLock : java.util.concurrent.locks.ReentrantLock@5fe5c6f[Unlocked]

I don't see anything in the source code to explain why the exceptionTableLock variable set in the JCL ForkJoinTask impl is nullified ...

walshbp@bendev:~/jep_testing/openj9-openjdk-jdk11$ egrep -r "exceptionTableLock"
test/jdk/java/util/concurrent/forkjoin/FJExceptionTableLeak.java:    final ReentrantLock exceptionTableLock;
test/jdk/java/util/concurrent/forkjoin/FJExceptionTableLeak.java:        VarHandle exceptionTableLockHandle = lookup.findStaticVarHandle(
test/jdk/java/util/concurrent/forkjoin/FJExceptionTableLeak.java:            ForkJoinTask.class, "exceptionTableLock", ReentrantLock.class);
test/jdk/java/util/concurrent/forkjoin/FJExceptionTableLeak.java:        exceptionTableLock = (ReentrantLock) exceptionTableLockHandle.get();
test/jdk/java/util/concurrent/forkjoin/FJExceptionTableLeak.java:        exceptionTableLock.lock();
test/jdk/java/util/concurrent/forkjoin/FJExceptionTableLeak.java:            exceptionTableLock.unlock();
src/java.base/share/classes/java/util/concurrent/ForkJoinTask.java:    private static final ReentrantLock exceptionTableLock
src/java.base/share/classes/java/util/concurrent/ForkJoinTask.java:            final ReentrantLock lock = exceptionTableLock;
src/java.base/share/classes/java/util/concurrent/ForkJoinTask.java:        final ReentrantLock lock = exceptionTableLock;
src/java.base/share/classes/java/util/concurrent/ForkJoinTask.java:        final ReentrantLock lock = exceptionTableLock;
src/java.base/share/classes/java/util/concurrent/ForkJoinTask.java:        final ReentrantLock lock = exceptionTableLock;

Log archive : FJExTabLeak.tar.gz

This test passes against Hotspot.

smlambert commented 5 years ago

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

JasonFengJ9 commented 5 years ago

Looking at this (might be same as https://github.com/eclipse/openj9/issues/3205)

JasonFengJ9 commented 5 years ago

Yeah, this was due to same cause as #3205, i.e, VarHandle to a static field didn't initialize the field if the field in question has been initialized yet. Manually verified that this test passes with the PR #3928 (already merged).

This issue can be closed (and the test can be re-enabled).

pdbain-ibm commented 5 years ago

@smlambert Please re-enable the test. @ben-walsh would you kindly verify and close this issue?

ben-walsh commented 5 years ago

Verification job running - https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/772 On successful completion, I'll create a PR to re-enable. @smlambert

ben-walsh commented 5 years ago

https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/772 shows the problem is still present running against a nightly 11 build, which I assume is not expected ?

@JasonFengJ9 What was the build version you manually verified against ?

JasonFengJ9 commented 5 years ago

@ben-walsh I did verification with a patch generated from the PR.

Looked at the grinder job, its jvm -version output is as following:

openjdk version "11.0.1" 2018-10-16
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.1+13-201901071931)
Eclipse OpenJ9 VM AdoptOpenJDK (build master-f8231edc8, JRE 11 Linux amd64-64-Bit Compressed References 20190107_86 (JIT enabled, AOT enabled)
OpenJ9   - f8231edc8
OMR      - 3c42fa79
JCL      - ab5eb2bc46 based on jdk-11.0.1+13)

https://github.com/eclipse/openj9/pull/3928 was merged on Jan. 8th so not contained in this jvm.

Please re-run the grinder with latest nightly build (verified build 11.0.1+13-201901101911 passes this test).

ben-walsh commented 5 years ago

Rebuilding https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/772 under https://ci.adoptopenjdk.net/view/Test_grinder/job/Grinder/792. AOJDK website currently shows https://github.com/AdoptOpenJDK/openjdk11-binaries/releases/download/jdk11u-2019-01-11-01-22/OpenJDK11U-jdk_x64_linux_openj9_2019-01-11-01-22.tar.gz as the latest nightly build available for the platform, which is what I'd expect to be used.

smlambert commented 5 years ago

Grinder/792 passes, console output shows 2019-01-11-01-22 is used:

17:43:40 curl -OLJks https://api.adoptopenjdk.net/v2/binary/nightly/openjdk11?openjdk_impl=openj9&os=linux&arch=x64&release=latest&type=jdk&heap_size=normal $ ssh-agent 17:43:49 unzip file: OpenJDK11U-jdk_x64_linux_openj9_2019-01-11-01-22.tar.gz ... 17:43:53 Run /home/jenkins/workspace/Grinder/openjdkbinary/j2sdk-image/bin/java -version 17:43:53 openjdk version "11.0.1" 2018-10-16 17:43:53 OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.1+13-201901101911) 17:43:53 Eclipse OpenJ9 VM AdoptOpenJDK (build master-16eaa1c01, JRE 11 Linux amd64-64-Bit Compressed References 20190110_89 (JIT enabled, AOT enabled) 17:43:53 OpenJ9 - 16eaa1c01 17:43:53 OMR - 6830bfc1 17:43:53 JCL - ab5eb2bc46 based on jdk-11.0.1+13)

JasonFengJ9 commented 5 years ago

@ben-walsh this can be closed now, thanks.