JDK21 java/lang/Thread/virtual/stress/Skynet.java#default j9scar.209 ASSERTION FAILED openj9/runtime/j9vm/javanextvmi.cpp:560

JasonFengJ9 commented 11 months ago

Failure link

From an internal build(ubu22s390x-rt-1):

java version "21.0.1-beta" 2023-10-17
IBM Semeru Runtime Certified Edition 21.0.1+12-202310241436 (build 21.0.1-beta+12-202310241436)
Eclipse OpenJ9 VM 21.0.1+12-202310241436 (build master-900abdd2b, JRE 21 Linux s390x-64-Bit Compressed References 20231024_19 (JIT enabled, AOT enabled)
OpenJ9   - 900abdd2b
OMR      - 501add5e5
JCL      - badb8d95a based on jdk-21.0.1+12)

Rerun in Grinder - Change TARGET to run only the failed test targets.

Optional info

Failure output (captured from console output)

[2023-10-24T15:57:17.358Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode650
[2023-10-24T15:57:17.358Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops 

[2023-10-24T16:27:43.273Z] TEST: java/lang/Thread/virtual/stress/Skynet.java#default

[2023-10-24T16:27:43.274Z] STDERR:
[2023-10-24T16:27:43.274Z] 16:27:11.819 0x3fecc003600  j9scar.209    *   ** ASSERTION FAILED ** at /home/jenkins/workspace/build-scripts/jobs/jdk21u/jdk21u-linux-s390x-openj9-IBM/workspace/build/src/openj9/runtime/j9vm/javanextvmi.cpp:560: ((isSameOrSuperClassOf((((J9RAMClassRef*)(&((currentThread)->javaVM)->jclConstantPool[(30)]))->value), ((0 != (currentThread)->compressObjectReferences) ? (struct J9Class*)((UDATA)(((void)0, *(U_32*)((U_8*)(currentThread->threadObject) + ((__builtin_offsetof (J9Object, clazz)))))) & ~((UDATA)(0x100 - 1))) : (struct J9Class*)((UDATA)(((void)0, *(UDATA*)((U_8*)(currentThread->threadObject) + ((__builtin_offsetof (J9Object, clazz)))))) & ~((UDATA)(0x100 - 1)))))))
[2023-10-24T16:27:43.274Z] JVMDUMP039I Processing dump event "traceassert", detail "" at 2023/10/24 17:27:11 - please wait.

[2023-10-24T16:27:43.275Z] TEST RESULT: Failed. Unexpected exit from test [exit code: 255]
[2023-10-24T16:27:43.275Z] --------------------------------------------------
[2023-10-24T16:35:34.979Z] Test results: passed: 929; failed: 1
[2023-10-24T16:35:58.970Z] Report written to /home/jenkins/workspace/Test_openjdk21_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16981630354831/jdk_lang_1/report/html/report.html
[2023-10-24T16:35:58.970Z] Results written to /home/jenkins/workspace/Test_openjdk21_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16981630354831/jdk_lang_1/work
[2023-10-24T16:35:58.970Z] Error: Some tests failed or other problems occurred.
[2023-10-24T16:35:59.762Z] -----------------------------------
[2023-10-24T16:35:59.762Z] jdk_lang_1_FAILED

50x internal grinder

babsingh commented 11 months ago

Core files: https://na.artifactory.swg-devops.com/artifactory/sys-rt-generic-local/hyc-runtimes-jenkins.swg-devops.com/Test_openjdk21_j9_sanity.openjdk_s390x_linux_testList_1/42/openjdk_test_output.tar.gz

babsingh commented 11 months ago

Issue 1: !vthreads cmd doesn't work in DDR due to a BAD threadObject.

Caused by: com.ibm.j9ddr.NullPointerDereference: Memory Fault reading 0x00000000 :
    at com.ibm.j9ddr.vm29.pointer.AbstractPointer.getLongAtOffset(AbstractPointer.java:456)
    at com.ibm.j9ddr.vm29.pointer.generated.J9ObjectFullPointer.clazz(Unknown Source)
    at com.ibm.j9ddr.vm29.pointer.helper.J9ObjectHelper.rawClazz(J9ObjectHelper.java:118)
    at com.ibm.j9ddr.vm29.pointer.helper.J9ObjectHelper.clazz(J9ObjectHelper.java:132)
    at com.ibm.j9ddr.vm29.pointer.helper.J9ObjectHelper.getFieldOffset(J9ObjectHelper.java:409)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.VirtualThreadsCommand.getName(VirtualThreadsCommand.java:74)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.VirtualThreadsCommand.displayVirtualThreads(VirtualThreadsCommand.java:115)
    at com.ibm.j9ddr.vm29.tools.ddrinteractive.VirtualThreadsCommand.run(VirtualThreadsCommand.java:88)

babsingh commented 11 months ago

Issue 2: J9VMThread->threadObject has a BAD value.

> !j9vmthread 0x3fecc003600
    0xa8: struct J9Object* threadObject = !j9object 0x000003FF86769338 // <FAULT>
    0xb98: struct J9Object* carrierThreadObject = !j9object 0x000003FF55AC5060 // jdk/internal/misc/CarrierThread
    0xb78: struct J9VMContinuation* currentContinuation = !j9vmcontinuation 0x000003FEB005FA00

> !j9object 0x000003FF86769338
Unable to read object clazz at 0x000003FF86769338 (clazz = 0x000003FF56E6EC00)

> !stack 0x3fecc003600
<3fecc003600>   !j9method 0x000003FF982CA2A0   java/lang/VirtualThread.notifyJvmtiHideFrames(Z)V
<3fecc003600>   !j9method 0x000003FF982C9D60   java/lang/VirtualThread.switchToCarrierThread()V
<3fecc003600>   !j9method 0x000003FF982C9F40   java/lang/VirtualThread.unpark()V
<3fecc003600>   !j9method 0x000003FF982EEDD8   java/lang/Access.unparkVirtualThread(Ljava/lang/Thread;)V
<3fecc003600>   !j9method 0x000003FED4054F98   jdk/internal/misc/VirtualThreads.unpark(Ljava/lang/Thread;)V
<3fecc003600>   !j9method 0x000003FF982C1A28   java/util/concurrent/locks/LockSupport.unpark(Ljava/lang/Thread;)V
<3fecc003600>   !j9method 0x000003FF98543E40   java/util/concurrent/SynchronousQueue$TransferStack$SNode.tryMatch(Ljava/util/concurrent/SynchronousQueue$TransferStack$SNode;)Z
<3fecc003600>   !j9method 0x000003FF98543760   java/util/concurrent/SynchronousQueue$TransferStack.transfer(Ljava/lang/Object;ZJ)Ljava/lang/Object;
<3fecc003600>   !j9method 0x000003FF98542770   java/util/concurrent/SynchronousQueue.take()Ljava/lang/Object;
<3fecc003600>   !j9method 0x000003FF985302F8   Skynet$Channel.receive()Ljava/lang/Object;
<3fecc003600>   !j9method 0x000003FF9852FF20   Skynet.skynet(LSkynet$Channel;III)V
<3fecc003600>   !j9method 0x000003FF9852FF40   Skynet.lambda$skynet$1(LSkynet$Channel;III)V
<3fecc003600>   !j9method 0x000003FF985308E8   Skynet$$Lambda/0x000000009c662918.run()V
<3fecc003600>   !j9method 0x000003FF982ABEA0   java/lang/Thread.runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V
<3fecc003600>   !j9method 0x000003FF982C9D00   java/lang/VirtualThread.run(Ljava/lang/Runnable;)V
<3fecc003600>   !j9method 0x000003FED404B670   java/lang/VirtualThread$VThreadContinuation$1.run()V
<3fecc003600>   !j9method 0x000003FF982D9260   jdk/internal/vm/Continuation.enter(Ljdk/internal/vm/Continuation;)V

> !continuationstack 0x000003FEB005FA00
<3feb005fa00>   !j9method 0x000003FF982D9400   jdk/internal/vm/Continuation.enterImpl()Z
<3feb005fa00>   !j9method 0x000003FF982D9280   jdk/internal/vm/Continuation.run()V
<3feb005fa00>   !j9method 0x000003FF982C9C60   java/lang/VirtualThread.runContinuation()V
<3feb005fa00>   !j9method 0x000003FED404C288   java/lang/VirtualThread$$Lambda/0x0000000097f9eb58.run()V
<3feb005fa00>   !j9method 0x000003FED40548A8   java/util/concurrent/ForkJoinTask$AdaptedRunnableAction.exec()Z
<3feb005fa00>   !j9method 0x000003FED404D008   java/util/concurrent/ForkJoinTask.doExec()I
<3feb005fa00>   !j9method 0x000003FED4037740   java/util/concurrent/ForkJoinPool$WorkQueue.topLevelExec(Ljava/util/concurrent/ForkJoinTask;Ljava/util/concurrent/ForkJoinPool$WorkQueue;)V
<3feb005fa00>   !j9method 0x000003FED4035628   java/util/concurrent/ForkJoinPool.scan(Ljava/util/concurrent/ForkJoinPool$WorkQueue;II)I
<3feb005fa00>   !j9method 0x000003FED4035608   java/util/concurrent/ForkJoinPool.runWorker(Ljava/util/concurrent/ForkJoinPool$WorkQueue;)V
<3feb005fa00>   !j9method 0x000003FF984DE170   java/util/concurrent/ForkJoinWorkerThread.run()V
<3feb005fa00>                           JNI call-in frame
<3feb005fa00>                           Native method frame

babsingh commented 11 months ago

Issue 2 ... stackslots shows extensive JIT inlining ... the BAD threadObject is propagated from the JIT frames.

> !stackslots 0x3fecc003600
<3fecc003600> *** BEGIN STACK WALK, flags = 00400001 walkThread = 4,392,879,142,400 ***
<3fecc003600>   ITERATE_O_SLOTS
<3fecc003600>   RECORD_BYTECODE_PC_OFFSET
<3fecc003600> Initial values: walkSP = 0x000003FEB0060FC8, PC = 0x0000000000000006, literals = 0x0000000000000000, A0 = 0x000003FEB0060FF0, j2iFrame = 0x0000000000000000, decomp = 0x0000000000000000
<3fecc003600> JIT JNI call-out frame: bp = 0x000003FEB0060FE8, sp = 0x000003FEB0060FC8, pc = 0x0000000000000006, cp = 0x000003FF982C8AE0, arg0EA = 0x000003FEB0060FF0, flags = 0x0000000020000000
<3fecc003600>   Method: java/lang/VirtualThread.notifyJvmtiHideFrames(Z)V !j9method 0x000003FF982CA2A0
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061110, pc = 0x000003FF3B13A0BC, unwindSP = 0x000003FEB0060FF0, cp = 0x000003FF982C8AE0, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A7DAB8
<3fecc003600>   Method: java/lang/VirtualThread.switchToCarrierThread()V !j9method 0x000003FF982C9D60
<3fecc003600>   Bytecode index = 2, inlineDepth = 6, PC offset = 0x00000000001712C2
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061110, pc = 0x000003FF3B13A0BC, unwindSP = 0x000003FEB0060FF0, cp = 0x000003FF982C8AE0, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A7DAB8
<3fecc003600>   Method: java/lang/VirtualThread.unpark()V !j9method 0x000003FF982C9F40
<3fecc003600>   Bytecode index = 49, inlineDepth = 5, PC offset = 0x00000000000381C2
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061110, pc = 0x000003FF3B13A0BC, unwindSP = 0x000003FEB0060FF0, cp = 0x000003FF982F1880, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A7DAB8
<3fecc003600>   Method: java/lang/Access.unparkVirtualThread(Ljava/lang/Thread;)V !j9method 0x000003FF982EEDD8
<3fecc003600>   Bytecode index = 13, inlineDepth = 4, PC offset = 0x00000000000083C8
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061110, pc = 0x000003FF3B13A0BC, unwindSP = 0x000003FEB0060FF0, cp = 0x000003FED4054DC0, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A7DAB8
<3fecc003600>   Method: jdk/internal/misc/VirtualThreads.unpark(Ljava/lang/Thread;)V !j9method 0x000003FED4054F98
<3fecc003600>   Bytecode index = 6, inlineDepth = 3, PC offset = 0x00000000001721C2
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061110, pc = 0x000003FF3B13A0BC, unwindSP = 0x000003FEB0060FF0, cp = 0x000003FF982C1B70, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A7DAB8
<3fecc003600>   Method: java/util/concurrent/locks/LockSupport.unpark(Ljava/lang/Thread;)V !j9method 0x000003FF982C1A28
<3fecc003600>   Bytecode index = 12, inlineDepth = 2, PC offset = 0x00000000000086C2
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061110, pc = 0x000003FF3B13A0BC, unwindSP = 0x000003FEB0060FF0, cp = 0x000003FF98543BF0, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A7DAB8
<3fecc003600>   Method: java/util/concurrent/SynchronousQueue$TransferStack$SNode.tryMatch(Ljava/util/concurrent/SynchronousQueue$TransferStack$SNode;)Z !j9method 0x000003FF98543E40
<3fecc003600>   Bytecode index = 31, inlineDepth = 1, PC offset = 0x0000000000007CC8
<3fecc003600> JIT frame: bp = 0x000003FEB0061110, pc = 0x000003FF3B13A0BC, unwindSP = 0x000003FEB0060FF0, cp = 0x000003FF985431C0, arg0EA = 0x000003FEB0061138, jitInfo = 0x000003FF38A7DAB8
<3fecc003600>   Method: java/util/concurrent/SynchronousQueue$TransferStack.transfer(Ljava/lang/Object;ZJ)Ljava/lang/Object; !j9method 0x000003FF98543760
<3fecc003600>   Bytecode index = 31, inlineDepth = 0, PC offset = 0x00000000000068CC
<3fecc003600>   stackMap=0x000003FF38A80615, slots=I16(0x0005) parmBaseOffset=I16(0x0020), parmSlots=U16(0x0002), localBaseOffset=I16(0xFF88)
<3fecc003600>   Described JIT args starting at 0x000003FEB0061130 for U16(0x0002) slots
<3fecc003600>       O-Slot: : a1[0x000003FEB0061130] = 0x0000000000000000
<3fecc003600>       O-Slot: : a0[0x000003FEB0061138] = 0x000003FF86402B78
<3fecc003600>   Described JIT temps starting at 0x000003FEB0061098 for IDATA(0x000000000000000F) slots
<3fecc003600>       O-Slot: : t14[0x000003FEB0061098] = 0x000003FF86769338 <-- BAD threadObject
<3fecc003600>       O-Slot: : t13[0x000003FEB00610A0] = 0x000003FF86769338 <-- BAD threadObject
<3fecc003600>       I-Slot: : t12[0x000003FEB00610A8] = 0x000003FF57138918
<3fecc003600>       O-Slot: : t11[0x000003FEB00610B0] = 0x000003FF8D9A0100
<3fecc003600>       I-Slot: : t10[0x000003FEB00610B8] = 0x000003FF917737A8
<3fecc003600>       I-Slot: : t9[0x000003FEB00610C0] = 0x000003FF98530700
<3fecc003600>       I-Slot: : t8[0x000003FEB00610C8] = 0x000003FF00000009
<3fecc003600>       O-Slot: : t7[0x000003FEB00610D0] = 0x000003FF86403388
<3fecc003600>       I-Slot: : t6[0x000003FEB00610D8] = 0x000003FF8C62EBA8
<3fecc003600>       O-Slot: : t5[0x000003FEB00610E0] = 0x000003FF86403388
<3fecc003600>       O-Slot: : t4[0x000003FEB00610E8] = 0x000003FF8D9A0138
<3fecc003600>       O-Slot: : t3[0x000003FEB00610F0] = 0x000003FF86769338  <-- BAD threadObject
<3fecc003600>       I-Slot: : t2[0x000003FEB00610F8] = 0x000003FF8D714B28
<3fecc003600>       O-Slot: : t1[0x000003FEB0061100] = 0x000003FF8D9A0170
<3fecc003600>       O-Slot: : t0[0x000003FEB0061108] = 0x000003FF86403388
<3fecc003600>   JIT-RegisterMap = UDATA(0x0000000000000000)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061020] = UDATA(0x000003FF86402B30) (jit_r6)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061028] = UDATA(0x000003FF98543500) (jit_r7)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061030] = UDATA(0x0000000000000000) (jit_r8)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061038] = UDATA(0x000003FF98542400) (jit_r9)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061040] = UDATA(0x000003FF0000000A) (jit_r10)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061048] = UDATA(0x000003FF86402B30) (jit_r11)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061050] = UDATA(0x000003FF0000000A) (jit_r12)
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061170, pc = 0x000003FF3B13037C, unwindSP = 0x000003FEB0061118, cp = 0x000003FF98542A50, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A7B3F8
<3fecc003600>   Method: java/util/concurrent/SynchronousQueue.take()Ljava/lang/Object; !j9method 0x000003FF98542770
<3fecc003600>   Bytecode index = 7, inlineDepth = 1, PC offset = 0x000000000001D082
<3fecc003600> JIT frame: bp = 0x000003FEB0061170, pc = 0x000003FF3B13037C, unwindSP = 0x000003FEB0061118, cp = 0x000003FF985301D0, arg0EA = 0x000003FEB0061178, jitInfo = 0x000003FF38A7B3F8
<3fecc003600>   Method: Skynet$Channel.receive()Ljava/lang/Object; !j9method 0x000003FF985302F8
<3fecc003600>   Bytecode index = 8, inlineDepth = 0, PC offset = 0x0000000000000082
<3fecc003600>   stackMap=0x000003FF38A7B538, slots=I16(0x0001) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0001), localBaseOffset=I16(0x0000)
<3fecc003600>   Described JIT args starting at 0x000003FEB0061178 for U16(0x0001) slots
<3fecc003600>       O-Slot: : a0[0x000003FEB0061178] = 0x000003FF86402B30
<3fecc003600>   Described JIT temps starting at 0x000003FEB0061170 for IDATA(0x0000000000000000) slots
<3fecc003600>   JIT-RegisterMap = UDATA(0x0000000000000000)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061140] = UDATA(0x000003FF8C62EB90) (jit_r6)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061148] = UDATA(0x000003FF00000005) (jit_r7)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061150] = UDATA(0x0000000000159A32) (jit_r8)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061158] = UDATA(0x000003FF982CF000) (jit_r9)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061040] = UDATA(0x000003FF0000000A) (jit_r10)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061048] = UDATA(0x000003FF86402B30) (jit_r11)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061050] = UDATA(0x000003FF0000000A) (jit_r12)
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061228, pc = 0x000003FF3B112074, unwindSP = 0x000003FEB0061178, cp = 0x000003FF9852FA10, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A77E78
<3fecc003600>   Method: Skynet.skynet(LSkynet$Channel;III)V !j9method 0x000003FF9852FF20
<3fecc003600>   Bytecode index = 82, inlineDepth = 3, PC offset = 0x0000000000165582
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061228, pc = 0x000003FF3B112074, unwindSP = 0x000003FEB0061178, cp = 0x000003FF9852FA10, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A77E78
<3fecc003600>   Method: Skynet.lambda$skynet$1(LSkynet$Channel;III)V !j9method 0x000003FF9852FF40
<3fecc003600>   Bytecode index = 6, inlineDepth = 2, PC offset = 0x000003FF3B111467
<3fecc003600> JIT inline frame: bp = 0x000003FEB0061228, pc = 0x000003FF3B112074, unwindSP = 0x000003FEB0061178, cp = 0x000003FF985305F0, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A77E78
<3fecc003600>   Method: Skynet$$Lambda/0x000000009c662918.run()V !j9method 0x000003FF985308E8
<3fecc003600>   Bytecode index = 16, inlineDepth = 1, PC offset = 0x000003FF3B111467
<3fecc003600> JIT frame: bp = 0x000003FEB0061228, pc = 0x000003FF3B112074, unwindSP = 0x000003FEB0061178, cp = 0x000003FF982AA690, arg0EA = 0x000003FEB0061240, jitInfo = 0x000003FF38A77E78
<3fecc003600>   Method: java/lang/Thread.runWith(Ljava/lang/Object;Ljava/lang/Runnable;)V !j9method 0x000003FF982ABEA0
<3fecc003600>   Bytecode index = 16, inlineDepth = 0, PC offset = 0x0000000000000286
<3fecc003600>   stackMap=0x000003FF38A78056, slots=I16(0x0003) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0003), localBaseOffset=I16(0xFFD8)
<3fecc003600>   Described JIT args starting at 0x000003FEB0061230 for U16(0x0003) slots
<3fecc003600>       O-Slot: : a2[0x000003FEB0061230] = 0x000003FF86769490
<3fecc003600>       O-Slot: : a1[0x000003FEB0061238] = 0x000003FF559847E8
<3fecc003600>       O-Slot: : a0[0x000003FEB0061240] = 0x000003FF86769338  <-- BAD threadObject
<3fecc003600>   Described JIT temps starting at 0x000003FEB0061200 for IDATA(0x0000000000000005) slots
<3fecc003600>       I-Slot: : t4[0x000003FEB0061200] = 0x000003FF55AC4ED0
<3fecc003600>       I-Slot: : t3[0x000003FEB0061208] = 0x000003FF982CA220
<3fecc003600>       I-Slot: : t2[0x000003FEB0061210] = 0x0000000020000000
<3fecc003600>       O-Slot: : t1[0x000003FEB0061218] = 0x000003FF864009D0
<3fecc003600>       I-Slot: : t0[0x000003FEB0061220] = 0x000003FF8DC397B0
<3fecc003600>   JIT-RegisterMap = UDATA(0x0000000000000800)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061140] = UDATA(0x000003FF8C62EB90) (jit_r6)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061148] = UDATA(0x000003FF00000005) (jit_r7)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061150] = UDATA(0x0000000000159A32) (jit_r8)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061158] = UDATA(0x000003FF982CF000) (jit_r9)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061040] = UDATA(0x000003FF0000000A) (jit_r10)
<3fecc003600>       JIT-RegisterMap-O-Slot[0x000003FEB0061048] = 0x000003FF86402B30 (jit_r11)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061050] = UDATA(0x000003FF0000000A) (jit_r12)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061190] = UDATA(0x000003FF559847E8) (jit_r6)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061198] = UDATA(0x000003FF00000000) (jit_r7)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB00611A0] = UDATA(0x000003FF86769338) (jit_r8)  <-- BAD threadObject
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB00611A8] = UDATA(0x000003FF86769490) (jit_r9)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB00611B0] = UDATA(0x000003FF867694B8) (jit_r10)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB00611B8] = UDATA(0x0000000000000000) (jit_r11)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB00611C0] = UDATA(0x000003FF3B12F968) (jit_r12)
<3fecc003600> JIT inline frame: bp = 0x000003FEB00612E8, pc = 0x000003FF3B12E1F4, unwindSP = 0x000003FEB0061230, cp = 0x000003FF982C8AE0, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A79638
<3fecc003600>   Method: java/lang/VirtualThread.run(Ljava/lang/Runnable;)V !j9method 0x000003FF982C9D00
<3fecc003600>   Bytecode index = 63, inlineDepth = 2, PC offset = 0x0000000000025C00
<3fecc003600> JIT inline frame: bp = 0x000003FEB00612E8, pc = 0x000003FF3B12E1F4, unwindSP = 0x000003FEB0061230, cp = 0x000003FED404C1C0, arg0EA = 0x0000000000000000, jitInfo = 0x000003FF38A79638
<3fecc003600>   Method: java/lang/VirtualThread$VThreadContinuation$1.run()V !j9method 0x000003FED404B670
<3fecc003600>   Bytecode index = 8, inlineDepth = 1, PC offset = 0x000000000017C3FA
<3fecc003600> JIT frame: bp = 0x000003FEB00612E8, pc = 0x000003FF3B12E1F4, unwindSP = 0x000003FEB0061230, cp = 0x000003FF982D8B30, arg0EA = 0x000003FEB00612F0, jitInfo = 0x000003FF38A79638
<3fecc003600>   Method: jdk/internal/vm/Continuation.enter(Ljdk/internal/vm/Continuation;)V !j9method 0x000003FF982D9260
<3fecc003600>   Bytecode index = 8, inlineDepth = 0, PC offset = 0x00000000000003FA
<3fecc003600>   stackMap=0x000003FF38A79D46, slots=I16(0x0001) parmBaseOffset=I16(0x0008), parmSlots=U16(0x0001), localBaseOffset=I16(0xFFB0)
<3fecc003600>   Described JIT args starting at 0x000003FEB00612F0 for U16(0x0001) slots
<3fecc003600>       O-Slot: : a0[0x000003FEB00612F0] = 0x000003FF86769438
<3fecc003600>   Described JIT temps starting at 0x000003FEB0061298 for IDATA(0x000000000000000A) slots
<3fecc003600>       I-Slot: : t9[0x000003FEB0061298] = 0x000003FF64825D78
<3fecc003600>       I-Slot: : t8[0x000003FEB00612A0] = 0x000003FF64825D78
<3fecc003600>       I-Slot: : t7[0x000003FEB00612A8] = 0x0000000000000000
<3fecc003600>       I-Slot: : t6[0x000003FEB00612B0] = 0x000003FF3B108ABC
<3fecc003600>       O-Slot: : t5[0x000003FEB00612B8] = 0x000003FF86769338  <-- BAD threadObject
<3fecc003600>       I-Slot: : t4[0x000003FEB00612C0] = 0x000003FF8DC39930
<3fecc003600>       I-Slot: : t3[0x000003FEB00612C8] = 0x000003FF8DC39930
<3fecc003600>       I-Slot: : t2[0x000003FEB00612D0] = 0x000003FF8DC397B0
<3fecc003600>       I-Slot: : t1[0x000003FEB00612D8] = 0x000003FF8DC397B0
<3fecc003600>       I-Slot: : t0[0x000003FEB00612E0] = 0x000003FF8DC397D8
<3fecc003600>   JIT-RegisterMap = UDATA(0x0000000000000700)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061190] = UDATA(0x000003FF559847E8) (jit_r6)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB0061198] = UDATA(0x000003FF00000000) (jit_r7)
<3fecc003600>       JIT-RegisterMap-O-Slot[0x000003FEB00611A0] = 0x000003FF86769338 (jit_r8) <-- BAD threadObject
<3fecc003600>       JIT-RegisterMap-O-Slot[0x000003FEB00611A8] = 0x000003FF86769490 (jit_r9)
<3fecc003600>       JIT-RegisterMap-O-Slot[0x000003FEB00611B0] = 0x000003FF867694B8 (jit_r10)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB00611B8] = UDATA(0x0000000000000000) (jit_r11)
<3fecc003600>       JIT-RegisterMap-I-Slot[0x000003FEB00611C0] = UDATA(0x000003FF3B12F968) (jit_r12)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061248] = UDATA(0x0000000000000000) (jit_r6)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061250] = UDATA(0x000003FF982F2600) (jit_r7)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061258] = UDATA(0x000003FF55AC4ED0) (jit_r8)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061260] = UDATA(0x000003FF8DC398D8) (jit_r9)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061268] = UDATA(0x000003FF8DC397D8) (jit_r10)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061270] = UDATA(0x0000000000000000) (jit_r11)
<3fecc003600>   JIT-Frame-RegisterMap[0x000003FEB0061278] = UDATA(0x000003FF3B10CDF8) (jit_r12)
<3fecc003600> I2J values: PC = 0x000003FF97F33E8E, A0 = 0x000003FEB0061320, walkSP = 0x000003FEB0061300, literals = 0x0000000000000000, JIT PC = 0x000003FF96C06C60, pcAddress = 0x000003FF5476D968, decomp = 0x0000000000000000
<3fecc003600> JNI call-in frame: bp = 0x000003FEB0061320, sp = 0x000003FEB0061300, pc = 0x000003FF97F33E8E, cp = 0x0000000000000000, arg0EA = 0x000003FEB0061320, flags = 0x0000000000000000
<3fecc003600>   New ELS = 0x0000000000000000
<3fecc003600> JNI native method frame: bp = 0x000003FEB0061348, sp = 0x000003FEB0061328, pc = 0x0000000000000007, cp = 0x0000000000000000, arg0EA = 0x000003FEB0061348, flags = 0x0000000000000000
<3fecc003600> <end of stack>
<3fecc003600> *** END STACK WALK (rc = NONE) ***

babsingh commented 11 months ago

DDR !vthread cmd doesn't work due to the BAD threadObject. See https://github.com/eclipse-openj9/openj9/issues/18353#issuecomment-1782305107 for more details.
J9VMThread->threadObject is BAD:
- VM: The triggered assertion accesses currentThread->threadObject. Can a GC impact it in the absence of VM access? Do we need to wrap JVM_VirtualThreadHideFrames with internalEnterVMFromJNI and internalExitVMToJNI i.e. acquire VM access to read J9VMThread->threadObject in a stable state? See https://github.com/eclipse-openj9/openj9/issues/18353#issuecomment-1782306987 for J9VMThread and stack details.
- JIT: The BAD threadObject propagates through the JIT frames. Are we inlining and processing the ChangesCurrentThread annotation correctly? See https://github.com/eclipse-openj9/openj9/issues/18353#issuecomment-1782311399 for stackslots.

++ @nbhuiyan @fengxue-IS

fyi @tajila @0xdaryl @pshipton

dmitripivkine commented 11 months ago

An object at 0x3FF86769338 is not "bad", it is Forwarded Pointer to !j9object 0x000003ff56e6ec40. This assertion occur mid-scavenge obviously. So, if this code is not called as a part of GC scan it should wait for GC end to be executed.

babsingh commented 11 months ago

Just had a chat with @dmitripivkine. !j9object 0x000003FF86769338 is not a bad object, just a forwarded pointer. We are accessing J9VMThread->threadObject during a scavenger scan. To avoid the collision with the GC scan, we need to acquire VM access before accessing J9VMThread->threadObject. The other option is to just remove the assertion which accesses J9VMThread->threadObject if the assertion is unneeded (not essential). This a VM issue; unrelated to the JIT.

babsingh commented 11 months ago

@fengxue-IS to open the PR to resolve this failure.

fengxue-IS commented 11 months ago

after reviewing the call chain reaching the assertion check, I suggest we just remove the virtual thread check in this native call, other than the assert itself, there is no code that uses java objects which require vmaccess. the code JVM_VirtualThreadHideFrames is private and only used within JCL, so it is safe to assume the virtual thread object have been set.

babsingh commented 11 months ago

@fengxue-IS agreed, lets remove the assert.

fengxue-IS commented 11 months ago

Opened PR to remove the assertion

eclipse-openj9 / openj9