openj9 icon indicating copy to clipboard operation
openj9 copied to clipboard

Crash vmState=0x00000000 running MissingCallerSensitive.java

Open pshipton opened this issue 4 years ago • 14 comments

https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_xl_Nightly/217 jdk/internal/reflect/CallerSensitive/MissingCallerSensitive.java ub18-ppcle-1

Diagnostics https://140-211-168-230-openstack.osuosl.org/artifactory/ci-eclipse-openj9/Test/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_xl_Nightly/217/openjdk_test_output.tar.gz

00:13:49  stderr:
00:13:49  Unhandled exception
00:13:49  Type=Segmentation error vmState=0x00000000
00:13:49  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
00:13:49  Handler1=00007AEB926F0690 Handler2=00007AEB9262C100
00:13:49  R0=00007AEB9275F548 R1=00007AEB4D93B660 R2=00007AEB92896F00 R3=0000000000000004
00:13:49  R4=00007AEB6C1B05B0 R5=00007AEB8C496A00 R6=00007AEB1D70E250 R7=0000000000000498
00:13:49  R8=0000000000000018 R9=0000000000000018 R10=0000000000000008 R11=00007AEB6C2C8800
00:13:49  R12=0000000000004400 R13=00007AEB4D9468E0 R14=00007AEAA800D080 R15=00007AEAB0006F00
00:13:49  R16=00007AEB4E170038 R17=FFFFFFFFFFFFFFFF R18=00007AEB4D93BDA8 R19=00007AEB1D70E5D6
00:13:49  R20=00007AEAA8000C50 R21=0000000000000010 R22=00007AEAA800D028 R23=00007AEB93824410
00:13:49  R24=00007AEAB0006F00 R25=00007AEB4D93F240 R26=00007AEB4D93B9A0 R27=00007AEB4D93B890
00:13:49  R28=00007AEB4D93B870 R29=00007AEB6C2B88B0 R30=0000000000000000 R31=0000000000000000
00:13:49  NIP=00007AEB927583E8 MSR=800000010280F033 ORIG_GPR3=00000000000081C8 CTR=00007AEB927635E0
00:13:49  LINK=00007AEB9275F548 XER=0000000000000000 CCR=0000000044004482 SOFTE=0000000000000001
00:13:49  TRAP=0000000000000300 DAR=0000000000000020 dsisr=0000000040000000 RESULT=0000000000000000
00:13:49  FPR0 00007aeaa800d0c8 (f: 2818625792.000000, d: 6.677211e-310)
00:13:49  FPR1 40551ab4a0000000 (f: 2684354560.000000, d: 8.441727e+01)
00:13:49  FPR2 3fe8000000000000 (f: 0.000000, d: 7.500000e-01)
00:13:49  FPR3 004100540045004d (f: 4522061.000000, d: 1.891455e-307)
00:13:49  FPR4 3fce840b4ac4e4d2 (f: 1254417664.000000, d: 2.384047e-01)
00:13:49  FPR5 bfe7154748bef6c8 (f: 1220474624.000000, d: -7.213475e-01)
00:13:49  FPR6 3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
00:13:49  FPR7 3fc526e57720db08 (f: 1998641920.000000, d: 1.652495e-01)
00:13:49  FPR8 bfdffffef20a4123 (f: 4060758272.000000, d: -4.999997e-01)
00:13:49  FPR9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR10 bfe03f2a28285f5e (f: 673734464.000000, d: -5.077105e-01)
00:13:49  FPR11 3ff0000000000000 (f: 0.000000, d: 1.000000e+00)
00:13:49  FPR12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR13 0000000000000001 (f: 1.000000, d: 4.940656e-324)
00:13:49  FPR14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR16 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR17 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR18 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR19 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR20 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR21 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR22 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR23 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  FPR31 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:13:49  Module=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_xl_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
00:13:49  Module_base_address=00007AEB926B0000
00:13:49  Target=2_90_20201130_358 (Linux 4.15.0-96-generic)
00:13:49  CPU=ppc64le (16 logical CPUs) (0x1fdc70000 RAM)
00:13:49  ----------- Stack Backtrace -----------
00:13:49  (0x00007AEB927583E8 [libj9vm29.so+0xa83e8])
00:13:49  (0x00007AEB927B6134 [libj9vm29.so+0x106134])
00:13:49  (0x00007AEB926C8284 [libj9vm29.so+0x18284])
00:13:49  (0x00007AEB92756110 [libj9vm29.so+0xa6110])
00:13:49  (0x00007AEB9262D508 [libj9prt29.so+0x3d508])
00:13:49  (0x00007AEB927517C4 [libj9vm29.so+0xa17c4])
00:13:49  (0x00007AEB925C1268 [libj9thr29.so+0x11268])
00:13:49  (0x00007AEB937E885C [libpthread.so.0+0x885c])
00:13:49  clone+0x98 (0x00007AEB93699028 [libc.so.6+0x159028])

pshipton avatar Dec 01 '20 13:12 pshipton

@tajila @gacholio fyi

pshipton avatar Dec 01 '20 14:12 pshipton

I'll take a look.

gacholio avatar Dec 01 '20 16:12 gacholio

2 cores, both crash in the exact same place dereferencing NULL somewhere in the bytecode interpreter. Neither java stack is immediately useful.

gacholio avatar Dec 01 '20 17:12 gacholio

Crash appears to be in:

> !j9method 0x00007aeb8c496ed0
J9Method at 0x7aeb8c496ed0 {
  Fields for J9Method:
	0x0: U8* bytecodes = !j9x 0x00007AEB1D70E5D0 // "�"
	0x8: struct J9ConstantPool* constantPool = !j9constantpool 0x00007AEB8C496BE0 (flags = 0x0)
	0x10: void* methodRunAddress = !j9x 0x0000000000000006
	0x18: volatile void* extra = !j9x 0x0000000000000F9B
}
Signature: java/util/concurrent/locks/AbstractQueuedSynchronizer$Node.compareAndSetWaitStatus(II)Z !bytecodes 0x00007AEB8C496ED0
ROM Method: !j9rommethod 0x00007AEB1D70E5BC
Next Method: !j9method 0x00007AEB8C496EF0
> !bytecodes 0x7aeb8c496ed0
  Name: compareAndSetWaitStatus
  Signature: (II)Z
  Access Flags (50010): default final 
  Max Stack: 4
  Argument Count: 3
  Temp Count: 0

    0 getstatic 16 java/util/concurrent/locks/AbstractQueuedSynchronizer$Node.WAITSTATUS Ljava/lang/invoke/VarHandle;
    3 aload0 
    4 iload1 
    5 iload2 
    6 invokevirtual 18 java/lang/invoke/VarHandle.compareAndSet(Ljava/util/concurrent/locks/AbstractQueuedSynchronizer$Node;II)Z
    9 returnZ 

at bytecode 6.

gacholio avatar Dec 01 '20 17:12 gacholio

Full stack:

> !stackslots 0x7aeb8c57da00,0x7aeb8c6f7078,0x7aeb8c6f70c0,0x7AEB1D70E5D6,0x7aeb8c496ed0
<7aeb8c57da00> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x00007AEB8C57DA00 ***
<7aeb8c57da00> 	ITERATE_O_SLOTS
<7aeb8c57da00> 	RECORD_BYTECODE_PC_OFFSET
<7aeb8c57da00> Initial values: walkSP = 0x00007AEB8C6F7078, PC = 0x00007AEB1D70E5D6, literals = 0x00007AEB8C496ED0, A0 = 0x00007AEB8C6F70C0, j2iFrame = 0x0000000000000000, ELS = 0x00007AEB4C4DBF90, decomp = 0x0000000000000000
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F70A8, sp = 0x00007AEB8C6F7078, pc = 0x00007AEB1D70E5D6, cp = 0x00007AEB8C496BE0, arg0EA = 0x00007AEB8C6F70C0, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/locks/AbstractQueuedSynchronizer$Node.compareAndSetWaitStatus(II)Z !j9method 0x00007AEB8C496ED0
<7aeb8c57da00> 	Bytecode index = 6
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F70C0 for 0x0000000000000003 slots
<7aeb8c57da00> 		I-Slot: a0[0x00007AEB8C6F70C0] = 0x00007AEB6C169438
<7aeb8c57da00> 		I-Slot: a1[0x00007AEB8C6F70B8] = 0x00007AEBFFFFFFFE
<7aeb8c57da00> 		I-Slot: a2[0x00007AEB8C6F70B0] = 0x0000000000000000
<7aeb8c57da00> 	Pending stack starting at 0x00007AEB8C6F7090 for UDATA(0x0000000000000004) slots
<7aeb8c57da00> 		O-Slot: p0[0x00007AEB8C6F7090] = 0x0000000000000000
<7aeb8c57da00> 		O-Slot: p1[0x00007AEB8C6F7088] = 0x00007AEB6C169438
<7aeb8c57da00> 		I-Slot: p2[0x00007AEB8C6F7080] = 0x00007AEBFFFFFFFE
<7aeb8c57da00> 		I-Slot: p3[0x00007AEB8C6F7078] = 0x0000000000000000
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F70D8, sp = 0x00007AEB8C6F70C8, pc = 0x00007AEB1D70D4D4, cp = 0x00007AEB8C491BB0, arg0EA = 0x00007AEB8C6F70E8, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/locks/AbstractQueuedSynchronizer.transferAfterCancelledWait(Ljava/util/concurrent/locks/AbstractQueuedSynchronizer$Node;)Z !j9method 0x00007AEB8C491A90
<7aeb8c57da00> 	Bytecode index = 4
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F70E8 for 0x0000000000000002 slots
<7aeb8c57da00> 		O-Slot: a0[0x00007AEB8C6F70E8] = 0x00007AEB6C0E69E8
<7aeb8c57da00> 		O-Slot: a1[0x00007AEB8C6F70E0] = 0x00007AEB6C169438
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F7100, sp = 0x00007AEB8C6F70F0, pc = 0x00007AEB1D7ABD8F, cp = 0x00007AEB8C6ACA90, arg0EA = 0x00007AEB8C6F7160, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.awaitNanos(J)J !j9method 0x00007AEB8C6AD188
<7aeb8c57da00> 	Bytecode index = 67
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F7160 for 0x000000000000000C slots
<7aeb8c57da00> 		O-Slot: a0[0x00007AEB8C6F7160] = 0x00007AEB6C0E68F0
<7aeb8c57da00> 		I-Slot: a1[0x00007AEB8C6F7158] = 0x00007AEB8BEE2150
<7aeb8c57da00> 		I-Slot: a2[0x00007AEB8C6F7150] = 0xFFFFFFFFFF207BC5
<7aeb8c57da00> 		I-Slot: t3[0x00007AEB8C6F7148] = 0x00007AEB8C6F71BA
<7aeb8c57da00> 		I-Slot: t4[0x00007AEB8C6F7140] = 0x00443F8D6AD55C2C
<7aeb8c57da00> 		I-Slot: t5[0x00007AEB8C6F7138] = 0x00007AEB8C6AA068
<7aeb8c57da00> 		I-Slot: t6[0x00007AEB8C6F7130] = 0x0000000DF72EB444
<7aeb8c57da00> 		O-Slot: t7[0x00007AEB8C6F7128] = 0x00007AEB6C169438
<7aeb8c57da00> 		I-Slot: t8[0x00007AEB8C6F7120] = 0x0000000000000001
<7aeb8c57da00> 		I-Slot: t9[0x00007AEB8C6F7118] = 0x0000000000000000
<7aeb8c57da00> 		I-Slot: t10[0x00007AEB8C6F7110] = 0x00007AEB1D96AEDC
<7aeb8c57da00> 		I-Slot: t11[0x00007AEB8C6F7108] = 0x00007AEB8C6F31A0
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F7178, sp = 0x00007AEB8C6F7168, pc = 0x00007AEB1D9695D6, cp = 0x00007AEB8C6AA6F0, arg0EA = 0x00007AEB8C6F71B8, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/ScheduledThreadPoolExecutor$DelayedWorkQueue.take()Ljava/util/concurrent/RunnableScheduledFuture; !j9method 0x00007AEB8C6AA068
<7aeb8c57da00> 	Bytecode index = 126
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F71B8 for 0x0000000000000008 slots
<7aeb8c57da00> 		O-Slot: a0[0x00007AEB8C6F71B8] = 0x00007AEB6C0E6918
<7aeb8c57da00> 		O-Slot: t1[0x00007AEB8C6F71B0] = 0x00007AEB6C0E6950
<7aeb8c57da00> 		I-Slot: t2[0x00007AEB8C6F71A8] = 0x0000000000000000
<7aeb8c57da00> 		I-Slot: t3[0x00007AEB8C6F71A0] = 0x00007AEB8C6AA208
<7aeb8c57da00> 		I-Slot: t4[0x00007AEB8C6F7198] = 0x0000000DF72EB444
<7aeb8c57da00> 		O-Slot: t5[0x00007AEB8C6F7190] = 0x00007AEB6C169350
<7aeb8c57da00> 		I-Slot: t6[0x00007AEB8C6F7188] = 0x00007AEB8C6F4230
<7aeb8c57da00> 		I-Slot: t7[0x00007AEB8C6F7180] = 0x00007AEB8BEE2008
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F71D0, sp = 0x00007AEB8C6F71C0, pc = 0x00007AEB1D969D25, cp = 0x00007AEB8C6AA6F0, arg0EA = 0x00007AEB8C6F71D8, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/ScheduledThreadPoolExecutor$DelayedWorkQueue.take()Ljava/lang/Object; !j9method 0x00007AEB8C6AA208
<7aeb8c57da00> 	Bytecode index = 1
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F71D8 for 0x0000000000000001 slots
<7aeb8c57da00> 		I-Slot: a0[0x00007AEB8C6F71D8] = 0x00007AEB8BE166D8
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F71F0, sp = 0x00007AEB8C6F71E0, pc = 0x00007AEB1D7A4F7D, cp = 0x00007AEB8C6A5DC0, arg0EA = 0x00007AEB8C6F7220, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/ThreadPoolExecutor.getTask()Ljava/lang/Runnable; !j9method 0x00007AEB8C6A6B30
<7aeb8c57da00> 	Bytecode index = 149
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F7220 for 0x0000000000000006 slots
<7aeb8c57da00> 		O-Slot: a0[0x00007AEB8C6F7220] = 0x00007AEB6C0E6968
<7aeb8c57da00> 		I-Slot: t1[0x00007AEB8C6F7218] = 0x0000000000000000
<7aeb8c57da00> 		I-Slot: t2[0x00007AEB8C6F7210] = 0x00007AEBE0000001
<7aeb8c57da00> 		I-Slot: t3[0x00007AEB8C6F7208] = 0x00007AEB00000001
<7aeb8c57da00> 		I-Slot: t4[0x00007AEB8C6F7200] = 0x0000000000000000
<7aeb8c57da00> 		I-Slot: t5[0x00007AEB8C6F71F8] = 0x0000000000000001
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F7238, sp = 0x00007AEB8C6F7228, pc = 0x00007AEB1D7A502E, cp = 0x00007AEB8C6A5DC0, arg0EA = 0x00007AEB8C6F7278, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/ThreadPoolExecutor.runWorker(Ljava/util/concurrent/ThreadPoolExecutor$Worker;)V !j9method 0x00007AEB8C6A6B50
<7aeb8c57da00> 	Bytecode index = 26
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F7278 for 0x0000000000000008 slots
<7aeb8c57da00> 		O-Slot: a0[0x00007AEB8C6F7278] = 0x00007AEB6C0E6968
<7aeb8c57da00> 		O-Slot: a1[0x00007AEB8C6F7270] = 0x00007AEB6C169470
<7aeb8c57da00> 		O-Slot: t2[0x00007AEB8C6F7268] = 0x00007AEB6C169350
<7aeb8c57da00> 		I-Slot: t3[0x00007AEB8C6F7260] = 0x0000000000000000
<7aeb8c57da00> 		I-Slot: t4[0x00007AEB8C6F7258] = 0x00007AEB00000001
<7aeb8c57da00> 		I-Slot: t5[0x00007AEB8C6F7250] = 0x0000000000000000
<7aeb8c57da00> 		I-Slot: t6[0x00007AEB8C6F7248] = 0x00007AEB8C6A6B50
<7aeb8c57da00> 		I-Slot: t7[0x00007AEB8C6F7240] = 0x00007AEB6C270338
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F7290, sp = 0x00007AEB8C6F7280, pc = 0x00007AEB1D7C6AC5, cp = 0x00007AEB8C6F4010, arg0EA = 0x00007AEB8C6F7298, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/util/concurrent/ThreadPoolExecutor$Worker.run()V !j9method 0x00007AEB8C6F41D0
<7aeb8c57da00> 	Bytecode index = 5
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F7298 for 0x0000000000000001 slots
<7aeb8c57da00> 		I-Slot: a0[0x00007AEB8C6F7298] = 0x00007AEB8BEE2008
<7aeb8c57da00> Bytecode frame: bp = 0x00007AEB8C6F72B0, sp = 0x00007AEB8C6F72A0, pc = 0x00007AEB1D49DF59, cp = 0x00007AEB8C357090, arg0EA = 0x00007AEB8C6F72B8, flags = 0x0000000000000000
<7aeb8c57da00> 	Method: java/lang/Thread.run()V !j9method 0x00007AEB8C358728
<7aeb8c57da00> 	Bytecode index = 13
<7aeb8c57da00> 	Using local mapper
<7aeb8c57da00> 	Locals starting at 0x00007AEB8C6F72B8 for 0x0000000000000001 slots
<7aeb8c57da00> 		I-Slot: a0[0x00007AEB8C6F72B8] = 0x00007AEB8BEE2150
<7aeb8c57da00> JNI call-in frame: bp = 0x00007AEB8C6F72E0, sp = 0x00007AEB8C6F72C0, pc = 0x00007AEB9285CA58, cp = 0x0000000000000000, arg0EA = 0x00007AEB8C6F72E0, flags = 0x0000000000000000
<7aeb8c57da00> 	New ELS = 0x0000000000000000
<7aeb8c57da00> JNI native method frame: bp = 0x00007AEB8C6F7308, sp = 0x00007AEB8C6F72E8, pc = 0x0000000000000007, cp = 0x0000000000000000, arg0EA = 0x00007AEB8C6F7308, flags = 0x0000000000000000
<7aeb8c57da00> <end of stack>
<7aeb8c57da00> *** END STACK WALK (rc = NONE) ***

gacholio avatar Dec 01 '20 17:12 gacholio

The WAITSTATUS static appears valid:

> !j9object 0x00007AEB6C2B88B0
!J9Object 0x00007AEB6C2B88B0 {
	struct J9Class* clazz = !j9class 0x7AEB8C493B00 // java/lang/invoke/InstanceFieldVarHandle
	Object flags = 0x00000000;
	J lockword = 0x0000000000000000 (offset = 0) (java/lang/Object) <hidden>
	[Ljava/lang/invoke/MethodHandle; handleTable = !fj9object 0x7aeb6c31bae8 (offset = 8) (java/lang/invoke/VarHandle)
	Ljava/lang/Class; fieldType = !fj9object 0x7aeb6c000f18 (offset = 16) (java/lang/invoke/VarHandle)
	[Ljava/lang/Class; coordinateTypes = !fj9object 0x7aeb6c31bbf0 (offset = 24) (java/lang/invoke/VarHandle)
	I modifiers = 0x00300040 (offset = 32) (java/lang/invoke/VarHandle)
	J vmslot = 0x0000000000000030 (offset = 40) (java/lang/invoke/FieldVarHandle)
	Ljava/lang/String; fieldName = !fj9object 0x7aeb6c2c8598 (offset = 48) (java/lang/invoke/FieldVarHandle)
	Ljava/lang/Class; definingClass = !fj9object 0x7aeb6c03cce8 (offset = 56) (java/lang/invoke/FieldVarHandle)
}

gacholio avatar Dec 01 '20 17:12 gacholio

The stack is modified by the VarHandle implementation code:

0x7AEB8C6F7070 :  00007aeb6c2b88b0 0000000000000000 [ ..+l.z.......... ] 
0x7AEB8C6F7080 :  00007aebfffffffe 00007aeb6c169438 [ .....z..8..l.z.. ] 
0x7AEB8C6F7090 :  000000000000000

The VarHandle is pushed onto the stack, and it's old stack slot is overwritten with a MethodHandle (somehow 0 in this case, which is no doubt the cause of the crash).

gacholio avatar Dec 01 '20 17:12 gacholio

I expect the actual crash occurs transitioning to the MH interpreter due to the NULL MH. The code which set the slot to NULL is:

https://github.com/eclipse/openj9/blob/master/runtime/vm/BytecodeInterpreter.hpp#L8469-L8553

gacholio avatar Dec 01 '20 18:12 gacholio

@babsingh There must be a timing hole somewhere in the caching mechanism, though I don't see it. This might also be related to weak memory ordering on PPC. I notice the callSiteType variable has been randomly marked volatile, which might trick the compiler into doing something stupid.

gacholio avatar Dec 01 '20 19:12 gacholio

100x grinder https://ci.eclipse.org/openj9/job/Grinder/1231/

pshipton avatar Dec 01 '20 19:12 pshipton

Grinder appears to be failing for an unrelated reason:

14:36:53  Error: Cannot find file: /home/jenkins/workspace/Grinder_iteration_3/openjdk-tests/TKG/../openjdk/openjdk-jdk/jdk/internal/reflect/CallerSensitive/MissingCallerSensitive.java

gacholio avatar Dec 01 '20 19:12 gacholio

Ya, I messed up the test name. 100x (25x on 4 machines) grinder https://ci.eclipse.org/openj9/job/Grinder/1232/ - passed

pshipton avatar Dec 01 '20 19:12 pshipton

Observed at a JDK11 zLinux build job/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/29/ (rhel7s390x-3-3)

java version "11.0.14-beta" 2022-01-18
IBM Semeru Runtime Certified Edition 11.0.14+5-202112080215 (build 11.0.14-beta+5-202112080215)
Eclipse OpenJ9 VM 11.0.14+5-202112080215 (build master-f5069c6c9, JRE 11 Linux s390x-64-Bit Compressed References 20211207_208 (JIT enabled, AOT enabled)
OpenJ9   - f5069c6c9
OMR      - 11cbde10d
JCL      - 59d4ee7750 based on jdk-11.0.14+5)

[2021-12-08T03:20:15.826Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode150
[2021-12-08T03:20:15.826Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:+UseCompressedOops 

[2021-12-08T03:38:29.220Z] --------------------------------------------------
[2021-12-08T03:38:29.220Z] TEST: jdk/internal/reflect/CallerSensitive/MissingCallerSensitive.java

[2021-12-08T03:38:29.222Z] stderr:
[2021-12-08T03:38:29.222Z] Unhandled exception
[2021-12-08T03:38:29.222Z] Type=Segmentation error vmState=0x00000000
[2021-12-08T03:38:29.222Z] J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=1642ae70 Signal_Code=00000001
[2021-12-08T03:38:29.222Z] Handler1=000003FF7EC479C8 Handler2=000003FF7EB32260 InaccessibleAddress=0000000000000000
[2021-12-08T03:38:29.222Z] gpr0=000003FF2170D260 gpr1=000003FF78015070 gpr2=000000000000000C gpr3=0000000000000000
[2021-12-08T03:38:29.222Z] gpr4=0000000000A9AC00 gpr5=000000000000000C gpr6=0000000000000000 gpr7=000003FF394F8428
[2021-12-08T03:38:29.222Z] gpr8=000003FF2170D5EA gpr9=0000000000B87238 gpr10=0000000000000000 gpr11=000003FF394F8308
[2021-12-08T03:38:29.222Z] gpr12=000000002CBE3F20 gpr13=000003FF7EE38130 gpr14=000003FF7ECAB824 gpr15=000003FF394F7F68
[2021-12-08T03:38:29.222Z] psw=000003FF7ECA552C mask=0705000180000000 fpc=0008fe00 bea=000003FF7ECA54E6
[2021-12-08T03:38:29.222Z] fpr0 000003ff78015001 (f: 2013351936.000000, d: 2.171796e-311)
[2021-12-08T03:38:29.222Z] fpr1 4425400000000000 (f: 0.000000, d: 1.959967e+20)
[2021-12-08T03:38:29.222Z] fpr2 0000000000020040 (f: 131136.000000, d: 6.478979e-319)
[2021-12-08T03:38:29.222Z] fpr3 3c5a257b00200020 (f: 2097184.000000, d: 5.669598e-18)
[2021-12-08T03:38:29.222Z] fpr4 0000000000100000 (f: 1048576.000000, d: 5.180654e-318)
[2021-12-08T03:38:29.222Z] fpr5 3e924d5fa000c000 (f: 2684403712.000000, d: 2.727246e-07)
[2021-12-08T03:38:29.222Z] fpr6 000003ff00000001 (f: 1.000000, d: 2.170802e-311)
[2021-12-08T03:38:29.222Z] fpr7 3e3a3a0600000000 (f: 0.000000, d: 6.106369e-09)
[2021-12-08T03:38:29.222Z] fpr8 00000000007e6bd8 (f: 8285144.000000, d: 4.093405e-317)
[2021-12-08T03:38:29.222Z] fpr9 0000000000498be0 (f: 4819936.000000, d: 2.381365e-317)
[2021-12-08T03:38:29.222Z] fpr10 00000000006e2770 (f: 7219056.000000, d: 3.566688e-317)
[2021-12-08T03:38:29.222Z] fpr11 0000000000498bd0 (f: 4819920.000000, d: 2.381357e-317)
[2021-12-08T03:38:29.222Z] fpr12 00000000006e2a70 (f: 7219824.000000, d: 3.567067e-317)
[2021-12-08T03:38:29.222Z] fpr13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-08T03:38:29.222Z] fpr14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2021-12-08T03:38:29.222Z] fpr15 0000000000498bc0 (f: 4819904.000000, d: 2.381349e-317)
[2021-12-08T03:38:29.222Z] Module=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
[2021-12-08T03:38:29.222Z] Module_base_address=000003FF7EC00000
[2021-12-08T03:38:29.222Z] Target=2_90_20211207_208 (Linux 3.10.0-1160.49.1.el7.s390x)
[2021-12-08T03:38:29.222Z] CPU=s390x (4 logical CPUs) (0x1ec5df000 RAM)
[2021-12-08T03:38:29.222Z] ----------- Stack Backtrace -----------
[2021-12-08T03:38:29.222Z] (0x000003FF7ECA552C [libj9vm29.so+0xa552c])
[2021-12-08T03:38:29.223Z] (0x000003FF7ECA4558 [libj9vm29.so+0xa4558])
[2021-12-08T03:38:29.223Z] (0x000003FF7ED97A04 [libj9vm29.so+0x197a04])
[2021-12-08T03:38:29.223Z] ---------------------------------------
[2021-12-08T03:38:29.223Z] JVMDUMP039I Processing dump event "gpf", detail "" at 2021/12/07 19:38:12 - please wait.
[2021-12-08T03:38:29.223Z] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/core.20211207.193812.18683.0001.dmp' in response to an event
[2021-12-08T03:38:29.223Z] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/core.20211207.193812.18683.0001.dmp
[2021-12-08T03:38:29.223Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/javacore.20211207.193812.18683.0002.txt' in response to an event
[2021-12-08T03:38:29.223Z] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/javacore.20211207.193812.18683.0002.txt
[2021-12-08T03:38:29.223Z] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/Snap.20211207.193812.18683.0003.trc' in response to an event
[2021-12-08T03:38:29.223Z] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/Snap.20211207.193812.18683.0003.trc
[2021-12-08T03:38:29.223Z] JVMDUMP032I JVM requested JIT dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/jitdump.20211207.193812.18683.0004.dmp' in response to an event
[2021-12-08T03:38:29.223Z] JVMDUMP051I JIT dump occurred in 'pool-2-thread-1' thread 0x0000000000A9AC00
[2021-12-08T03:38:29.223Z] JVMDUMP053I JIT dump is recompiling java/util/concurrent/ThreadPoolExecutor.runWorker(Ljava/util/concurrent/ThreadPoolExecutor$Worker;)V
[2021-12-08T03:38:29.223Z] JVMDUMP053I JIT dump is recompiling java/lang/Thread.run()V
[2021-12-08T03:38:29.223Z] JVMDUMP010I JIT dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work/scratch/1/jitdump.20211207.193812.18683.0004.dmp
[2021-12-08T03:38:29.223Z] JVMDUMP013I Processed dump event "gpf", detail "".
[2021-12-08T03:38:29.223Z] 
[2021-12-08T03:38:29.223Z] TEST RESULT: Error. Agent communication error: java.io.EOFException; check console log for any additional details
[2021-12-08T03:38:29.223Z] --------------------------------------------------
[2021-12-08T03:38:48.913Z] Test results: passed: 727; error: 1
[2021-12-08T03:38:54.520Z] Report written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/jvmtest/openjdk/report/html/report.html
[2021-12-08T03:38:54.520Z] Results written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_s390x_linux_testList_1/aqa-tests/TKG/output_16389336133092/jdk_lang_0/work
[2021-12-08T03:38:54.520Z] Error: Some tests failed or other problems occurred.
[2021-12-08T03:38:54.520Z] 
[2021-12-08T03:38:54.520Z] jdk_lang_0_FAILED

JasonFengJ9 avatar Dec 09 '21 13:12 JasonFengJ9

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_Nightly/260 jdk_lang_0 jdk/internal/reflect/CallerSensitive/MissingCallerSensitive.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_Nightly/260/openjdk_test_output.tar.gz

21:42:02  Unhandled exception
21:42:02  Type=Segmentation error vmState=0x00000000
21:42:02  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
21:42:02  Handler1=0000FFFF82375550 Handler2=0000FFFF822EA220 InaccessibleAddress=0000000000000010
21:42:02  R0=000000000000000C R1=0000000000000001 R2=000000000000000C R3=0000FFFF7C02BBF0
21:42:02  R4=0000000000000000 R5=0000FFFF7C0C2E78 R6=0000FFFF29715668 R7=000000000000049C
21:42:02  R8=0000000000162700 R9=0000FFFF7C02BBF0 R10=0000000000000000 R11=00000000E014FE10
21:42:02  R12=0000000000000000 R13=00000000E0046638 R14=00000000001704B0 R15=0000000000001200
21:42:02  R16=0000FFFF825100C0 R17=0000FFFF8295E280 R18=00000000FFB03A30 R19=0000FFFF824E4020
21:42:02  R20=0000FFFF286DE120 R21=0000FFFF286DE0A0 R22=0000000000323300 R23=0000FFFF286DE150
21:42:02  R24=0000000000000000 R25=0000000000493838 R26=0000000000000000 R27=0000FFFF297159F2
21:42:02  R28=0000FFFF823C6160 R29=0000FFFF286DDDB0 R30=0000FFFF823CF4C4 R31=0000FFFF286DDDA0
21:42:02  PC=0000FFFF823C6F28 SP=0000FFFF286DDDA0 PSTATE=0000000060001000
21:42:02  V0 00000000004938d8 (f: 4798680.000000, d: 2.370863e-317)
21:42:02  V1 ffffffffffffffff (f: 4294967296.000000, d: -nan)
21:42:02  V2 000000003f800000 (f: 1065353216.000000, d: 5.263544e-315)
21:42:02  V3 bfd00ea348b88334 (f: 1220051712.000000, d: -2.508934e-01)
21:42:02  V4 bfdfe6497536d99f (f: 1966528896.000000, d: -4.984306e-01)
21:42:02  V5 bfc6574f0ac07758 (f: 180385632.000000, d: -1.745395e-01)
21:42:02  V6 3fe62e42fefa39ef (f: 4277811712.000000, d: 6.931472e-01)
21:42:02  V7 8020080280200802 (f: 2149582848.000000, d: -4.458850e-308)
21:42:02  V8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V11 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V16 4010040140100401 (f: 1074791424.000000, d: 4.003911e+00)
21:42:02  V17 fcfcfcfefd000000 (f: 4244635648.000000, d: -1.157119e+294)
21:42:02  V18 0000ffff286de2a8 (f: 678290112.000000, d: 1.390653e-309)
21:42:02  V19 0000ffff286de298 (f: 678290048.000000, d: 1.390653e-309)
21:42:02  V20 0000ffff286de288 (f: 678290048.000000, d: 1.390653e-309)
21:42:02  V21 0000ffff286de278 (f: 678290048.000000, d: 1.390653e-309)
21:42:02  V22 0000ffff286de268 (f: 678290048.000000, d: 1.390653e-309)
21:42:02  V23 00000000000000f0 (f: 240.000000, d: 1.185758e-321)
21:42:02  V24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
21:42:02  V31 000000003f400000 (f: 1061158912.000000, d: 5.242822e-315)
21:42:02  Module=/home/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_aarch64_linux_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
21:42:02  Module_base_address=0000FFFF82340000
21:42:02  Target=2_90_20220915_260 (Linux 4.18.0-348.7.1.el8_5.aarch64)
21:42:02  CPU=aarch64 (8 logical CPUs) (0x1dc280000 RAM)
21:42:02  ----------- Stack Backtrace -----------
21:42:02  protectedBacktrace+0x18 (0x0000FFFF822E69A8 [libj9prt29.so+0x269a8])
21:42:02  ---------------------------------------

pshipton avatar Sep 15 '22 02:09 pshipton

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_x86-64_mac_OMR/28 jdk_lang_j9_0 jdk/internal/reflect/CallerSensitive/MissingCallerSensitive.java

Diagnostics didn't get saved.

05:59:56  Type=Segmentation error vmState=0x00000000
05:59:56  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
05:59:56  Handler1=0000000003570E10 Handler2=0000000003890B70 InaccessibleAddress=0000000000000020
05:59:56  RDI=00007FDD54E04410 RSI=00007FDD5E289300 RAX=00007FDD56815220 RBX=0000700001C37AD0
05:59:56  RCX=0000000000000018 RDX=0000000000000000 R8=00007FDD599E9B98 R9=00007FDD5ACF6A00
05:59:56  R10=00007FDD56815220 R11=0000000046EAB4D2 R12=0000000046EAB4D2 R13=0000000000000000
05:59:56  R14=00007FDD5E289300 R15=00007FDD599E9B98
05:59:56  RIP=0000000003608658 GS=0000 FS=0000 RSP=0000700001C37840
05:59:56  RFlags=0000000000010246 CS=002B RBP=0000700001C37AC0 ERR=0000002000000004
05:59:56  TRAPNO=000000040000000E CPU=0020000000040000 FAULTVADDR=0000000000000020
05:59:56  XMM0 0000000046eab4cf (f: 1189786880.000000, d: 5.878328e-315)
05:59:56  XMM1 00007fdd599e9bb8 (f: 1503566720.000000, d: 6.946003e-310)
05:59:56  XMM2 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM3 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM4 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM5 656b6f766e692f67 (f: 1852387200.000000, d: 3.557613e+180)
05:59:56  XMM6 3fd4be5f957778a1 (f: 2507634944.000000, d: 3.241195e-01)
05:59:56  XMM7 402791272ee9dd8e (f: 787078528.000000, d: 1.178350e+01)
05:59:56  XMM8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM11 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  XMM15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
05:59:56  Module=/Users/jenkins/workspace/Test_openjdk11_j9_sanity.openjdk_x86-64_mac_OMR/openjdkbinary/j2sdk-image/lib/default/libj9vm29.dylib
05:59:56  Module_base_address=000000000353A000 Symbol=_ZN26VM_BytecodeInterpreterFull3runEP10J9VMThread
05:59:56  Symbol_address=00000000035EFFE0
05:59:56  Target=2_90_20230622_489 (Mac OS X 11.6.8)
05:59:56  CPU=amd64 (12 logical CPUs) (0x400000000 RAM)
05:59:56  ----------- Stack Backtrace -----------
05:59:56  _ZN26VM_BytecodeInterpreterFull3runEP10J9VMThread+0x18679 (0x0000000003608659 [libj9vm29.dylib+0xce659])
05:59:56  bytecodeLoopFull+0xd1 (0x00000000035EFFD1 [libj9vm29.dylib+0xb5fd1])

pshipton avatar Jun 22 '23 13:06 pshipton

I think this is another one that gets fixed with the MH backport

tajila avatar Jun 26 '23 13:06 tajila

@babsingh ^^

tajila avatar Jun 26 '23 13:06 tajila