search

eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.23k stars 713 forks source link

z/OS abbs ASSERTION FAILED ** at ./MarkingScheme.hpp:70: ((false)) #16646

Open pshipton opened 1 year ago

pshipton commented 1 year ago

Internal build [zOS S390] 80 Load_Level_2.abbs.5mins.Mode112 - labec16 IBM_JAVA_OPTIONS = -Xgcpolicy:gencon -Xjit:count=0 -Xnocompressedrefs

50x grinder passed

j> 10:48:00 20230201 10:47:42 Runtime State Reporter IMPORTANT: 1870 tests complete, 243 currently running
j> 10:48:25 Pointer: ACFB04A3 has is not object aligned (to 8 bytes) 
j> 10:48:25 18:48:24.661 0x448fa300    j9mm.141    *   ** ASSERTION FAILED ** at ./MarkingScheme.hpp:70: ((false))

I couldn't recreate the failure, but just in case, the change from previous build https://github.com/eclipse/omr/pull/6847

pshipton commented 1 year ago

@dmitripivkine fyi

dmitripivkine commented 1 year ago

All starts when GC expected !j9class 0x48814400 but this area in the class segment is zeroed:

0x488142E0 :  48814400 00000031 3e4e7100 00000021 [ H.D....1>Nq....! ]
0x488142F0 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814300 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814310 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814320 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814330 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814340 :  3d357b00 00000031 3d690300 00000031 [ =5{....1=i.....1 ]
0x48814350 :  3e4e8200 00000031 3d353000 00000421 [ >N.....1=50....! ]
0x48814360 :  3d632000 00000421 00000000 00000000 [ =c ....!........ ]
0x48814370 :  47fc323c 488141e0 00000006 00000001 [ G.2<H.A......... ]
0x48814380 :  47fc3268 488141e0 00000006 00000001 [ G.2hH.A......... ]
0x48814390 :  47fc3294 488141e0 00000018 4b2803f8 [ G.2.H.A.....K(.. ]
0x488143A0 :  47fc32d0 488141e0 00000018 4b2413f4 [ G.2.H.A.....K$.. ]
0x488143B0 :  47fc34f8 488141e0 00000000 00000000 [ G.4.H.A......... ]
0x488143C0 :  00000000 00000000 00000000 00000000 [ ................ ]
0x488143D0 :  00000000 00000000 00000000 00000000 [ ................ ]<--- !j9itable 0x488143D8 for !j9class 0x48814b00
0x488143E0 :  00000000 00000000 00000000 00000000 [ ................ ]
0x488143F0 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814400 :  00000000 00000000 00000000 00000000 [ ................ ]<--- expected j9class here
0x48814410 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814420 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814430 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814440 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814450 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814460 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814470 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814480 :  00000000 00000000 00000000 00000000 [ ................ ]
0x48814490 :  00000000 00000000 00000000 00000000 [ ................ ]
0x488144A0 :  00000000 00000000 00000000 00000000 [ ................ ]
0x488144B0 :  00000000 00000000 00000000 00000005 [ ................ ]
0x488144C0 :  19ef82b8 19ef8ae8 3e4e71fc 3e4e720c [ ........>Nq.>Nr. ]
0x488144D0 :  3e4e721c 3e4e723c 3e4e726c 4804f9e0 [ >Nr.>Nr<>NrlH... ]
0x488144E0 :  48814a00 47fc3a30 48814a00 00000021 [ H.J.G.:0H.J....! ]
0x488144F0 :  80000000 00000000 007fffff 00000000 [ ................ ]
0x48814500 :  7f800000 00000000 00800000 00000000 [ ................ ]
0x48814510 :  00000000 00000000 1c58ad68 00000000 [ .........X.h.... ]
0x48814520 :  1c7bda10 00000000 00000000 00000000 [ .{.............. ]

This is zOS-31, so first 2K [0,0x800] of virtual memory is available to read. GC code failure starts with dereferencing NULL and ends up at NULL->0x7c0

0x000007B0 :  55f007e4 474007bc 41f00030 5ef007e0 [ U...G@..A..0^... ]
0x000007C0 :  acfb04a3 58f0f000 0cefad04 04a318e0 [ ....X........... ] <----
0x000007D0 :  0b0e0000 00000000 00000000 00000000 [ ................ ]

interpreting 0xacfb04a3 as an object pointer.

Looks like this class use to be valid (?). I found class object for it, I am not sure why all fields except classLoader are zeroes

> !j9object 0x1C915F98
!J9Object 0x1C915F98 {
    struct J9Class* clazz = !j9class 0x3E4EAB00 // java/lang/Class
    Object flags = 0x0000000A;
    I lockword = 0x00000000 (offset = 0) (java/lang/Object) <hidden>
    J vmRef = 0x0000000048814400 (offset = 4) (java/lang/Class) <------- 
    Ljava/lang/ClassLoader; classLoader = !fj9object 0x1c5233b8 (offset = 12) (java/lang/Class)
    Ljava/security/ProtectionDomain; protectionDomain = !fj9object 0x0 (offset = 16) (java/lang/Class)
    Ljava/lang/String; classNameString = !fj9object 0x0 (offset = 20) (java/lang/Class)
    Ljava/lang/String; cachedToString = !fj9object 0x0 (offset = 24) (java/lang/Class)
    Ljava/lang/String; fileNameString = !fj9object 0x0 (offset = 28) (java/lang/Class)
    Ljava/lang/String; packageNameString = !fj9object 0x0 (offset = 32) (java/lang/Class)
    Ljava/lang/Class$AnnotationVars; annotationVars = !fj9object 0x0 (offset = 36) (java/lang/Class)
    Ljava/lang/ClassValue$ClassValueMap; classValueMap = !fj9object 0x0 (offset = 40) (java/lang/Class)
    Ljava/lang/Class$EnumVars; enumVars = !fj9object 0x0 (offset = 44) (java/lang/Class)
    Ljava/lang/J9VMInternals$ClassInitializationLock; initializationLock = !fj9object 0x0 (offset = 48) (java/lang/Class)
    Ljava/lang/Object; methodHandleCache = !fj9object 0x0 (offset = 52) (java/lang/Class)
    Ljava/lang/Class$ClassRepositoryHolder; classRepoHolder = !fj9object 0x0 (offset = 56) (java/lang/Class)
    Ljava/lang/Class$AnnotationCache; annotationCache = !fj9object 0x0 (offset = 60) (java/lang/Class)
    Ljava/lang/Class$MetadataCache; metadataCache = !fj9object 0x0 (offset = 64) (java/lang/Class)
    [Ljava/lang/Class; cachedInterfaces = !fj9object 0x0 (offset = 68) (java/lang/Class)
    Ljava/lang/Class; cachedDeclaringClass = !fj9object 0x0 (offset = 72) (java/lang/Class)
    Ljava/lang/Class; cachedEnclosingClass = !fj9object 0x0 (offset = 76) (java/lang/Class)
    Z cachedCheckInnerClassAttr = 0x00000000 (offset = 84) (java/lang/Class)
    Ljava/lang/Class$ReflectCache; reflectCache = !fj9object 0x0 (offset = 80) (java/lang/Class)
}

If there is general memory corruption unrelated with memory content it is very hard to find obviously. There is another observation: I noticed next class in the memory 

> !j9class 0x48814b00
J9Class at 0x48814b00 {
  Fields for J9Class:
    0x0: UDATA eyecatcher = 0x99669966 (2573637990)
    0x4: struct J9ROMClass * romClass = !j9romclass 0x47FC65D8
    0x8: struct J9Class ** superclasses = !j9x 0x48814ADC
    0xc: UDATA classDepthAndFlags = 0x001E0001 (1966081)
    0x10: U32 classDepthWithFlags = 0x00000000 (0)
    0x14: U32 classFlags = 0x00000000 (0)
    0x18: struct J9ClassLoader * classLoader = !j9classloader 0x1C4DB3E0
    0x1c: j9object_t classObject = !j9object 0x1C7C51B8 // java/lang/Class
    0x20: volatile UDATA initializeStatus = 0x00000000 (0) <-------------------------
    0x24: struct J9Method * ramMethods = !j9method 0x48814BD0 // sun/misc/FloatingDecimal$BinaryToASCIIConverter.toJavaFormatString()Ljava/lang/String;
    0x28: UDATA * ramStatics = !j9x 0x00000000
    0x2c: struct J9Class * arrayClass = !j9class 0x00000000
    0x30: UDATA totalInstanceSize = 0x00000008 (8)
    0x34: struct J9ITable * lastITable = !j9itable 0x488143D8 <------------------------
    0x38: UDATA * instanceDescription = !j9x 0x00000001
    0x3c: UDATA * instanceLeafDescription = !j9x 0x00000001
    0x40: UDATA instanceHotFieldDescription = 0x00000000 (0)
    0x44: UDATA selfReferencingField1 = 0x00000000 (0)
    0x48: UDATA selfReferencingField2 = 0x00000000 (0)
    0x4c: struct J9Method * initializerCache = !j9method 0x00000000
    0x50: UDATA romableAotITable = 0x1A1BBCE0 (438025440)
    0x54: UDATA packageID = 0x3D32BDA9 (1026735529)
    0x58: struct J9Module * module = !j9module 0x00000000
    0x5c: struct J9Class * subclassTraversalLink = !j9class 0x48814A00 // sun/misc/FloatingDecimal
    0x60: struct J9Class * subclassTraversalReverseLink = !j9class 0x48814D00 // sun/misc/FloatingDecimal$ExceptionalBinaryToASCIIBuffer
    0x64: void ** iTable = !j9x 0x488143D8 <------------------------
    0x68: UDATA castClassCache = 0x00000000 (0)
    0x6c: void ** jniIDs = !j9x 0x00000000
    0x70: UDATA lockOffset = 0x00000004 (4)
    0x74: U16 reservedCounter = 0x0000 (0)
    0x76: U16 cancelCounter = 0x0000 (0)
    0x78: UDATA newInstanceCount = 0x00000000 (0)
    0x7c: IDATA backfillOffset = 0x00000008 (8)
    0x80: struct J9Class * replacedClass = !j9class 0x00000000
    0x84: UDATA finalizeLinkOffset = 0x00000000 (0)
    0x88: struct J9Class * nextClassInSegment = !j9class 0x48814A00 // sun/misc/FloatingDecimal
    0x8c: UDATA* ramConstantPool = !j9x 0x4804C7D0
    0x90: j9object_t * callSites = !j9x 0x00000000
    0x94: j9object_t * methodTypes = !j9x 0x00000000
    0x98: j9object_t * varHandleMethodTypes = !j9x 0x00000000
    0x9c: struct J9VMCustomSpinOptions * customSpinOption = !j9vmcustomspinoptions 0x00000000
    0xa0: struct J9Method ** staticSplitMethodTable = !j9x 0x00000000
    0xa4: struct J9Method ** specialSplitMethodTable = !j9x 0x00000000
    0xa8: struct J9JITExceptionTable * jitMetaDataList = !j9jitexceptiontable 0x00000000
    0xac: struct J9Class * gcLink = !j9class 0x00000000
    0xb0: struct J9Class * hostClass = !j9class 0x48814B00 // sun/misc/FloatingDecimal$BinaryToASCIIConverter
    0xb4: struct J9FlattenedClassCache * flattenedClassCache = !j9flattenedclasscache 0x00000000
    0xb8: struct J9ClassHotFieldsInfo * hotFieldsInfo = !j9classhotfieldsinfo 0x00000000
}
Class name: sun/misc/FloatingDecimal$BinaryToASCIIConverter
To view static fields, use !j9statics 0x48814B00
To view instance shape, use !j9classshape 0x48814B00

> !j9itable 0x488143D8
J9ITable at 0x488143d8 {
  Fields for J9ITable:
    0x0: struct J9Class * interfaceClass = !j9class 0x00000000
    0x4: UDATA depth = 0x00000000 (0)
    0x8: struct J9ITable * next = !j9itable 0x00000000
}

has initializeStatus = 0x00000000. If it is not a corruption as well it might mean an initialization of this class has not been complete. Also please notice iTable = !j9x 0x488143D8 points to the same zeroed chunk as well (normally this section should not contain zeroes, at least by GC expectations). I wondering what if problematic memory range was zeroed during initialization of !j9class 0x48814b00 some time after point !j9itable 0x488143D8 was created and set to the j9class? This theory does not explain why class object !j9object 0x1C915F98 for !j9class 0x48814400 is full of zeroes however.

Core is loaded to /team/dmitri/16646/J9BUILD.JVM.TDUMP.J9BUILD9.D230201.T104824

dmitripivkine commented 1 year ago

@tajila @pshipton FYI. I will dig around a little bit more with hope to discover something

dmitripivkine commented 1 year ago

GC Check discovered two more problems in this core - class pointer in O-slot:

Checking THREAD STACKS...  
  <gc check (5): from debugger: THREAD STACKS: slot 414f1e00(1ca7eca8) -> 3d5a2500: object slot appears to contain a J9Class pointer>
  <gc check (6): from debugger: THREAD STACKS: slot 45a29200(1ca7eca8) -> 3d5a2500: object slot appears to contain a J9Class pointer>

> !stackslots 0x414f1e00
<414f1e00> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x414F1E00 ***
<414f1e00>  ITERATE_O_SLOTS
<414f1e00>  RECORD_BYTECODE_PC_OFFSET
<414f1e00> Initial values: walkSP = 0x47E0F178, PC = 0x00000008, literals = 0x00000004, A0 = 0x47E0F1A4, j2iFrame = 0x47E0F200, ELS = 0x42258808, decomp = 0x00000000
<414f1e00> MethodType frame: bp = 0x47E0F194, sp = 0x47E0F178, pc = 0x00000008, cp = 0x00000000, arg0EA = 0x47E0F1A4, flags = 0x00000000
<414f1e00>  Object pushes starting at 0x47E0F178 for 1 slots
<414f1e00>      Push[0x47E0F178] = 0x1C9152E0
<414f1e00>      O-Slot[0x1CA7ECA8] = 0x3D5A2500 <-----
<414f1e00>      O-Slot: a0[0x47E0F1A4] = 0x38B2B048
<414f1e00>      I-Slot: a1[0x47E0F1A0] = 0x00000000
<414f1e00>      I-Slot: a2[0x47E0F19C] = 0x00000000
<414f1e00> invokeExact J2I frame: bp = 0x47E0F200, sp = 0x47E0F1A8, pc = 0x19EF7264, cp = 0x00000000, arg0EA = 0x47E0F200, flags = 0x10000000
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1F0] = UDATA(0x38B2B070) (jit_r6)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1EC] = UDATA(0x1CA7ECA8) (jit_r7)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1E8] = UDATA(0x1C9BD620) (jit_r8)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1E4] = UDATA(0x1A1B49D8) (jit_r9)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1E0] = UDATA(0x00000000) (jit_r10)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1DC] = UDATA(0x00000000) (jit_r11)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1D8] = UDATA(0x3D34D400) (jit_r12)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1D4] = UDATA(0x3E4EB300) (jit_r22)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1D0] = UDATA(0x00000000) (jit_r23)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1CC] = UDATA(0x00000000) (jit_r24)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1C8] = UDATA(0x00000000) (jit_r25)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1C4] = UDATA(0x00000000) (jit_r26)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1C0] = UDATA(0x0000005E) (jit_r27)
<414f1e00>  JIT-J2I-RegisterMap[0x47E0F1BC] = UDATA(0x00100000) (jit_r28)
<414f1e00> JIT frame: bp = 0x47E0F26C, pc = 0x49FFEE74, unwindSP = 0x47E0F1F8, cp = 0x3E6132F0, arg0EA = 0x47E0F274, jitInfo = 0x49C7F1C8
<414f1e00>  Method: com/ibm/jtc/svt/tests/invoke/StaticAsTypeTestExplicit.testConvertLong(J)V !j9method 0x3E6143A0
<414f1e00>  Bytecode index = 632, inlineDepth = 0, PC offset = 0x0000067C
<414f1e00>  stackMap=0x49C7FF9C, slots=I16(0x0002) parmBaseOffset=I16(0x000C), parmSlots=U16(0x0000), localBaseOffset=I16(0xFFEC)
<414f1e00>  Described JIT temps starting at 0x47E0F258 for IDATA(0x00000005) slots
......

> !stackslots 0x45a29200
<45a29200> *** BEGIN STACK WALK, flags = 00400001 walkThread = 0x45A29200 ***
<45a29200>  ITERATE_O_SLOTS
<45a29200>  RECORD_BYTECODE_PC_OFFSET
<45a29200> Initial values: walkSP = 0x480C1680, PC = 0x00000008, literals = 0x00000004, A0 = 0x480C16AC, j2iFrame = 0x480C1708, ELS = 0x45F92808, decomp = 0x00000000
<45a29200> MethodType frame: bp = 0x480C169C, sp = 0x480C1680, pc = 0x00000008, cp = 0x00000000, arg0EA = 0x480C16AC, flags = 0x00000000
<45a29200>  Object pushes starting at 0x480C1680 for 1 slots
<45a29200>      Push[0x480C1680] = 0x1C9152E0
<45a29200>      O-Slot[0x1CA7ECA8] = 0x3D5A2500 <-----
<45a29200>      O-Slot: a0[0x480C16AC] = 0x38B47D30
<45a29200>      I-Slot: a1[0x480C16A8] = 0x00000000
<45a29200>      I-Slot: a2[0x480C16A4] = 0x00000000
<45a29200> invokeExact J2I frame: bp = 0x480C1708, sp = 0x480C16B0, pc = 0x19EF7264, cp = 0x00000000, arg0EA = 0x480C1708, flags = 0x10000000
<45a29200>  JIT-J2I-RegisterMap[0x480C16F8] = UDATA(0x38B47D58) (jit_r6)
<45a29200>  JIT-J2I-RegisterMap[0x480C16F4] = UDATA(0x1CA7ECA8) (jit_r7)
<45a29200>  JIT-J2I-RegisterMap[0x480C16F0] = UDATA(0x1C9BD620) (jit_r8)
<45a29200>  JIT-J2I-RegisterMap[0x480C16EC] = UDATA(0x1A1B49D8) (jit_r9)
<45a29200>  JIT-J2I-RegisterMap[0x480C16E8] = UDATA(0x00000000) (jit_r10)
<45a29200>  JIT-J2I-RegisterMap[0x480C16E4] = UDATA(0x00000000) (jit_r11)
<45a29200>  JIT-J2I-RegisterMap[0x480C16E0] = UDATA(0x3EC95BA8) (jit_r12)
<45a29200>  JIT-J2I-RegisterMap[0x480C16DC] = UDATA(0x00000000) (jit_r22)
<45a29200>  JIT-J2I-RegisterMap[0x480C16D8] = UDATA(0x00000000) (jit_r23)
<45a29200>  JIT-J2I-RegisterMap[0x480C16D4] = UDATA(0x00000000) (jit_r24)
<45a29200>  JIT-J2I-RegisterMap[0x480C16D0] = UDATA(0x00000000) (jit_r25)
<45a29200>  JIT-J2I-RegisterMap[0x480C16CC] = UDATA(0x00000000) (jit_r26)
<45a29200>  JIT-J2I-RegisterMap[0x480C16C8] = UDATA(0x00000000) (jit_r27)
<45a29200>  JIT-J2I-RegisterMap[0x480C16C4] = UDATA(0x00100000) (jit_r28)
<45a29200> JIT frame: bp = 0x480C1774, pc = 0x49FFEE74, unwindSP = 0x480C1700, cp = 0x3E6132F0, arg0EA = 0x480C177C, jitInfo = 0x49C7F1C8
<45a29200>  Method: com/ibm/jtc/svt/tests/invoke/StaticAsTypeTestExplicit.testConvertLong(J)V !j9method 0x3E6143A0
<45a29200>  Bytecode index = 632, inlineDepth = 0, PC offset = 0x0000067C
<45a29200>  stackMap=0x49C7FF9C, slots=I16(0x0002) parmBaseOffset=I16(0x000C), parmSlots=U16(0x0000), localBaseOffset=I16(0xFFEC)
<45a29200>  Described JIT temps starting at 0x480C1760 for IDATA(0x00000005) slots

!j9class 0x3D5A2500 is a class for java/lang/invoke/MethodType