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

ClassLoadingTest StringIndexOutOfBoundsException: Range [0, 0 + 28) out of bounds for length 26 #16487

Open pshipton opened 1 year ago

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.system_s390x_linux_Nightly_testList_1/71 - rh7-390-4 ClassLoadingTest_5m_0

00:11:43  CLT 00:11:40.177 - Completed 53.4%. Number of tests started=33531 (+3668)
00:11:43  CLT 00:11:40.857 - First failure detected by thread: load-8. Not creating dumps as no dump generation is requested for this load test
00:11:43  CLT 00:11:41.019 - Test failed. Details recorded in execution log.
00:11:43  CLT 00:11:41.051 - Test failed
00:11:43  CLT   Failure num.  = 1
00:11:43  CLT   Test number   = 2
00:11:43  CLT   Test details  = 'ArbitraryJava[net.adoptopenjdk.test.classloading.ClassHog run]'
00:11:43  CLT   Suite number  = 0
00:11:43  CLT   Thread number = 8
00:11:43  CLT >>> Captured test output >>>
00:11:43  CLT Loaded Class: dioClip
00:11:43  CLT Loaded Class: letInitializer
00:11:43  CLT Loaded Class: ncontext.BeanContext
00:11:43  CLT Loaded Class: ncontext.BeanContextChild
00:11:43  CLT Loaded Class: ncontext.BeanContextChildComponentProxy
00:11:43  CLT Loaded Class: ncontext.BeanContextChildSupport
00:11:43  CLT Loaded Class: ncontext.BeanContextContainerProxy
00:11:43  CLT Loaded Class: ncontext.BeanContextEvent
00:11:43  CLT Loaded Class: ncontext.BeanContextMembershipEvent
00:11:43  CLT Loaded Class: ncontext.BeanContextMembershipListener
00:11:43  CLT Loaded Class: ncontext.BeanContextProxy
00:11:43  CLT Loaded Class: ncontext.BeanContextServiceAvailableEvent
00:11:43  CLT Loaded Class: ncontext.BeanContextServiceProvider
00:11:43  CLT Loaded Class: ncontext.BeanContextServiceProviderBeanInfo
00:11:43  CLT Loaded Class: ncontext.BeanContextServiceRevokedEvent
00:11:43  CLT Loaded Class: ncontext.BeanContextServiceRevokedListener
00:11:43  CLT Loaded Class: ncontext.BeanContextServices
00:11:43  CLT Loaded Class: ncontext.BeanContextServicesListener
00:11:43  CLT Loaded Class: ncontext.BeanContextServicesSupport
00:11:43  CLT Loaded Class: ncontext.BeanContextSupport
00:11:43  CLT Loaded Class: nDescriptor
00:11:43  CLT Loaded Class: nInfo
00:11:43  CLT Loaded Class: ns
00:11:43  CLT Loaded Class: tomizer
00:11:43  CLT Loaded Class: ignMode
00:11:43  CLT Loaded Class: ntSetDescriptor
00:11:43  CLT Loaded Class: tureDescriptor
00:11:43  CLT Loaded Class: exedPropertyDescriptor
00:11:43  CLT Loaded Class: rospectionException
00:11:43  CLT Loaded Class: rospector
00:11:43  CLT Loaded Class: hodDescriptor
00:11:43  CLT Loaded Class: ameterDescriptor
00:11:43  CLT Loaded Class: pertyChangeEvent
00:11:43  CLT Loaded Class: pertyChangeListener
00:11:43  CLT Loaded Class: pertyChangeSupport
00:11:43  CLT Loaded Class: pertyDescriptor
00:11:43  CLT Loaded Class: pertyEditor
00:11:43  CLT Loaded Class: pertyEditorManager
00:11:43  CLT Loaded Class: pertyEditorSupport
00:11:43  CLT Loaded Class: pertyVetoException
00:11:43  CLT Loaded Class: pleBeanInfo
00:11:43  CLT Loaded Class: oableChangeListener
00:11:43  CLT Loaded Class: oableChangeSupport
00:11:43  CLT Loaded Class: ibility
00:11:43  CLT Loaded Class: edInputStream
00:11:43  CLT Loaded Class: edOutputStream
00:11:43  CLT Loaded Class: edReader
00:11:43  CLT Loaded Class: edWriter
00:11:43  CLT Loaded Class: rayInputStream
00:11:43  CLT Loaded Class: rayOutputStream
00:11:43  CLT Loaded Class: rayReader
00:11:43  CLT Loaded Class: rayWriter
00:11:43  CLT Loaded Class: nversionException
00:11:43  CLT Loaded Class: put
00:11:43  CLT Loaded Class: putStream
00:11:43  CLT Loaded Class: tput
00:11:43  CLT Loaded Class: tputStream
00:11:43  CLT Loaded Class: eption
00:11:43  CLT Loaded Class: alizable
00:11:43  CLT Test failed:
00:11:43  CLT java.lang.StringIndexOutOfBoundsException: Range [0, 0 + 28) out of bounds for length 26
00:11:43  CLT   at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:55)
00:11:43  CLT   at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:52)
00:11:43  CLT   at java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:213)
00:11:43  CLT   at java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:210)
00:11:43  CLT   at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:98)
00:11:43  CLT   at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckFromIndexSize(Preconditions.java:118)
00:11:43  CLT   at java.base/jdk.internal.util.Preconditions.checkFromIndexSize(Preconditions.java:397)
00:11:43  CLT   at java.base/java.lang.String.checkBoundsOffCount(String.java:5362)
00:11:43  CLT   at java.base/java.lang.StringUTF16.checkBoundsOffCount(StringUTF16.java:1628)
00:11:43  CLT   at java.base/java.lang.StringUTF16.inflate(StringUTF16.java:1462)
00:11:43  CLT   at java.base/java.lang.StringLatin1.inflate(StringLatin1.java:782)
00:11:43  CLT   at java.base/java.lang.String.getBytes(String.java:5234)
00:11:43  CLT   at java.base/java.lang.StringConcatHelper.prepend(StringConcatHelper.java:298)
00:11:43  CLT   at java.base/java.lang.StringConcatHelper.simpleConcat(StringConcatHelper.java:369)
00:11:43  CLT   at net.adoptopenjdk.test.classloading.ClassHog.run(ClassHog.java:81)
00:11:43  CLT   at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
00:11:43  CLT   at java.base/java.lang.reflect.Method.invoke(Method.java:578)
00:11:43  CLT   at net.adoptopenjdk.loadTest.adaptors.ArbitraryJavaAdaptor.executeTest(ArbitraryJavaAdaptor.java:102)
00:11:43  CLT   at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182)
00:11:43  CLT   at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
00:11:43  CLT   at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
00:11:43  CLT   at java.base/java.lang.Thread.run(Thread.java:1573)
00:11:43  CLT <<<
pshipton commented 1 year ago

3x x 3 grinder https://openj9-jenkins.osuosl.org/job/Grinder/1701/ - passed (ub20-390-3, ub20-390-4, ub20-390-5) 10x x 6 grinder https://openj9-jenkins.osuosl.org/job/Grinder/1702 - passed (ub20-390-3, rh7-390-4, ub20-390-5, ub20-390-2, ub20-390-1, rh7-390-1)

JasonFengJ9 commented 1 year ago

JDK19 internal build(rhel7s390x-4-4)

openjdk version "19.0.1" 2022-10-18
IBM Semeru Runtime Open Edition 19.0.1+10 (build 19.0.1+10)
Eclipse OpenJ9 VM 19.0.1+10 (build master-a2475ea96, JRE 19 Linux s390x-64-Bit Compressed References 20221018_15 (JIT enabled, AOT enabled)
OpenJ9   - a2475ea96
OMR      - 7d8ea8b6b
JCL      - 5168276e58 based on jdk-19.0.1+10)

[2022-12-31T20:00:07.647Z] variation: Mode150
[2022-12-31T20:00:07.647Z] JVM_OPTIONS:  -XX:+UseCompressedOops 

[2022-12-31T20:02:48.960Z] CLT Test failed:
[2022-12-31T20:02:48.960Z] CLT java.lang.StringIndexOutOfBoundsException: Range [0, 0 + 28) out of bounds for length 26
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:55)
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:52)
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:213)
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:210)
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:98)
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckFromIndexSize(Preconditions.java:118)
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.util.Preconditions.checkFromIndexSize(Preconditions.java:397)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.String.checkBoundsOffCount(String.java:5362)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.StringUTF16.checkBoundsOffCount(StringUTF16.java:1628)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.StringUTF16.inflate(StringUTF16.java:1462)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.StringLatin1.inflate(StringLatin1.java:782)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.String.getBytes(String.java:5234)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.StringConcatHelper.prepend(StringConcatHelper.java:298)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.StringConcatHelper.simpleConcat(StringConcatHelper.java:369)
[2022-12-31T20:02:48.960Z] CLT  at net.adoptopenjdk.test.classloading.ClassHog.run(ClassHog.java:81)
[2022-12-31T20:02:48.960Z] CLT  at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.reflect.Method.invoke(Method.java:578)
[2022-12-31T20:02:48.960Z] CLT  at net.adoptopenjdk.loadTest.adaptors.ArbitraryJavaAdaptor.executeTest(ArbitraryJavaAdaptor.java:102)
[2022-12-31T20:02:48.960Z] CLT  at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
[2022-12-31T20:02:48.960Z] CLT  at java.base/java.lang.Thread.run(Thread.java:1573)
[2022-12-31T20:02:48.960Z] CLT <<<

[2022-12-31T20:02:48.961Z] ClassLoadingTest_5m_0_FAILED

30x grinder - all passed

babsingh commented 1 year ago

@thallium please do a preliminary triage: try to reproduce the failure (locally or in a grinder), develop a theory and probable cause for it.

thallium commented 1 year ago

https://hyc-runtimes-jenkins.swg-devops.com/job/Test_openjdk19_j9_sanity.system_s390x_linux_Personal_testList_2/11/ sanity.system passed https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/30390/ grinder passed

babsingh commented 1 year ago

@thallium https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/30390/ only ran 10 iterations. The failure is intermittent. Run two grinders for 200 iterations each. One grinder with -Xint (JIT disabled), and the other with the default options which should keep the JIT enabled.

thallium commented 1 year ago

https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/30394/ https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/30395/ @babsingh 200 iterations all passed, should I run again?

babsingh commented 1 year ago

should I run again?

No. The grinder results show that this failure is not easily reproducible. Also, it has been tagged as JIT. @thallium If you have free cycles, you can look at https://github.com/eclipse-openj9/openj9/issues/16493.

@pshipton iirc, the min failure rate needs to be 1 in 50 for it be addressed in the near future. Since this issue does not meet this requirement, can it be moved to backlog?

pshipton commented 1 year ago

Done

pshipton commented 1 year ago

@joransiu fyi

joransiu commented 1 year ago

@r30shah fyi..

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_special.system_s390x_linux_Personal_testList_3/7 ClassLoadingTest_special_5m_9 -Xaggressive -Xgcpolicy:gencon -Xjit -Xnocompressedrefs

20:07:51  CLT Test failed:
20:07:51  CLT java.lang.StringIndexOutOfBoundsException: Range [0, 0 + 28) out of bounds for length 26
20:07:51  CLT   at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:55)
20:07:51  CLT   at java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:52)
20:07:51  CLT   at java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:213)
20:07:51  CLT   at java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:210)
20:07:51  CLT   at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:98)
20:07:51  CLT   at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckFromIndexSize(Preconditions.java:118)
20:07:51  CLT   at java.base/jdk.internal.util.Preconditions.checkFromIndexSize(Preconditions.java:397)
20:07:51  CLT   at java.base/java.lang.String.checkBoundsOffCount(String.java:5362)
20:07:51  CLT   at java.base/java.lang.StringUTF16.checkBoundsOffCount(StringUTF16.java:1628)
20:07:51  CLT   at java.base/java.lang.StringUTF16.inflate(StringUTF16.java:1462)
20:07:51  CLT   at java.base/java.lang.StringLatin1.inflate(StringLatin1.java:782)
20:07:51  CLT   at java.base/java.lang.String.getBytes(String.java:5234)
20:07:51  CLT   at java.base/java.lang.StringConcatHelper.prepend(StringConcatHelper.java:298)
20:07:51  CLT   at java.base/java.lang.StringConcatHelper.simpleConcat(StringConcatHelper.java:369)
20:07:51  CLT   at net.adoptopenjdk.test.classloading.ClassHog.run(ClassHog.java:81)
r30shah commented 1 year ago

@dchopra001 Given that this is String related, can you take a look whenever you get chance? Adjust the priority based on the failure rate on previous grinders