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

jdk16 openj9 extended.perf dacapo-jython_0 java.lang.NullPointerException #11942

Open lumpfish opened 3 years ago

lumpfish commented 3 years ago

jdk16 openj9 extended.perf test target dacapo-jython_0 fails with java.lang.NullPointerException.

The test fails with openj9 build, passes with hotspot build. The test fails on all openj9 platforms.

Failing job link: https://ci.adoptopenjdk.net/job/Test_openjdk16_hs_extended.perf_x86-64_windows/4/consoleFull

Failing build:

17:51:01  openjdk version "16" 2021-03-16
17:51:01  OpenJDK Runtime Environment AdoptOpenJDK (build 16+35)
17:51:01  Eclipse OpenJ9 VM AdoptOpenJDK (build openj9-0.25.0-m1, JRE 16 Windows Server 2012 R2 amd64-64-Bit Compressed References 20210209_46 (JIT enabled, AOT enabled)
17:51:01  OpenJ9   - a80e4fe10
17:51:01  OMR      - adc01bb03
17:51:01  JCL      - 80c626b79bc based on jdk-16+35)

Test output:

17:58:44  ===============================================
17:58:44  Running test dacapo-jython_0 ...
17:58:44  ===============================================
17:58:44  dacapo-jython_0 Start Time: Tue Feb  9 17:58:43 2021 Epoch Time (ms): 1612893523978
17:58:44  "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:destroyAll; "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdkbinary/j2sdk-image\\bin\\java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
17:58:44  JVMSHRC005I No shared class caches available
17:58:44  JVMSHRC005I No shared class caches available
17:58:44  cache cleanup done
17:58:44  variation: NoOptions
17:58:44  JVM_OPTIONS:  
17:58:44  { itercnt=1; \
17:58:44  mkdir -p "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdk-tests/\\TKG\\output_16128934979825\\dacapo-jython_0"; \
17:58:44  cd "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdk-tests/\\TKG\\output_16128934979825\\dacapo-jython_0"; \
17:58:44  "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdkbinary/j2sdk-image\\bin\\java" -jar "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdk-tests///..//jvmtest\\perf\\dacapo\\dacapo.jar" jython; \
17:58:44    if [ $? -eq 0 ] ; then echo ""; echo "dacapo-jython_0""_PASSED"; echo ""; cd C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdk-tests/; rm -f -r "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdk-tests/\\TKG\\output_16128934979825\\dacapo-jython_0"; else echo ""; echo "dacapo-jython_0""_FAILED"; echo ""; fi; } 2>&1 | tee -a "C:/Users/jenkins/workspace/Test_openjdk16_j9_extended.perf_x86-64_windows/openjdk-tests/\\TKG\\output_16128934979825\\TestTargetResult";
17:58:48  java.lang.reflect.InvocationTargetException
17:58:48  java.lang.reflect.InvocationTargetException
17:58:48    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
17:58:48    at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:78)
17:58:48    at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
17:58:48    at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
17:58:48    at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
17:58:48    at org.dacapo.harness.TestHarness.runBenchmark(TestHarness.java:192)
17:58:48    at org.dacapo.harness.TestHarness.main(TestHarness.java:152)
17:58:48    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
17:58:48    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
17:58:48    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
17:58:48    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
17:58:48    at Harness.main(Unknown Source)
17:58:48  Caused by: java.lang.reflect.InvocationTargetException
17:58:48    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
17:58:48    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
17:58:48    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
17:58:48    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
17:58:48    at org.dacapo.harness.Jython.<init>(Jython.java:36)
17:58:48    ... 12 more
17:58:48  Caused by: Exception in thread "main" java.lang.reflect.InvocationTargetException
17:58:48    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
17:58:48    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
17:58:48    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
17:58:48    at java.base/java.lang.reflect.Method.invoke(Method.java:567)
17:58:48    at Harness.main(Unknown Source)
17:58:48  Caused by: java.lang.NullPointerException: Cannot invoke "org.python.core.PyObject.__findattr__(java.lang.String)" because "cls" is null
17:58:48    at org.python.core.Py.recursiveIsInstance(Py.java:1913)
17:58:48    at org.python.core.Py.isInstance(Py.java:1880)
17:58:48    at org.python.core.__builtin__.isinstance(__builtin__.java:696)
17:58:48    at org.python.core.Py.displayException(Py.java:1068)
17:58:48    at org.python.core.PyException.printStackTrace(PyException.java:79)
17:58:48    at org.python.core.PyException.toString(PyException.java:98)
17:58:48    at java.base/java.lang.Throwable.printStackTrace(Throwable.java:544)
17:58:48    at java.base/java.lang.Throwable.printStackTraceHelper(Throwable.java:342)
17:58:48    at java.base/java.lang.Throwable.printStackTrace(Throwable.java:307)
17:58:48    at java.base/java.lang.Throwable.printStackTrace(Throwable.java:250)
17:58:48    at org.dacapo.harness.TestHarness.main(TestHarness.java:157)
17:58:48    ... 5 more
17:58:49  
17:58:49  dacapo-jython_0_FAILED

To rerun: https://ci.adoptopenjdk.net/job/Grinder/parambuild/?JDK_VERSION=16&JDK_IMPL=openj9&JDK_VENDOR=adoptopenjdk&BUILD_LIST=perf&PLATFORM=x86-64_windows&TARGET=dacapo-jython_0

pshipton commented 3 years ago

@tajila we should investigate this.

tajila commented 3 years ago

@JasonFengJ9 can you please take a look at this

tajila commented 3 years ago

@lumpfish Did this just start failing? or was the test recently enabled?

JasonFengJ9 commented 3 years ago

Will look into this.

tajila commented 3 years ago

Here is the relevant code, https://github.com/jython/jython/blob/0a58cc26566d2b2334e80b2b3f2f42f6c738db2d/src/org/python/core/Py.java#L1358. Although its not the same version of jython that is being used in the tests so the line numbers are off.

JasonFengJ9 commented 3 years ago

Failing job link: https://ci.adoptopenjdk.net/job/Test_openjdk16_hs_extended.perf_x86-64_windows/4/consoleFull

This link is for hotspot, @lumpfish pls update it with OpenJ9 one.

lumpfish commented 3 years ago

This link is for hotspot, @lumpfish pls update it with OpenJ9 one.

Whoops - an OpenJ9 link: https://ci.adoptopenjdk.net/job/Test_openjdk16_j9_extended.perf_x86-64_linux/5/consoleFull

lumpfish commented 3 years ago

@lumpfish Did this just start failing? or was the test recently enabled?

It's part of the 'extended.perf' test suite which has recently been added on a weekly test cycle at AdoptOpenJDK (note the build number of only number 5). I think this is the first time this failure has been investigated. (Note there are a number of other failures in the test jobs which are not openj9 specific where the tests appear to be trying to access packages they are no longer allowed to.) So it's probably been there for some time.

JasonFengJ9 commented 3 years ago

This is same issue as https://github.com/eclipse/openj9/issues/6920, detail analysis is at https://github.com/eclipse/openj9/issues/6920#issuecomment-528062028.

It is not a JVM problem. The issue is within Jython code and has been fixed in latest release v2.7.2 [1]. This test uses latest dacapo.jar [2] however it contains an outdated jython.jar (v2.5.2), replacing it with latest v2.7.2 causes NoSuchMethodException: org.python.core.PySystemState.setArgv([Ljava.lang.String;). I back-ported the fix [3] into v2.5.2, and this dacapo-jython_0 test passes.

Additional notes:

  1. OpenJ9 JDK11 passes (probably different code path executed);
  2. OpenJ9 JDK15/16 failed since JDK15 GA version;
  3. RI JDK16 passes

I would suggest disable this test for OpenJ9 JDK16+ before the DaCapo Benchmark Suite updates its jython.jar.

[1] https://search.maven.org/artifact/org.python/jython-standalone [2] https://sourceforge.net/projects/dacapobench/files/latest/download [3] https://github.com/jython/frozen-mirror/blob/b8d7aa4cee50c0c0fe2f4b235dd62922dd0f3f99/src/org/python/core/PyJavaType.java#L246-L248

llxia commented 3 years ago

Test is excluded in https://github.com/AdoptOpenJDK/openjdk-tests/pull/2269/