OpenJDK java/util/Map/InPlaceOpsCollisions NullPointerException String.charAt #17922

pshipton · 2023-08-09T15:38:50Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_Nightly_testList_1/26
jdk_util_0
java/util/Map/InPlaceOpsCollisions.java

21:58:49  test InPlaceOpsCollisions.testMergeNull("Hashtable with unique strings", MapWithCollisionsProviders$$Lambda$41/0x0000000000000000@ca803881, "Extra Value"): failure
21:58:49  java.lang.NullPointerException
21:58:49  	at java.base/java.lang.String.charAt(String.java:1319)
21:58:49  	at java.base/java.util.Formatter.checkText(Formatter.java:2730)
21:58:49  	at java.base/java.util.Formatter.parse(Formatter.java:2708)
21:58:49  	at java.base/java.util.Formatter.format(Formatter.java:2655)
21:58:49  	at java.base/java.util.Formatter.format(Formatter.java:2609)
21:58:49  	at java.base/java.lang.String.format(String.java:3728)
21:58:49  	at InPlaceOpsCollisions.removeThirdKeys(InPlaceOpsCollisions.java:485)
21:58:49  	at InPlaceOpsCollisions.testMergeNull(InPlaceOpsCollisions.java:426)
21:58:49  	at jdk.internal.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
21:58:49  	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
21:58:49  	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
21:58:49  	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
21:58:49  	at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599)
21:58:49  	at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174)
21:58:49  	at org.testng.internal.MethodRunner.runInSequence(Met
21:58:49  
21:58:49  ...
21:58:49  Output overflow:
21:58:49  JT Harness has limited the test output to the text
21:58:49  at the beginning and the end, so that you can see how the
21:58:49  test began, and how it completed.
21:58:49  
21:58:49  If you need to see more of the output from the test,
21:58:49  set the system property javatest.maxOutputSize to a higher
21:58:49  value. The current value is 100000
21:58:49  ...
21:58:49  
21:58:49  l.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822)
21:58:49  	at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
21:58:49  	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
21:58:49  	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
21:58:49  	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
21:58:49  	at org.testng.TestRunner.privateRun(TestRunner.java:764)
21:58:49  	at org.testng.TestRunner.run(TestRunner.java:585)
21:58:49  	at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
21:58:49  	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
21:58:49  	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
21:58:49  	at org.testng.SuiteRunner.run(SuiteRunner.java:286)
21:58:49  	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
21:58:49  	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
21:58:49  	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
21:58:49  	at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
21:58:49  	at org.testng.TestNG.runSuites(TestNG.java:1069)
21:58:49  	at org.testng.TestNG.run(TestNG.java:1037)
21:58:49  	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
21:58:49  	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
21:58:49  	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
21:58:49  	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
21:58:49  	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
21:58:49  	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
21:58:49  	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
21:58:49  	at java.base/java.lang.Thread.run(Thread.java:839)
21:58:49  test InPlaceOpsCollisions.testReplaceOldValue("TreeMap with colliding objects", MapWithCollisionsProviders$$Lambda$41/0x0000000000000000@e3f8f134, 2500): failure
21:58:49  java.lang.NullPointerException
21:58:49  	at java.base/java.lang.String.charAt(String.java:1319)
21:58:49  	at java.base/java.util.Formatter.checkText(Formatter.java:2730)
21:58:49  	at java.base/java.util.Formatter.parse(Formatter.java:2708)
21:58:49  	at java.base/java.util.Formatter.format(Formatter.java:2655)
21:58:49  	at java.base/java.util.Formatter.format(Formatter.java:2609)
21:58:49  	at java.base/java.lang.String.format(String.java:3728)
21:58:49  	at InPlaceOpsCollisions.testReplaceOldValue(InPlaceOpsCollisions.java:122)
21:58:49  	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
21:58:49  	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
21:58:49  	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
21:58:49  	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
21:58:49  	at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
21:58:49  	at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:599)
21:58:49  	at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:174)
21:58:49  	at org.testng.internal.MethodRunner.runInSequence(MethodRunner.java:46)
21:58:49  	at org.testng.internal.TestInvoker$MethodInvocationAgent.invoke(TestInvoker.java:822)
21:58:49  	at org.testng.internal.TestInvoker.invokeTestMethods(TestInvoker.java:147)
21:58:49  	at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:146)
21:58:49  	at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:128)
21:58:49  	at java.base/java.util.ArrayList.forEach(ArrayList.java:1541)
21:58:49  	at org.testng.TestRunner.privateRun(TestRunner.java:764)
21:58:49  	at org.testng.TestRunner.run(TestRunner.java:585)
21:58:49  	at org.testng.SuiteRunner.runTest(SuiteRunner.java:384)
21:58:49  	at org.testng.SuiteRunner.runSequentially(SuiteRunner.java:378)
21:58:49  	at org.testng.SuiteRunner.privateRun(SuiteRunner.java:337)
21:58:49  	at org.testng.SuiteRunner.run(SuiteRunner.java:286)
21:58:49  	at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:53)
21:58:49  	at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:96)
21:58:49  	at org.testng.TestNG.runSuitesSequentially(TestNG.java:1218)
21:58:49  	at org.testng.TestNG.runSuitesLocally(TestNG.java:1140)
21:58:49  	at org.testng.TestNG.runSuites(TestNG.java:1069)
21:58:49  	at org.testng.TestNG.run(TestNG.java:1037)
21:58:49  	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:94)
21:58:49  	at com.sun.javatest.regtest.agent.TestNGRunner.main(TestNGRunner.java:54)
21:58:49  	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
21:58:49  	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
21:58:49  	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
21:58:49  	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
21:58:49  	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
21:58:49  	at java.base/java.lang.Thread.run(Thread.java:839)

etc.

The text was updated successfully, but these errors were encountered:

pshipton · 2023-08-09T15:40:31Z

Looks like a dup of #17774

knn-k · 2023-08-16T10:25:24Z

Reproduced 3 times in a 30x Grinder job.
https://openj9-jenkins.osuosl.org/job/Grinder_testList_0/253/consoleText

pshipton · 2023-08-16T10:33:25Z

3/30 is frequent enough to be a blocker.

knn-k · 2023-08-18T03:04:33Z

I haven't been able to reproduce the failure locally, running the test more than 60 times.
I used the binary from https://openj9-jenkins.osuosl.org/job/Build_JDK11_aarch64_linux_Nightly/489/

knn-k · 2023-08-18T23:23:47Z

I ran a 30x Grinder job with the latest nightly build from https://openj9-jenkins.osuosl.org/job/Build_JDK11_aarch64_linux_Nightly/498/, and got no failures.

knn-k · 2023-08-20T23:47:14Z

Another 30x Grinder job was also successful.
https://openj9-jenkins.osuosl.org/job/Grinder/2808/

hzongaro · 2023-08-22T15:28:53Z

Failure is highly intermittent, and hasn't been reproduced in a couple of weeks. I'll move it out to 0.43 for now.

pshipton · 2023-09-07T15:15:19Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OpenJDK11_testList_1/7/
jdk_util_0
java/util/Map/InPlaceOpsCollisions.java

09:50:33  test InPlaceOpsCollisions.testReplaceOldValue("HashMap with unique strings", MapWithCollisionsProviders$$Lambda$41/0x0000000000000000@a1a85b9f, "Extra Value"): failure
09:50:33  java.lang.NullPointerException
09:50:33  	at java.base/java.lang.String.charAt(String.java:1319)
09:50:33  	at java.base/java.util.Formatter.checkText(Formatter.java:2730)
09:50:33  	at java.base/java.util.Formatter.parse(Formatter.java:2708)
09:50:33  	at java.base/java.util.Formatter.format(Formatter.java:2655)
09:50:33  	at java.base/java.util.Formatter.format(Formatter.java:2609)
09:50:33  	at java.base/java.lang.String.format(String.java:3728)
09:50:33  	at InPlaceOpsCollisions.testReplaceOldValue(InPlaceOpsCollisions.java:122)

java/util/stream/boottest/java.base/java/util/stream/SpinedBufferTest.java

09:51:33  test java.util.stream.SpinedBufferTest.testSpliterator([I@c4fc7620, java.util.stream.SpinedBuffer@ec898b6b): failure
09:51:33  java.lang.NullPointerException
09:51:33  	at java.base/java.lang.String.charAt(String.java:1319)
09:51:33  	at java.base/java.util.Formatter.checkText(Formatter.java:2730)
09:51:33  	at java.base/java.util.Formatter.parse(Formatter.java:2708)
09:51:33  	at java.base/java.util.Formatter.format(Formatter.java:2655)
09:51:33  	at java.base/java.util.Formatter.format(Formatter.java:2609)
09:51:33  	at java.base/java.lang.String.format(String.java:3728)
09:51:33  	at java.base/java.util.SpliteratorTestHelper.testSplitUntilNull(SpliteratorTestHelper.java:578)
09:51:33  	at java.base/java.util.SpliteratorTestHelper.testSplitUntilNull(SpliteratorTestHelper.java:529)
09:51:33  	at java.base/java.util.SpliteratorTestHelper.testSpliterator(SpliteratorTestHelper.java:167)
09:51:33  	at java.base/java.util.SpliteratorTestHelper.testSpliterator(SpliteratorTestHelper.java:53)
09:51:33  	at java.base/java.util.SpliteratorTestHelper.testSpliterator(SpliteratorTestHelper.java:48)
09:51:33  	at java.base/java.util.stream.SpinedBufferTest.testSpliterator(SpinedBufferTest.java:92)

knn-k · 2023-09-08T07:45:54Z

I ran a 20x jdk_util_0 Grinder job, and got no failures.
https://openj9-jenkins.osuosl.org/job/Grinder/2875/

knn-k · 2023-09-10T23:27:27Z

Another 20x Grinder job did not fail, either.
https://openj9-jenkins.osuosl.org/job/Grinder/2876/

Akira1Saitoh · 2023-09-22T02:54:41Z

I was able to reproduce it and get dumps with -Xdump option.

https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/35030/

[2023-09-18T09:54:25.354Z] STDERR:
[2023-09-18T09:54:25.354Z] JVMDUMP039I Processing dump event "systhrow", detail "java/lang/NullPointerException" at 2023/09/18 05:26:33 - please wait.
[2023-09-18T09:54:25.354Z] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16950234906686/jdk_custom_0_ITER_69/work/scratch/0/core.20230918.052633.2686893.0001.dmp' in response to an event
[2023-09-18T09:54:25.354Z] JVMDUMP010I System dump written to /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16950234906686/jdk_custom_0_ITER_69/work/scratch/0/core.20230918.052633.2686893.0001.dmp
[2023-09-18T09:54:25.354Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16950234906686/jdk_custom_0_ITER_69/work/scratch/0/javacore.20230918.052633.2686893.0002.txt' in response to an event
[2023-09-18T09:54:25.354Z] JVMDUMP010I Java dump written to /home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16950234906686/jdk_custom_0_ITER_69/work/scratch/0/javacore.20230918.052633.2686893.0002.txt
[2023-09-18T09:54:25.354Z] JVMDUMP032I JVM requested JIT dump using '/home/jenkins/workspace/Grinder/aqa-tests/TKG/output_16950234906686/jdk_custom_0_ITER_69/work/scratch/0/jitdump.20230918.052633.2686893.0003.dmp' in response to an event
[2023-09-18T09:54:25.354Z] JVMDUMP051I JIT dump occurred in 'MainThread' thread 0x00000000001B1400
[2023-09-18T09:54:25.354Z] JVMDUMP053I JIT dump is recompiling java/util/Formatter.format(Ljava/util/Locale;Ljava/lang/String;[Ljava/lang/Object;)Ljava/util/Formatter;

Unfortunately, jitdump was not available.

1XMCURTHDINFO  Current thread
3XMTHREADINFO      "MainThread" J9VMThread:0x00000000001B1400, omrthread_t:0x0000FFFF7828CA40, java/lang/Thread:0x00000000E00CD2C0, state:R, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x1A, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x00000000E0044E60)
3XMTHREADINFO1            (native thread ID:0x28FFCA, native priority:0x5, native policy:UNKNOWN, vmstate:R, vm thread flags:0x00041020)
3XMTHREADINFO2            (native stack address range from:0x0000FFFF5D4D4000, to:0x0000FFFF5D514000, size:0x40000)
3XMCPUTIME               CPU usage total: 34.072865580 secs, current category="Application"
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at java/lang/String.charAt(String.java:1319(Compiled Code))
4XESTACKTRACE                at java/util/Formatter.checkText(Formatter.java:2730(Compiled Code))
4XESTACKTRACE                at java/util/Formatter.parse(Formatter.java:2708(Compiled Code))
4XESTACKTRACE                at java/util/Formatter.format(Formatter.java:2655(Compiled Code))
4XESTACKTRACE                at java/util/Formatter.format(Formatter.java:2609(Compiled Code))
4XESTACKTRACE                at java/lang/String.format(String.java:3728(Compiled Code))
4XESTACKTRACE                at InPlaceOpsCollisions.testMergeNull(InPlaceOpsCollisions.java:446(Compiled Code))
...

<1b1400> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x00000000001B1400 ***
<1b1400>        ITERATE_O_SLOTS
<1b1400>        RECORD_BYTECODE_PC_OFFSET
<1b1400> Initial values: walkSP = 0x00000000001B6B08, PC = 0x0000000000000005, literals = 0x0000000000000000, A0 = 0x00000000001
B6B28, j2iFrame = 0x0000000000000000, ELS = 0x0000FFFF5D511B80, decomp = 0x0000000000000000
<1b1400> JIT resolve frame: bp = 0x00000000001B6B28, sp = 0x00000000001B6B08, pc = 0x0000000000000005, cp = 0x0000000000000000, 
arg0EA = 0x00000000001B6B28, flags = 0x0000000000080000
<1b1400>        Object push (savedJITException)
<1b1400>                O-Slot[0x00000000001B6B08] = 0x0000000000000000
<1b1400>        Generic resolve
<1b1400>        unwindSP initialized to 0x00000000001B6B30
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511810] = UDATA(0x0000000000000000) (jit_r0)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511818] = UDATA(0x000000000000001E) (jit_r1)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511820] = UDATA(0x00000000FFDA5818) (jit_r2)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511828] = UDATA(0x00000000E0572C60) (jit_r3)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511830] = UDATA(0x000000000000001E) (jit_r4)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511838] = UDATA(0x00000000FFDA5758) (jit_r5)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511840] = UDATA(0x00000000E0149558) (jit_r6)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511848] = UDATA(0x00000000E0572C60) (jit_r7)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511850] = UDATA(0x00000000FFDA57C0) (jit_r8)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511858] = UDATA(0x00000000E003F020) (jit_r9)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511860] = UDATA(0x0000000000000017) (jit_r10)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511868] = UDATA(0x00000000E0572C70) (jit_r11)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511870] = UDATA(0x0000000000000000) (jit_r12)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511878] = UDATA(0x000000000000001E) (jit_r13)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511880] = UDATA(0x0000000000000000) (jit_r14)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511888] = UDATA(0x0000000000000001) (jit_r15)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511890] = UDATA(0x0000FFFF7DC7D984) (jit_r16)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511898] = UDATA(0x0000FFFF7F7A64C0) (jit_r17)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118A0] = UDATA(0x000000000000001C) (jit_r18)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118A8] = UDATA(0x00000000001B1400) (jit_r19)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118B0] = UDATA(0x00000000001B6B30) (jit_r20)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118B8] = UDATA(0x00000000FFDA5770) (jit_r21)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118C0] = UDATA(0x00000000E01713F8) (jit_r22)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118C8] = UDATA(0x0000000000000000) (jit_r23)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118D0] = UDATA(0x000000000000001E) (jit_r24)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118D8] = UDATA(0x00000000FFDA5758) (jit_r25)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118E0] = UDATA(0x00000000E0149558) (jit_r26)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118E8] = UDATA(0x0000000000000001) (jit_r27)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118F0] = UDATA(0x0000000000000017) (jit_r28)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D5118F8] = UDATA(0x0000002B5D511A68) (jit_r29)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511900] = UDATA(0x0000FFFF5FBC6138) (jit_r30)
<1b1400>        JIT-Resolve-RegisterMap[0x0000FFFF5D511908] = UDATA(0x0000FFFF7802EA90) (jit_r31)
<1b1400> JIT inline frame: bp = 0x00000000001B6D48, pc = 0x0000FFFF5FBC8171, unwindSP = 0x00000000001B6B30, cp = 0x0000000000034
A20, arg0EA = 0x0000000000000000, jitInfo = 0x0000FFFF5C0D5698
<1b1400>        Method: java/lang/String.charAt(I)C !j9method 0x0000000000033D38
<1b1400>        Bytecode index = 2, inlineDepth = 3, PC offset = 0x000000000010C355
<1b1400> JIT inline frame: bp = 0x00000000001B6D48, pc = 0x0000FFFF5FBC8171, unwindSP = 0x00000000001B6B30, cp = 0x00000000001F8
8F0, arg0EA = 0x0000000000000000, jitInfo = 0x0000FFFF5C0D5698
<1b1400>        Method: java/util/Formatter.checkText(Ljava/lang/String;II)V !j9method 0x00000000001F9338
<1b1400>        Bytecode index = 9, inlineDepth = 2, PC offset = 0x0000000000129031
<1b1400> JIT inline frame: bp = 0x00000000001B6D48, pc = 0x0000FFFF5FBC8171, unwindSP = 0x00000000001B6B30, cp = 0x00000000001F8
8F0, arg0EA = 0x0000000000000000, jitInfo = 0x0000FFFF5C0D5698
<1b1400>        Method: java/util/Formatter.parse(Ljava/lang/String;)Ljava/util/List; !j9method 0x00000000001F9318
<1b1400>        Bytecode index = 57, inlineDepth = 1, PC offset = 0x000000000004817D
<1b1400> JIT frame: bp = 0x00000000001B6D48, pc = 0x0000FFFF5FBC8171, unwindSP = 0x00000000001B6B30, cp = 0x00000000001F88F0, ar
g0EA = 0x00000000001B6D68, jitInfo = 0x0000FFFF5C0D5698
<1b1400>        Method: java/util/Formatter.format(Ljava/util/Locale;Ljava/lang/String;[Ljava/lang/Object;)Ljava/util/Formatter;
 !j9method 0x00000000001F92F8
<1b1400>        Bytecode index = 57, inlineDepth = 0, PC offset = 0x0000000000003925
<1b1400>        stackMap=0x0000FFFF5C0D7D41, slots=I16(0x0004) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0004), localBaseOffse
t=I16(0xFE90)
<1b1400>        Described JIT args starting at 0x00000000001B6D50 for U16(0x0004) slots
<1b1400>                O-Slot: : a3[0x00000000001B6D50] = 0x00000000FFDA56F0
<1b1400>                O-Slot: : a2[0x00000000001B6D58] = 0x00000000E0572C60
<1b1400>                O-Slot: : a1[0x00000000001B6D60] = 0x00000000E0038A90
<1b1400>                O-Slot: : a0[0x00000000001B6D68] = 0x00000000FFDA5710
<1b1400>        Described JIT temps starting at 0x00000000001B6BD8 for IDATA(0x000000000000002E) slots
...

(kca) x/64i 0xffff5fbc810c
0xffff5fbc810c {java/util/Formatter.format} +14528                      d2867300 mov       x0, #0x3398 CONST 0x33398 Ptr Obj - {java/lang/String$StringCompressionFlag}T <<< +4232
0xffff5fbc8110 {java/util/Formatter.format} +14532                      f2a00060 movk      x0, #3, lsl #16
0xffff5fbc8114 {java/util/Formatter.format} +14536                      f9400000 ldr       x0, [x0]
0xffff5fbc8118 {java/util/Formatter.format} +14540                      f9411680 ldr       x0, [x20, #0x228]      <--- String "compute: containsValue(%s[%s])"
0xffff5fbc811c {java/util/Formatter.format} +14544                      b940040b ldr       w11, [x0, #4]            <--- [B value
0xffff5fbc8120 {java/util/Formatter.format} +14548                      b940080c ldr       w12, [x0, #8]           <--- B coder
0xffff5fbc8124 {java/util/Formatter.format} +14552                      b9400560 ldr       w0, [x11, #4]
0xffff5fbc8128 {java/util/Formatter.format} +14556                      1acc240d lsr       w13, w0, w12
0xffff5fbc812c {java/util/Formatter.format} +14560                      d2867300 mov       x0, #0x3398 CONST 0x33398 Ptr Obj - {java/lang/String$StringCompressionFlag}T
0xffff5fbc8130 {java/util/Formatter.format} +14564                      f2a00060 movk      x0, #3, lsl #16
0xffff5fbc8134 {java/util/Formatter.format} +14568                      f9400009 ldr       x9, [x0]
0xffff5fbc8138 {java/util/Formatter.format} +14572                      f9402a60 ldr       x0, [x19, #0x50] <<< ^+17636
0xffff5fbc813c {java/util/Formatter.format} +14576                      b100041f cmn       x0, #1
0xffff5fbc8140 {java/util/Formatter.format} +14580         32:2         54031ec0 b.eq      #0xffff5fbce518 C>> +40140  // ificmpgt C>> +63
0xffff5fbc8144 {java/util/Formatter.format} +14584                      6b0d01df cmp       w14, w13 <<< ^+40144
0xffff5fbc8148 {java/util/Formatter.format} +14588                      540280ea b.ge      #0xffff5fbcd164 C>> +35096 
0xffff5fbc814c {java/util/Formatter.format} +14592                      d503201f nop       
0xffff5fbc8150 {java/util/Formatter.format} +14596                      b9400560 ldr       w0, [x11, #4]
0xffff5fbc8154 {java/util/Formatter.format} +14600                      1acc2401 lsr       w1, w0, w12
0xffff5fbc8158 {java/util/Formatter.format} +14604                      4b0e0021 sub       w1, w1, w14
0xffff5fbc815c {java/util/Formatter.format} +14608                      528b75c0 mov       w0, #0x5bae
0xffff5fbc8160 {java/util/Formatter.format} +14612                      72a008a0 movk      w0, #0x45, lsl #16
0xffff5fbc8164 {java/util/Formatter.format} +14616                      6b00003f cmp       w1, w0
0xffff5fbc8168 {java/util/Formatter.format} +14620                      5400ec2c b.gt      #0xffff5fbc9eec C>> +22176 
0xffff5fbc816c {java/util/Formatter.format} +14624                      f9405680 ldr       x0, [x20, #0xa8]   <--- 0 is loaded into x0
0xffff5fbc8170 {java/util/Formatter.format} +14628                      b9400401 ldr       w1, [x0, #4]          <--- NPE here
0xffff5fbc8174 {java/util/Formatter.format} +14632                      b9409280 ldr       w0, [x20, #0x90]
0xffff5fbc8178 {java/util/Formatter.format} +14636                      1ac02422 lsr       w2, w1, w0
0xffff5fbc817c {java/util/Formatter.format} +14640                      b401ad09 cbz       x9, #0xffff5fbcb71c C>> +28368 
0xffff5fbc8180 {java/util/Formatter.format} +14644                      b900928c str       w12, [x20, #0x90]
0xffff5fbc8184 {java/util/Formatter.format} +14648                      b9409280 ldr       w0, [x20, #0x90]
0xffff5fbc8188 {java/util/Formatter.format} +14652                      35005c00 cbnz      w0, #0xffff5fbc8d08 C>> +17596 
0xffff5fbc818c {java/util/Formatter.format} +14656                      b9409280 ldr       w0, [x20, #0x90]
0xffff5fbc8190 {java/util/Formatter.format} +14660                      34005de0 cbz       w0, #0xffff5fbc8d4c C>> +17664 
0xffff5fbc8194 {java/util/Formatter.format} +14664                      f900568b str       x11, [x20, #0xa8]
0xffff5fbc8198 {java/util/Formatter.format} +14668                      f9405680 ldr       x0, [x20, #0xa8]
0xffff5fbc819c {java/util/Formatter.format} +14672                      8b2ec000 add       x0, x0, w14, sxtw
0xffff5fbc81a0 {java/util/Formatter.format} +14676                      39402000 ldrb      w0, [x0, #8]
0xffff5fbc81a4 {java/util/Formatter.format} +14680                      7100941f cmp       w0, #0x25
0xffff5fbc81a8 {java/util/Formatter.format} +14684                      54014040 b.eq      #0xffff5fbca9b0 C>> +24932

Akira1Saitoh · 2023-09-25T02:37:22Z

I got a jitdump generated on NullPointerException. https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder_iteration_2/2478/

NullPointerException was thrown when loading arrayLength of String.value because the address loaded from [w20, 168] <temp slot 68> was 0.

29373  \\ java/util/Formatter.format(Ljava/util/Locale;Ljava/lang/String;[Ljava/lang/Object;)Ljava/util/Formatter;
2929374  \\   12 JBinvokespecial 55 java/util/Formatter.parse(Ljava/lang/String;)Ljava/util/List;
2929375  \\      57 JBinvokestatic 72 java/util/Formatter.checkText(Ljava/lang/String;II)V
2929376  \\          9 JBinvokevirtual 79 java/lang/String.charAt(I)C
2929377  \\             7 JBinvokevirtual 32 java/lang/String.lengthInternal()I
2929378  \\                7 JBgetfield 34 java/lang/String.value [B
2929379 
2929380     0xffff6633cf84 000038f0 [    0xfffee381ab00] f9405680 7     ldrimmx         w0, [w20, 168]          # SymRef  <temp slot 68>[#3577  Auto +168] [flags 0x7 0x0 ]     
2929381 
2929382  \\ java/util/Formatter.format(Ljava/util/Locale;Ljava/lang/String;[Ljava/lang/Object;)Ljava/util/Formatter;
2929383  \\   12 JBinvokespecial 55 java/util/Formatter.parse(Ljava/lang/String;)Ljava/util/List;
2929384  \\      57 JBinvokestatic 72 java/util/Formatter.checkText(Ljava/lang/String;II)V
2929385  \\          9 JBinvokevirtual 79 java/lang/String.charAt(I)C
2929386  \\             7 JBinvokevirtual 32 java/lang/String.lengthInternal()I
2929387  \\               10 JBarraylength 
2929388 
2929389     0xffff6633cf88 000038f4 [    0xfffee381ab90] b9400401 10    ldrimmw         w1, [w0, 4]             # SymRef  <contiguous-array-size>[#261  Shadow +4] [flags 0x603 0x0 ]      <-- NPE here

The aload node for <temp slot 68> is n35809n. I do not find a astore node for <temp slot 68> before this node, although there are many after it.

2718809  n35813n  (  0)  treetop                                                                              [    0xfffeedd8aa0
2718809 0] bci=[33,15,2288] rc=0 vc=4032 vn=- li=1706 udi=- nc=1
2718810  n35812n  (  0)    iushr (in GPR_    0xfffee381ad70) (X>=0 cannotOverflow )                           [    0xfffeedd8a9b
2718810 0] bci=[33,15,2288] rc=0 vc=4032 vn=- li=1706 udi=44400 nc=2 flg=0x1100
2718811  n35810n  (  0)      iloadi  <contiguous-array-size>[#261  Shadow +4] [flags 0x603 0x0 ] (in GPR_    0xfffee381a980) (X>
2718811 =0 cannotOverflow )  [    0xfffeedd8a910] bci=[33,10,2288] rc=0 vc=4032 vn=- li=1706 udi=43392 nc=1 flg=0x1100
2718812  n35809n  (  0)        aload  <temp slot 68>[#3577  Auto] [flags 0x7 0x0 ] (in &GPR_    0xfffee381aa40) (X!=0 )  [    0x
2718812 fffeedd8a8c0] bci=[33,7,2288] rc=0 vc=4032 vn=- li=1706 udi=43584 nc=0 flg=0x4
2718813  n35811n  (  0)      iload  <temp slot 69>[#3578  Auto] [flags 0x3 0x0 ] (in GPR_    0xfffee381ac20) (cannotOverflow )  
2718813 [    0xfffeedd8a960] bci=[33,12,2288] rc=0 vc=4032 vn=- li=1706 udi=44064 nc=0 flg=0x1000
2718814 ------------------------------
2718815 
2718816  [    0xfffee381ab00]   7       ldrimmx         &GPR_    0xfffee381aa40, [w20, 0]               # SymRef  <temp slot 68>
2718816 [#3577  Auto] [flags 0x7 0x0 ]  
2718817  [    0xfffee381ab90]   10      ldrimmw         GPR_    0xfffee381a980, [&GPR_    0xfffee381aa40, 4]            # SymRef
2718817   <contiguous-array-size>[#261  Shadow +4] [flags 0x603 0x0 ]   
2718818  [    0xfffee381ace0]   12      ldrimmw         GPR_    0xfffee381ac20, [w20, 0]                # SymRef  <temp slot 69>
2718818 [#3578  Auto] [flags 0x3 0x0 ]  
2718819  [    0xfffee381ade0]   15      lsrvw   GPR_    0xfffee381ad70, GPR_    0xfffee381a980, GPR_    0xfffee381ac20

In the optimization phase, there was an astore node for <temp slot 68> (n35794n) before n35809n, but it was moved to block_2099 by generalStoreSinking.

1904811 n35838n   BBStart <block_1701> (freq 509) (extension of previous block) (cold) (in loop 378)  [    0xfffeedd8b1d0] bci=[32,2,1319] rc=0 vc=12763 vn=- li=- udi=- nc=0
1904812 n35794n   astore  <temp slot 68>[#3577  Auto] [flags 0x7 0x0 ] (X!=0 )                        [    0xfffeedd8a410] bci=[33,7,2288] rc=0 vc=12763 vn=- li=- udi=417 nc=1 flg=0x4
1904813 n35793n     aload  <temp slot 90>[#3604  Auto] [flags 0x7 0x0 ] (X!=0 createdByPRE )          [    0xfffeedd8a3c0] bci=[33,7,2288] rc=2 vc=12763 vn=- li=- udi=611 nc=0 flg=0x40004
1904814 n35800n   istore  <temp slot 69>[#3578  Auto] [flags 0x3 0x0 ]                                [    0xfffeedd8a5f0] bci=[33,12,2288] rc=0 vc=12763 vn=- li=- udi=418 nc=1
1904815 n35799n     iload  <temp slot 92>[#3606  Auto] [flags 0x3 0x0 ] (cannotOverflow createdByPRE )  [    0xfffeedd8a5a0] bci=[33,12,2288] rc=2 vc=12763 vn=- li=- udi=612 nc=0 flg=0x41000
1904816 n35808n   ificmpgt --> block_1696 BBStart at n35756n (maxLoopIternGuard )                     [    0xfffeedd8a870] bci=[33,15,2288] rc=0 vc=12763 vn=- li=- udi=- nc=2 flg=0x820
1904817 n35806n     isub (cannotOverflow )                                                            [    0xfffeedd8a7d0] bci=[33,15,2288] rc=1 vc=12763 vn=- li=- udi=- nc=2 flg=0x1000
1904818 n35804n       iushr (X>=0 cannotOverflow )                                                    [    0xfffeedd8a730] bci=[33,15,2288] rc=1 vc=12763 vn=- li=- udi=- nc=2 flg=0x1100
1904819 n35802n         arraylength (stride 1) (X>=0 cannotOverflow )                                 [    0xfffeedd8a690] bci=[33,10,2288] rc=1 vc=12763 vn=- li=- udi=- nc=1 flg=0x1100
1904820 n35793n           ==>aload
1904821 n35799n         ==>iload
1904822 n35805n       iload  i<auto slot 3>[#2343  Auto] [flags 0x3 0x0 ] (X>=0 cannotOverflow )      [    0xfffeedd8a780] bci=[32,5,1319] rc=1 vc=12763 vn=- li=- udi=613 nc=0 flg=0x1100
1904823 n35807n     iconst 0x455bae (X!=0 X>=0 )                                                      [    0xfffeedd8a820] bci=[33,15,2288] rc=1 vc=12763 vn=- li=- udi=- nc=0 flg=0x104
1904824 n35828n   BBEnd </block_1701> (cold)                                                          [    0xfffeedd8aeb0] bci=[32,2,1319] rc=0 vc=12763 vn=- li=- udi=- nc=0
1904825 n35825n   BBStart <block_1706> (freq 509) (extension of previous block) (cold) (in loop 378)  [    0xfffeedd8adc0] bci=[32,2,1319] rc=0 vc=12763 vn=- li=- udi=- nc=0
1904826 n35813n   istore  <temp slot 70>[#3579  Auto] [flags 0x3 0x0 ]                                [    0xfffeedd8aa00] bci=[33,15,2288] rc=0 vc=12763 vn=- li=- udi=419 nc=1
1904827 n35812n     iushr (X>=0 cannotOverflow )                                                      [    0xfffeedd8a9b0] bci=[33,15,2288] rc=1 vc=12763 vn=- li=- udi=- nc=2 flg=0x1100
1904828 n35810n       arraylength (stride 1) (X>=0 cannotOverflow )                                   [    0xfffeedd8a910] bci=[33,10,2288] rc=1 vc=12763 vn=- li=- udi=- nc=1 flg=0x1100
1904829 n35809n         aload  <temp slot 68>[#3577  Auto] [flags 0x7 0x0 ] (X!=0 )                   [    0xfffeedd8a8c0] bci=[33,7,2288] rc=1 vc=12763 vn=- li=- udi=614 nc=0 flg=0x4
1904830 n35811n       iload  <temp slot 69>[#3578  Auto] [flags 0x3 0x0 ] (cannotOverflow )           [    0xfffeedd8a960] bci=[33,12,2288] rc=1 vc=12763 vn=- li=- udi=615 nc=0 flg=0x1000
1904831 n45386n   ifacmpeq --> block_2055 BBStart at n45378n (swappedChildren )                       [    0xfffeea525a50] bci=[32,23,1321] rc=0 vc=12763 vn=- li=- udi=- nc=2 flg=0x20020
1904832 n45384n     aload  <temp slot 118>[#3632  Auto] [flags 0x7 0x0 ] (createdByPRE )              [    0xfffeea5259b0] bci=[32,20,1321] rc=1 vc=12763 vn=- li=- udi=- nc=0 flg=0x40000
1904833 n45385n     aconst NULL (X==0 )                                                               [    0xfffeea525a00] bci=[32,19,1321] rc=1 vc=12763 vn=- li=- udi=- nc=0 flg=0x2
1904834 n45394n   BBEnd </block_1706> (cold) 
...
1904849 n45897n   BBStart <block_2099> (freq 509) (extension of previous block) (cold) (in loop 378)  [    0xfffeea52fa00] bci=[1904849 31,9,2730] rc=0 vc=12763 vn=- li=- udi=- nc=0
1904850 n45899n   istore  <temp slot 6>[#2376  Auto] [flags 0x3 0x0 ]                                 [    0xfffeea52faa0] bci=[1904850 32,50,1322] rc=0 vc=12763 vn=- li=- udi=420 nc=1

1918338 <optimization id=217 name=generalStoreSinking method=java/util/Formatter.format(Ljava/util/Locale;Ljava/lang/String;[Ljava/lang/Object;)Ljava/util/Formatter;>
1918339 Performing 217: generalStoreSinking
...
1918390 [ 16104] O^O SINK STORES:  Finding placements for store [0000FFFEEDD8A410]  with tree depth 2
...
1923744 n35838n   BBStart <block_1701> (freq 509) (extension of previous block) (cold)                [    0xfffeedd8b1d0] bci=[
1923744 32,2,1319] rc=0 vc=3 vn=- li=- udi=- nc=0
1923745 n35808n   ificmpgt --> block_1696 BBStart at n35756n (maxLoopIternGuard )                     [    0xfffeedd8a870] bci=[33,15,2288] rc=0 vc=1707 vn=- li=- udi=- nc=2 flg=0x820
1923746 n35806n     isub (cannotOverflow )                                                            [    0xfffeedd8a7d0] bci=[33,15,2288] rc=1 vc=1707 vn=- li=- udi=- nc=2 flg=0x1000
1923747 n35804n       iushr (X>=0 cannotOverflow )                                                    [    0xfffeedd8a730] bci=[33,15,2288] rc=1 vc=1707 vn=- li=- udi=- nc=2 flg=0x1100
1923748 n35802n         arraylength (stride 1) (X>=0 cannotOverflow )                                 [    0xfffeedd8a690] bci=[33,10,2288] rc=1 vc=1707 vn=- li=- udi=- nc=1 flg=0x1100
1923749 n35793n           aload  <temp slot 90>[#3604  Auto] [flags 0x7 0x0 ] (X!=0 createdByPRE )    [    0xfffeedd8a3c0] bci=[33,7,2288] rc=2 vc=1709 vn=- li=- udi=611 nc=0 flg=0x40004
1923750 n35799n         iload  <temp slot 92>[#3606  Auto] [flags 0x3 0x0 ] (cannotOverflow createdByPRE )  [    0xfffeedd8a5a0]  bci=[33,12,2288] rc=2 vc=1708 vn=- li=- udi=612 nc=0 flg=0x41000
1923751 n35805n       iload  i<auto slot 3>[#2343  Auto] [flags 0x3 0x0 ] (X>=0 cannotOverflow )      [    0xfffeedd8a780] bci=[32,5,1319] rc=1 vc=1707 vn=- li=- udi=613 nc=0 flg=0x1100
1923752 n35807n     iconst 0x455bae (X!=0 X>=0 )                                                      [    0xfffeedd8a820] bci=[33,15,2288] rc=1 vc=1707 vn=- li=- udi=- nc=0 flg=0x104
1923753 n35828n   BBEnd </block_1701> (cold)                                                          [    0xfffeedd8aeb0] bci=[32,2,1319] rc=0 vc=3 vn=- li=- udi=- nc=0
1923754 n35825n   BBStart <block_1706> (freq 509) (extension of previous block) (cold)                [    0xfffeedd8adc0] bci=[32,2,1319] rc=0 vc=3 vn=- li=- udi=- nc=0
1923755 n35813n   treetop                                                                             [    0xfffeedd8aa00] bci=[33,15,2288] rc=0 vc=1706 vn=- li=- udi=419 nc=1
1923756 n35812n     iushr (X>=0 cannotOverflow )                                                      [    0xfffeedd8a9b0] bci=[33,15,2288] rc=1 vc=1706 vn=- li=- udi=- nc=2 flg=0x1100
1923757 n35810n       arraylength (stride 1) (X>=0 cannotOverflow )                                   [    0xfffeedd8a910] bci=[33,10,2288] rc=1 vc=1706 vn=- li=- udi=- nc=1 flg=0x1100
1923758 n35809n         aload  <temp slot 68>[#3577  Auto] [flags 0x7 0x0 ] (X!=0 )                   [    0xfffeedd8a8c0] bci=[33,7,2288] rc=1 vc=1706 vn=- li=- udi=614 nc=0 flg=0x4
...
1923782 n45897n   BBStart <block_2099> (freq 509) (extension of previous block) (cold)                [    0xfffeea52fa00] bci=[31,9,2730] rc=0 vc=3 vn=- li=- udi=- nc=0
1923783 n35794n   astore  <temp slot 68>[#3577  Auto] [flags 0x7 0x0 ] (X!=0 )                        [    0xfffeedd8a410] bci=[1923783 33,7,2288] rc=0 vc=1709 vn=- li=- udi=417 nc=1 flg=0x4
1923784 n35793n     ==>aload
1923785 n45899n   istore  <temp slot 6>[#2376  Auto] [flags 0x3 0x0 ]                                 [    0xfffeea52faa0] bci=[1923785 32,50,1322] rc=0 vc=1700 vn=- li=- udi=420 nc=1

knn-k · 2023-09-25T05:33:51Z

@hzongaro Please take a look at @Akira1Saitoh's comment above. It looks like an issue in optimization.

hzongaro · 2023-09-25T12:47:16Z

@hzongaro Please take a look at @Akira1Saitoh's comment above. It looks like an issue in optimization.

Thank you for the investigation, @Akira1Saitoh and @knn-k - I will take a look.

hzongaro · 2023-09-28T14:41:39Z

@jmesyou, may I ask you to take a look at this problem? I've been trying to reproduce the failure in Grinder runs with extra tracing of General Store Sinking in the jitdump, using the following EXTRA_OPTION, but haven't succeeded.

"-Xdump:jit:events=throw+systhrow,filter=java/lang/NullPointerException,request=serial,opts=traceGeneralStoreSinking"

However, there's an internal grinder run that's currently in progress that has shown at least one NullPointerException in String.charAt. We'll see whether it has a useful jitdump.

hzongaro · 2023-09-28T17:23:01Z

FYI - on any future Grinder reruns, you might want to used the range suboption to reduce the number of jitdumps produced:

-Xdump:jit:events=throw+systhrow,filter=java/lang/NullPointerException,range=1..3,request=serial,opts=traceGeneralStoreSinking

hzongaro · 2023-10-02T00:45:51Z

It seems that I was mistaken about the usage of the opts suboption of -Xdump for jitdumps. An example from a jitdump-related issue #9479 hinted that compiler trace options would be permitted as values for the opts suboption:

-Xdump:jit:
    events=gpf+abort,
    label=/home/user/jitdump.%Y%m%d.%H%M%S.%pid.%seq.dmp,
    range=1..0,
    priority=200,
    request=serial,
    opts=traceOSR+traceLiveness+traceAliases

However, when support for the opts suboption was actually added for jitdumps in pull request #11989, it was used to specify the name of a method that should be queued for recompilation with tracing.

-Xdump:jit:
    events=throw,
    filter=*NullPointerException#java/util/Calendar.setTime,
    range=1..1,
    opts=java/lang/String.indexOf(II)I

Thus, my use of opts=traceGeneralStoreSinking did not have the desired effect of tracing store sinking in the jitdump recompilation. :-(

pshipton · 2023-10-12T12:50:06Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OMR_testList_2/33/
java/util/stream/boottest/java.base/java/util/stream/SpinedBufferTest.java

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_OMR_testList_1/34/
java/util/Map/InPlaceOpsCollisions.java

hzongaro · 2023-10-30T16:41:18Z

Moving to the backlog for now, as it's a rather intermittent failure. @jmesyou will continue investigating.

pshipton · 2023-11-23T12:45:35Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_Release_testList_1/17/

pshipton · 2024-01-04T18:50:05Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_mac_OMR_testList_0/37

cjjdespres · 2024-06-10T17:51:29Z

Something similar to this (failures in InPlaceOpsCollisions and SpinedBufferTest) seems to have started happening in the JITServer nightly tests as well, e.g. in https://hyc-runtimes-jenkins.swg-devops.com/job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_jit_Personal_testList_1/335/

[2024-06-10T08:43:40.914Z] test InPlaceOpsCollisions.testReplaceOldValue("WeakHashMap with colliding objects", MapWithCollisionsProviders$$Lambda$41/0x0000000000000000@e428cf26, 2500): failure
[2024-06-10T08:43:40.914Z] java.lang.NullPointerException
[2024-06-10T08:43:40.914Z] 	at java.base/java.util.Formatter$FormatSpecifier.precision(Formatter.java:2829)
[2024-06-10T08:43:40.914Z] 	at java.base/java.util.Formatter$FormatSpecifier.<init>(Formatter.java:2856)
[2024-06-10T08:43:40.914Z] 	at java.base/java.util.Formatter.parse(Formatter.java:2713)
[2024-06-10T08:43:40.915Z] 	at java.base/java.util.Formatter.format(Formatter.java:2655)
[2024-06-10T08:43:40.915Z] 	at java.base/java.util.Formatter.format(Formatter.java:2609)
[2024-06-10T08:43:40.915Z] 	at java.base/java.lang.String.format(String.java:3741)
[2024-06-10T08:43:40.915Z] 	at InPlaceOpsCollisions.testReplaceOldValue(InPlaceOpsCollisions.java:122)

[2024-06-10T08:45:47.045Z] java.lang.NullPointerException
[2024-06-10T08:45:47.045Z] 	at java.base/java.util.Formatter$FormatSpecifier.precision(Formatter.java:2829)
[2024-06-10T08:45:47.045Z] 	at java.base/java.util.Formatter$FormatSpecifier.<init>(Formatter.java:2856)
[2024-06-10T08:45:47.045Z] 	at java.base/java.util.Formatter.parse(Formatter.java:2713)
[2024-06-10T08:45:47.045Z] 	at java.base/java.util.Formatter.format(Formatter.java:2655)
[2024-06-10T08:45:47.045Z] 	at java.base/java.util.Formatter.format(Formatter.java:2609)
[2024-06-10T08:45:47.045Z] 	at java.base/java.lang.String.format(String.java:3741)
[2024-06-10T08:45:47.045Z] 	at java.base/java.util.SpliteratorTestHelper.testSplitUntilNull(SpliteratorTestHelper.java:578)

though it's a different platform.

hzongaro · 2024-06-25T13:48:19Z

The IL that results after General Store Sinking that @Akira1Saitoh described above looks very similar to the IL in #17515 (comment). These are likely duplicates of one another.

hzongaro · 2024-12-10T02:10:12Z

As I mentioned in #17515 (comment), the fix needs some further work. I'll have to move this out to 0.51.

hzongaro · 2024-12-10T02:11:01Z

As I mentioned in #17515 (comment), the fix needs some further work. I'll have to move this out to 0.51.

Oops! Missed that this was already assigned to "Future."

hzongaro · 2025-01-22T19:41:16Z

It seems we haven't seen a recurrence of this problem on aarch64 in quite a while. I was unable to reproduce it with recent builds. The only problem that had been identified appeared to be the same problem reported in issue #17515, which has been fixed by OMR pull request eclipse-omr/omr#7573, so I will close this issue.

pshipton added the test failure label Aug 9, 2023

pshipton mentioned this issue Aug 9, 2023

NullPointerExceptions seen in SpinedBufferTest #17774

Closed

pshipton added this to the Release 0.41 (Java 8, 11, 17) Oct refresh milestone Aug 16, 2023

pshipton added the blocker label Aug 16, 2023

pshipton added the comp:jit label Aug 18, 2023

pshipton removed the blocker label Aug 19, 2023

hzongaro modified the milestones: Release 0.41 (Java 8, 11, 17) Oct refresh, Release 0.43 (Java 8, 11, 17, 21) Jan refresh Aug 22, 2023

hzongaro assigned jmesyou Oct 12, 2023

hzongaro modified the milestones: Release 0.43 (Java 8, 11, 17, 21) Jan refresh, Backlog Oct 30, 2023

hzongaro added the prio:high label Oct 30, 2023

hzongaro modified the milestones: Backlog, Future Apr 18, 2024

hzongaro unassigned jmesyou Jun 25, 2024

hzongaro closed this as completed Jan 22, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OpenJDK java/util/Map/InPlaceOpsCollisions NullPointerException String.charAt #17922

OpenJDK java/util/Map/InPlaceOpsCollisions NullPointerException String.charAt #17922

pshipton commented Aug 9, 2023

pshipton commented Aug 9, 2023

knn-k commented Aug 16, 2023

pshipton commented Aug 16, 2023

knn-k commented Aug 18, 2023

knn-k commented Aug 18, 2023

knn-k commented Aug 20, 2023

hzongaro commented Aug 22, 2023

pshipton commented Sep 7, 2023 •

edited

Loading

knn-k commented Sep 8, 2023

knn-k commented Sep 10, 2023

Akira1Saitoh commented Sep 22, 2023

Akira1Saitoh commented Sep 25, 2023

knn-k commented Sep 25, 2023

hzongaro commented Sep 25, 2023

hzongaro commented Sep 28, 2023

hzongaro commented Sep 28, 2023

hzongaro commented Oct 2, 2023

pshipton commented Oct 12, 2023 •

edited

Loading

hzongaro commented Oct 30, 2023

pshipton commented Nov 23, 2023

pshipton commented Jan 4, 2024

cjjdespres commented Jun 10, 2024

hzongaro commented Jun 25, 2024

hzongaro commented Dec 10, 2024

hzongaro commented Dec 10, 2024

hzongaro commented Jan 22, 2025

OpenJDK java/util/Map/InPlaceOpsCollisions NullPointerException String.charAt #17922

OpenJDK java/util/Map/InPlaceOpsCollisions NullPointerException String.charAt #17922

Comments

pshipton commented Aug 9, 2023

pshipton commented Aug 9, 2023

knn-k commented Aug 16, 2023

pshipton commented Aug 16, 2023

knn-k commented Aug 18, 2023

knn-k commented Aug 18, 2023

knn-k commented Aug 20, 2023

hzongaro commented Aug 22, 2023

pshipton commented Sep 7, 2023 • edited Loading

knn-k commented Sep 8, 2023

knn-k commented Sep 10, 2023

Akira1Saitoh commented Sep 22, 2023

Akira1Saitoh commented Sep 25, 2023

knn-k commented Sep 25, 2023

hzongaro commented Sep 25, 2023

hzongaro commented Sep 28, 2023

hzongaro commented Sep 28, 2023

hzongaro commented Oct 2, 2023

pshipton commented Oct 12, 2023 • edited Loading

hzongaro commented Oct 30, 2023

pshipton commented Nov 23, 2023

pshipton commented Jan 4, 2024

cjjdespres commented Jun 10, 2024

hzongaro commented Jun 25, 2024

hzongaro commented Dec 10, 2024

hzongaro commented Dec 10, 2024

hzongaro commented Jan 22, 2025

pshipton commented Sep 7, 2023 •

edited

Loading

pshipton commented Oct 12, 2023 •

edited

Loading