Spring app fails on OpenJ9 with a profiler with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" #5676

AntonKatilin · 2019-05-06T10:35:46Z

A Spring application fails with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" on latest OpenJ9 Java 8 and Java 12 when started with YourKit Java Profiler agent's default instrumentation.

There is no issue with HotSpot in the same configuration, therefore we suppose there might be a JVM bug. Could you please check whether it's a JVM bug or, if the bytecode is indeed invalid, share detail on what's wrong with it.

How to reproduce:

Create this Spring app:

import org.springframework.aop.framework.ProxyFactory;

public class Target {
  public static void main(final String[] args) {
    final ProxyFactory proxyFactory = new ProxyFactory(new Target());
    proxyFactory.setProxyTargetClass(true);
    proxyFactory.getProxy();
  }
}

Normally, it should start on OpenJ9 without any issues except for some non critical access warnings on Java 12.

Get the latest YourKit Java Profiler agent by downloading and unpacking https://www.yourkit.com/download/docker/YourKit-JavaProfiler-2019.1-docker.zip . The ZIP contains agents for Linux and Windows. No key is needed.
Start the example with -agentpath: to let it fail on "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent".

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

DanHeidinga · 2019-05-06T12:50:45Z

@ChengJin01 Can you take a look at this?

ChengJin01 · 2019-05-06T13:45:15Z

Will investigate to see what happened to the app.

ChengJin01 · 2019-05-06T20:53:52Z

I already reproduced the issue locally on OpenJ9:

jdk-12.0.1_12_openj9/bin/java  -agentpath:YourKit-JavaProfiler-2019.1/bin/linux-x86-64/libyjpagent.so   -cp .:spring-aop-5.16.jar:spring-core-5.1.6.jar:commons-logging-1.2.jar -Xint  Target
[YourKit Java Profiler 2019.1-b117] Log file: /home/jincheng/.yjp/log/Target-25573.log
Exception in thread "main" org.springframework.aop.framework.AopConfigException: Unexpected AOP exception; nested exception is java.lang.IllegalStateException: Unable to load cache item
	at org.springframework.aop.framework.CglibAopProxy.getProxy(CglibAopProxy.java:214)
	at org.springframework.aop.framework.CglibAopProxy.getProxy(CglibAopProxy.java:155)
	at org.springframework.aop.framework.ProxyFactory.getProxy(ProxyFactory.java:97)
	at Target.main(Target.java:7)
Caused by: java.lang.IllegalStateException: Unable to load cache item
	at org.springframework.cglib.core.internal.LoadingCache.createEntry(LoadingCache.java:79)
	at org.springframework.cglib.core.internal.LoadingCache.get(LoadingCache.java:34)
	at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData.get(AbstractClassGenerator.java:134)
	at org.springframework.cglib.core.AbstractClassGenerator.create(AbstractClassGenerator.java:319)
	at org.springframework.cglib.proxy.Enhancer.createHelper(Enhancer.java:569)
	at org.springframework.cglib.proxy.Enhancer.createClass(Enhancer.java:416)
	at org.springframework.aop.framework.ObjenesisCglibAopProxy.createProxyClassAndInstance(ObjenesisCglibAopProxy.java:57)
	at org.springframework.aop.framework.CglibAopProxy.getProxy(CglibAopProxy.java:205)
	... 3 more
Caused by: java.lang.VerifyError: JVMVRFY012 stack shape inconsistent; 
class=Target$$EnhancerBySpringCGLIB$$fdc9b9d7, method=<init>()V, pc=14  <-----------
	at java.base/java.lang.Class.forNameImpl(Native Method)
	at java.base/java.lang.Class.forName(Class.java:415)
	at org.springframework.cglib.core.ReflectUtils.defineClass(ReflectUtils.java:563)
	at org.springframework.cglib.core.AbstractClassGenerator.generate(AbstractClassGenerator.java:363)
	at org.springframework.cglib.proxy.Enhancer.generate(Enhancer.java:582)
	at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData$3.apply(AbstractClassGenerator.java:110)
	at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData$3.apply(AbstractClassGenerator.java:108)
	at org.springframework.cglib.core.internal.LoadingCache$2.call(LoadingCache.java:54)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at org.springframework.cglib.core.internal.LoadingCache.createEntry(LoadingCache.java:61)
	... 10 more

and it works fine with OpenJDK:

jdk-12.0.1_12_hotspot/bin/java -version
openjdk version "12.0.1" 2019-04-16
OpenJDK Runtime Environment AdoptOpenJDK (build 12.0.1+12)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 12.0.1+12, mixed mode, sharing)

../jdk-12.0.1_12_hotspot/bin/java  -agentpath:/home/jincheng/issues_2019/5676_bcv_spring/YourKit-JavaProfiler-2019.1/bin/linux-x86-64/libyjpagent.so   -cp .:spring-aop-5.16.jar:spring-core-5.1.6.jar:commons-logging-1.2.jar  -Xint  Target
[YourKit Java Profiler 2019.1-b117] Log file: .../.yjp/log/Target-25622.log

@AntonKatilin, please help to confirm whether this is the same verification error detected on your side.

ChengJin01 · 2019-05-06T20:58:13Z

The snaptrace shows it failed at an <init> method of a generated class Target$$EnhancerBySpringCGLIB$$fdc9b9d7 at runtime verification:

17:06:09.052425000  0x0000000000efe700 j9vm.2              Exit       <Created RAM class 0x12dc900 from ROM class 0x7f83d4e88eb0
17:06:09.052482000  0x0000000000efe700 j9bcverify(j9vm).107 Entry      >j9bcv_verifyBytecodes - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 
17:06:09.053001000  0x0000000000efe700 j9bcverify(j9vm).29 Exception  * verifyBytecodes - verifyError 0xc, method <init>()V, pc = 0xe
17:06:09.053001000  0x0000000000efe700 j9bcverify(j9vm).68 Exception  * verifyBytecodes - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V error 0xc, at offset 14(0xe), bytecode = 0xdf
17:06:09.053002000  0x0000000000efe700 j9bcverify(j9vm).28 Exception  * j9rtv_verifyBytecodes - verifyError 0xc, method 0xe
17:06:09.053002000  0x0000000000efe700 j9bcverify(j9vm).111 Exit       <j9bcv_verifyBytecodes - returning -1

Given that the DDR got corrupted when decoding some of the methods (including ) on this class, I need to add debugging information in code to see how it goes.

AntonKatilin · 2019-05-06T21:24:45Z

please help to confirm whether this is the same verification error detected on your side.

I confirm this is exactly the issue we've experienced.

AntonKatilin · 2019-05-06T21:30:47Z

If it helps, we found that specifying -Xverify:none eliminates the exception, and the application seems to work normally with that option specified. So it may be a too-strict-check issue.

ChengJin01 · 2019-05-06T22:03:18Z

If it helps, we found that specifying -Xverify:none eliminates the exception, and the application seems to work normally with that option specified. So it may be a too-strict-check issue.

Specifying -Xverify:none disables the verifier at runtime. So we still need to figure out why it failed in such case.

AntonKatilin · 2019-05-06T22:10:56Z

Yes, sure. We understand what -Xverify:none does. Just wanted to let you know.

ChengJin01 · 2019-05-07T22:48:40Z

Looking at the bytecode of the failing method Target$$EnhancerBySpringCGLIB$$fdc9b9d7.<init>()V:

Signature: Target$$EnhancerBySpringCGLIB$$fdc9b9d7.<init>()V !bytecodes 0x00000000012D2F60 <-----------
ROM Method: !j9rommethod 0x00007F83D4E8B2F4
Next Method: !j9method 0x00000000012D2F80

> bytecodes 0x00000000012D2F60
  Name: <init>
  Signature: ()V
  Access Flags (20001): public 
  Max Stack: 15
  Caught Exceptions (4):
     start   end   handler   catch type
     -----   ---   -------   ----------
     23  37  37   (any)
     18  41  41   java/lang/RuntimeException
     18  41  41   java/lang/Error
     18  41  42   java/lang/Throwable
  Argument Count: 1
  Temp Count: 3

    0 iconstm1 
    1 istorew 1
    5 ldcw 158 (int/float) 0x00003EA4
    8 ldc2lw 238 (long) 0x00007F83A03D1450
   11 invokestatic 118 com/yourkit/runtime/Callback.yjpMethodEntry(IJ)J
   14 lstorew 2
   18 aload0  <------------- failed here when calling matchStack for the next stack map
   19 dup 
   20 invokespecial 94 Target.<init>()V
   23 invokestatic 28 Target$$EnhancerBySpringCGLIB$$fdc9b9d7.CGLIB$BIND_CALLBACKS(Ljava/lang/Object;)V
   26 ldcw 158 (int/float) 0x00003EA4
   29 lloadw 2
   33 invokestatic 119 com/yourkit/runtime/Callback.yjpMethodExit(IJ)V
   36 genericReturn 
   37 invokestatic 116 com/yourkit/probes/builtin/CpuTracingSupport.onUncaughtException()V
   40 athrow 
   41 athrow 
   42 new 37 java/lang/reflect/UndeclaredThrowableException
   45 dupx1 
   46 swap 
   47 invokespecial 38 java/lang/reflect/UndeclaredThrowableException.<init>(Ljava/lang/Throwable;)V
   50 dup 
   51 iloadw 1
   55 ldcw 127 (int/float) 0x000010C1
   58 sipush 0
   61 ldc2lw 239 (long) 0x00007F83D4DC43A8
   64 invokestatic 120 com/yourkit/runtime/Callback.yjpInit(Ljava/lang/Object;IISJ)I
   67 istorew 1
   71 nop 
   72 nop 
   73 nop 
   74 athrow

against the detailed snaptrace on the verifier:

 j9bcverify(j9vm).31 Exit       <j9rtv_verifyBytecodes
 j9bcverify(j9vm).108 Event       j9bcv_verifyBytecodes - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V method modifiers 0x20001
 j9bcverify(j9vm).78 Event       buildBranchMap - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V branchCount = 3
 
 j9bcverify(j9vm).1  Entry      >simulateStack
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 41(0x29)
 j9bcverify(j9vm).95 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V copy stack to stack 1 at target PC = 41(0x29), queue for unwalked
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 41(0x29)
 j9bcverify(j9vm).97 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to stack 1 at target PC = 41(0x29)
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/RuntimeException
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/RuntimeException
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Error
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Error
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/RuntimeException
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).91 Event       mergeObjectTypes - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge source class java/lang/Error with target class java/lang/RuntimeException to class java/lang/Throwable (0x2)
 j9bcverify(j9vm).93 Event       mergeObjectTypes - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merged class 0x40 - rewalk
 j9bcverify(j9vm).100 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V changed stack at target PC = 41(0x29), queue for rewalk
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 42(0x2a)
 j9bcverify(j9vm).95 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V copy stack to stack 2 at target PC = 42(0x2a), queue for unwalked
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 37(0x25)
 j9bcverify(j9vm).95 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V copy stack to stack 0 at target PC = 37(0x25), queue for unwalked
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 41(0x29)
 j9bcverify(j9vm).97 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to stack 1 at target PC = 41(0x29)
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/RuntimeException
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 41(0x29)
 j9bcverify(j9vm).97 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to stack 1 at target PC = 41(0x29)
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Error
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 42(0x2a)
 j9bcverify(j9vm).97 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to stack 2 at target PC = 42(0x2a)
 j9bcverify(j9vm).100 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V changed stack at target PC = 42(0x2a), queue for rewalk
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).103 Event       simulateStack - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V stopped at offset 36(0x24), new walk from offset 37(0x25)
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 41(0x29)
 j9bcverify(j9vm).97 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to stack 1 at target PC = 41(0x29)
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/RuntimeException
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 41(0x29)
 j9bcverify(j9vm).97 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to stack 1 at target PC = 41(0x29)
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Throwable
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).24 Entry      >verifierGetRAMClass - class loader 0x9807a720, class: java/lang/Error
 j9bcverify(j9vm).25 Event       verifierGetRAMClass - class already loaded
 j9bcverify(j9vm).27 Exit       <verifierGetRAMClass
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).94 Entry      >mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to target PC = 42(0x2a)
 j9bcverify(j9vm).97 Event       mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V merge to stack 2 at target PC = 42(0x2a)
 j9bcverify(j9vm).101 Exit       <mergeStacks - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V returning 0
 j9bcverify(j9vm).104 Event       simulateStack - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V stopped at offset 40(0x28), rewalk from offset 41(0x29)
 j9bcverify(j9vm).104 Event       simulateStack - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V stopped at offset 41(0x29), rewalk from offset 42(0x2a)
 j9bcverify(j9vm).4  Exit       <simulateStack

 j9bcverify(j9vm).30 Entry      >j9rtv_verifyBytecodes - class: Target$$EnhancerBySpringCGLIB$$fdc9b9d7
 j9bcverify(j9vm).32 Entry      >verifyBytecodes - method: <init>()V
 j9bcverify(j9vm).75 Event       nextStack - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V stackMapsCount = 3, nextMapIndex = 1, nextStackPC = 37 of 75
 j9bcverify(j9vm).76 Event       nextExceptionStart - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V catchCount = 4, lastPC = -1, nextPC = 18 of 75
 j9bcverify(j9vm).69 Entry      >j9rtv_verifyArguments - signature (IJ)J
 j9bcverify(j9vm).74 Exit       <j9rtv_verifyArguments - returning 0
 j9bcverify(j9vm).59 Entry      >findAndMatchStack - match stack from 14 to stack at 41
 j9bcverify(j9vm).62 Entry      >matchStack - inlineMatch is 0
 j9bcverify(j9vm).67 Exit       <matchStack - returning 1  <------ failed due to the incorrect uninitializedThis flag in the stacmap frame
 j9bcverify(j9vm).61 Exit       <findAndMatchStack - returning 1
 j9bcverify(j9vm).29 Exception  * verifyBytecodes - verifyError 0xc, method <init>()V, pc = 0xe
 j9bcverify(j9vm).68 Exception  * verifyBytecodes - Target$$EnhancerBySpringCGLIB$$fdc9b9d7 <init>()V error 0xc, at offset 14(0xe), bytecode = 0xdf
 j9bcverify(j9vm).28 Exception  * j9rtv_verifyBytecodes - verifyError 0xc, method 0xe
 j9bcverify(j9vm).31 Exit       <j9rtv_verifyBytecodes
 j9bcverify(j9vm).111 Exit       <j9bcv_verifyBytecodes - returning -1

It shows it failed in matchStack() at:

static IDATA 
matchStack(J9BytecodeVerificationData * verifyData, J9BranchTargetStack *liveStack, J9BranchTargetStack * targetStack, UDATA inlineMatch)
{
...
	/* Target stack frame flag needs to be subset of ours. See JVM sepc 4.10.1.4 */
	if (liveStack->uninitializedThis && !targetStack->uninitializedThis) {
		rc = BCV_FAIL;  <-------------------- failed here (confirmed by the printing message)
		goto _finished;
	}

Given that the stackmap of the constructor method was built via simulateStack (already shown in the snaptrace above), it is likely there is problem dealing with BCV_SPECIAL_INIT (used to set up the uninitializedThis flag) in simulateStack / mergeStacks.

ChengJin01 · 2019-05-07T23:09:51Z

Specifically, the failure occurred when checking the stack against the exception handler stack as follows:

verifyBytecodes (J9BytecodeVerificationData * verifyData)
{
...
	while (pc < length) {
		/* Check the stack against the exception handler stack */
		if (pc == (UDATA) nextExceptionStartPC) {
			handler = J9EXCEPTIONINFO_HANDLERS(exceptionInfo);
			SAVE_STACKTOP(liveStack, stackTop);

			/* Save the current liveStack element zero */
			/* Reset the stack pointer and push the exception on the empty stack */
			originalStackTop = stackTop;
			originalStackZeroEntry = liveStack->stackElements[liveStack->stackBaseIndex];

			/* Find all exception handlers from here */
			for (i = exceptionInfo->catchCount; i; i--, handler++) {
				if (handler->startPC == pc) {
					/* Check the maps at the handler PC */
					/* Modify the liveStack temporarily to contain the handler exception */
					if (handler->exceptionClassIndex) {
						catchName = J9ROMSTRINGREF_UTF8DATA((J9ROMStringRef *)(&constantPool [handler->exceptionClassIndex]));
						catchClass = convertClassNameToStackMapType(verifyData, J9UTF8_DATA(catchName), J9UTF8_LENGTH(catchName), 0, 0);
					} else {
						catchClass = BCV_JAVA_LANG_THROWABLE_INDEX;
						catchClass <<= BCV_CLASS_INDEX_SHIFT;
					}

					/* Empty the stack */
					stackTop = &(liveStack->stackElements[liveStack->stackBaseIndex]);
					PUSH(catchClass);
					SAVE_STACKTOP(liveStack, stackTop);

     rc = findAndMatchStack (verifyData, handler->handlerPC, start); <--- BCV_FAIL returned from matchStack
					if (BCV_SUCCESS != rc) {
						if (BCV_ERR_INSUFFICIENT_MEMORY == rc) {
							goto _outOfMemoryError;
						}
						goto _mapError;  <----------------------
					}
				}
			}

ChengJin01 · 2019-05-08T23:07:09Z

Debugging message in code shows it failed on java/lang/RuntimeException

  Name: <init>
  Signature: ()V
  Access Flags (20001): public 
  Max Stack: 15
  Caught Exceptions (4):
     start   end   handler   catch type
     -----   ---   -------   ----------
     23       37    37         (any)
     18       41    41         java/lang/RuntimeException <--------- failed at this handler
     18       41    41         java/lang/Error
     18       41    42         java/lang/Throwable
  Argument Count: 1
  Temp Count: 3

verifyBytecodes: matchStack failed: BCV_FAIL: exceptionInfo->catchCount = 4, i = 3, 
exceptionClassIndex = 34, nextExceptionStartPC = 18, 
pc = 18, handler->startPC = 18,  handler->handlerPC = 41, 
stackIndex = 1, catchName = java/lang/RuntimeException

According to the logic in setInitializedThisStatus (against the Spec), the uninitializedThis flag is set to true if any slot element (including the data in both locals and stacks) in the stackmape frame contains BCV_SPECIAL_INIT (0x4) (means the map's stack contains an uninitialized_this object) after generating the requested stackmap via simulateStack .

However, the debugging message shows there is no such element in the failing stackmap frame for java/lang/RuntimeException (even in the whole stackmap)

setInitializedThisStatus: currentMapIndex =0, currentStack->stackElements[]: pc = 37, stackBaseIndex = 4, stackTopIndex = 5
[0]=288 [1]=33 [2]=129 [3]=1 [4]=64 , currentStack->uninitializedThis = 0

setInitializedThisStatus: currentMapIndex =1, currentStack->stackElements[]: pc = 41, stackBaseIndex = 4, stackTopIndex = 5
[0]=1 [1]=33 [2]=129 [3]=1 [4]=64 , currentStack->uninitializedThis = 0  <------ no element containing BCV_SPECIAL_INIT  

setInitializedThisStatus: currentMapIndex =2, currentStack->stackElements[]: pc = 42, stackBaseIndex = 4, stackTopIndex = 5
[0]=1 [1]=33 [2]=129 [3]=1 [4]=64 , currentStack->uninitializedThis = 0

Given that the first element in the stackmap frame should contain BCV_SPECIAL_INIT in the case of the <init> method, I need to double-check the code in mergeStacks to see whether anything went wrong in merging the stack.

ChengJin01 · 2019-05-09T22:33:11Z

It seems there is no issue with simulateStack / mergeStacks. I need to get back to check where it failed as the existing code there was modified for the flag check specific to the case of invokespecial and exception handlers.

ChengJin01 · 2019-05-10T00:36:20Z

The check on the uninitializedThis flag in our code only applied to the class file with stackmaps (since Java 7 /class version = 51). In this case, such check should be ignored for class file without stackmaps (the class version is 46 < 51) ,

> dumpromclass  0x00007F83D4E88EB0
ROM Size: 0x2e70 (11888)
Class Name: Target$$EnhancerBySpringCGLIB$$fdc9b9d7
Superclass Name: Target
Source File Name: <generated>
Sun Access Flags (0x1): public 
J9  Access Flags (0xc100000): 
Class file version: 46.0   <----------------------------

That's explains why the test program above passed on Hotspot as the check gets used since Java 7.
It also works for our code after disabling the check on the generated stackmaps.

matchStack(...)
{
...
if (!verifyData->createdStackMap  <------
&& liveStack->uninitializedThis && !targetStack->uninitializedThis) 
{ 
...}

The change is to disable the check on the uninitializedThis flag on old version classfiles (< 51) as such check is only applied to classfiles with stackmaps which was introduced since Java 7(class version is 51). Fix: eclipse-openj9#5676 Signed-off-by: Cheng Jin <jincheng@ca.ibm.com>

jgeekgd · 2022-04-28T02:51:13Z

This issue is coming in openjdk 17-

Apr 28, 2022 8:20:51 AM org.springframework.context.annotation.AnnotationConfigApplicationContext prepareRefresh
INFO: Refreshing org.springframework.context.annotation.AnnotationConfigApplicationContext@b1a58a3: startup date [Thu Apr 28 08:20:51 IST 2022]; root of context hierarchy
Exception in thread "main" java.lang.IllegalStateException: Cannot load configuration class: com.gd.config.AppConfig
at org.springframework.context.annotation.ConfigurationClassPostProcessor.enhanceConfigurationClasses(ConfigurationClassPostProcessor.java:403)
at org.springframework.context.annotation.ConfigurationClassPostProcessor.postProcessBeanFactory(ConfigurationClassPostProcessor.java:249)
at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:281)
at org.springframework.context.support.PostProcessorRegistrationDelegate.invokeBeanFactoryPostProcessors(PostProcessorRegistrationDelegate.java:125)
at org.springframework.context.support.AbstractApplicationContext.invokeBeanFactoryPostProcessors(AbstractApplicationContext.java:686)
at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:524)
at com.gd.client.MainClasss.main(MainClasss.java:15)
Caused by: java.lang.ExceptionInInitializerError
at org.springframework.context.annotation.ConfigurationClassEnhancer.newEnhancer(ConfigurationClassEnhancer.java:122)
at org.springframework.context.annotation.ConfigurationClassEnhancer.enhance(ConfigurationClassEnhancer.java:110)
at org.springframework.context.annotation.ConfigurationClassPostProcessor.enhanceConfigurationClasses(ConfigurationClassPostProcessor.java:393)
... 6 more
Caused by: java.lang.IllegalStateException: Unable to load cache item
at org.springframework.cglib.core.internal.LoadingCache.createEntry(LoadingCache.java:79)
at org.springframework.cglib.core.internal.LoadingCache.get(LoadingCache.java:34)
at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData.get(AbstractClassGenerator.java:116)
at org.springframework.cglib.core.AbstractClassGenerator.create(AbstractClassGenerator.java:291)
at org.springframework.cglib.core.KeyFactory$Generator.create(KeyFactory.java:221)
at org.springframework.cglib.core.KeyFactory.create(KeyFactory.java:174)
at org.springframework.cglib.core.KeyFactory.create(KeyFactory.java:153)
at org.springframework.cglib.proxy.Enhancer.(Enhancer.java:73)
... 9 more
Caused by: java.lang.ExceptionInInitializerError
at org.springframework.cglib.core.KeyFactory$Generator.generateClass(KeyFactory.java:243)
at org.springframework.cglib.core.DefaultGeneratorStrategy.generate(DefaultGeneratorStrategy.java:25)
at org.springframework.cglib.core.AbstractClassGenerator.generate(AbstractClassGenerator.java:329)
at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData$3.apply(AbstractClassGenerator.java:93)
at org.springframework.cglib.core.AbstractClassGenerator$ClassLoaderData$3.apply(AbstractClassGenerator.java:91)
at org.springframework.cglib.core.internal.LoadingCache$2.call(LoadingCache.java:54)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at org.springframework.cglib.core.internal.LoadingCache.createEntry(LoadingCache.java:61)
... 16 more
Caused by: java.lang.reflect.InaccessibleObjectException: Unable to make protected final java.lang.Class java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain) throws java.lang.ClassFormatError accessible: module java.base does not "opens java.lang" to unnamed module @42d3bd8b
at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:354)
at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:297)
at java.base/java.lang.reflect.Method.checkCanSetAccessible(Method.java:199)
at java.base/java.lang.reflect.Method.setAccessible(Method.java:193)
at org.springframework.cglib.core.ReflectUtils$1.run(ReflectUtils.java:54)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:318)
at org.springframework.cglib.core.ReflectUtils.(ReflectUtils.java:44)
... 24 more

ChengJin01 · 2022-04-28T03:16:51Z

Hi @gangadharparde, there is no evidence indicating the exception above was the same as the original issue (even though it occurred in the springframework) in that the fix here was to resolve the VerifyError specific problem in the runtime verification prior to the execution, which was different from ClassFormatError in the static verification when loading classes

You'd better double-check and open a new issue with the complete error messages plus the steps to reproduce the issue for our investigation.

ChengJin01 · 2022-04-28T03:20:41Z

According to the error message above:

Caused by: java.lang.reflect.InaccessibleObjectException: 
Unable to make protected final java.lang.Class java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain) 
throws java.lang.ClassFormatError accessible: module java.base does not "opens java.lang" to unnamed module @42d3bd8b
...
at java.base/java.security.AccessController.doPrivileged(AccessController.java:318)

it looks like there was some module specific access issue from the package opens java.lang in the module java.base to unnamed module.

FYI: @JasonFengJ9

JasonFengJ9 · 2022-04-28T11:40:51Z

@gangadharparde pls try --add-opens java.base/java.lang=ALL-UNNAMED.

pshipton added the userRaised label May 6, 2019

DanHeidinga added this to the Release 0.15 (Java 8, 11, 12) July refresh milestone May 6, 2019

pshipton added the backport:candidate Possible candidate for a backport to a `0.x.y+1` release label May 7, 2019

ChengJin01 mentioned this issue May 10, 2019

Disable the flag check on method without stackmaps #5736

Merged

ChengJin01 mentioned this issue May 12, 2019

(v0.14.2) Disable the flag check on method without stackmaps #5740

Merged

DanHeidinga closed this as completed in #5736 May 12, 2019

pshipton removed the backport:candidate Possible candidate for a backport to a `0.x.y+1` release label May 13, 2019

pshipton modified the milestones: Release 0.15 (Java 8, 11, 12) July refresh, Release 0.14.2 (Java 8, 11, 12) Bug fixes May 13, 2019

ChengJin01 mentioned this issue Apr 29, 2020

J9(1.8.0_232) and J9(11.0.5): failed to throw VerifyError? #9385

Closed

ChengJin01 mentioned this issue Apr 30, 2020

Add the check of BCV_SPECIAL in generating stackmaps #9419

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Spring app fails on OpenJ9 with a profiler with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" #5676

Spring app fails on OpenJ9 with a profiler with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" #5676

AntonKatilin commented May 6, 2019 •

edited by fjeremic

DanHeidinga commented May 6, 2019

ChengJin01 commented May 6, 2019

ChengJin01 commented May 6, 2019 •

edited

ChengJin01 commented May 6, 2019 •

edited

AntonKatilin commented May 6, 2019 •

edited

AntonKatilin commented May 6, 2019 •

edited

ChengJin01 commented May 6, 2019 •

edited

AntonKatilin commented May 6, 2019

ChengJin01 commented May 7, 2019 •

edited

ChengJin01 commented May 7, 2019 •

edited

ChengJin01 commented May 8, 2019 •

edited

ChengJin01 commented May 9, 2019 •

edited

ChengJin01 commented May 10, 2019 •

edited

jgeekgd commented Apr 28, 2022

ChengJin01 commented Apr 28, 2022

ChengJin01 commented Apr 28, 2022 •

edited

JasonFengJ9 commented Apr 28, 2022

Spring app fails on OpenJ9 with a profiler with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" #5676

Spring app fails on OpenJ9 with a profiler with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" #5676

Comments

AntonKatilin commented May 6, 2019 • edited by fjeremic

DanHeidinga commented May 6, 2019

ChengJin01 commented May 6, 2019

ChengJin01 commented May 6, 2019 • edited

ChengJin01 commented May 6, 2019 • edited

AntonKatilin commented May 6, 2019 • edited

AntonKatilin commented May 6, 2019 • edited

ChengJin01 commented May 6, 2019 • edited

AntonKatilin commented May 6, 2019

ChengJin01 commented May 7, 2019 • edited

ChengJin01 commented May 7, 2019 • edited

ChengJin01 commented May 8, 2019 • edited

ChengJin01 commented May 9, 2019 • edited

ChengJin01 commented May 10, 2019 • edited

jgeekgd commented Apr 28, 2022

ChengJin01 commented Apr 28, 2022

ChengJin01 commented Apr 28, 2022 • edited

JasonFengJ9 commented Apr 28, 2022

AntonKatilin commented May 6, 2019 •

edited by fjeremic

ChengJin01 commented May 6, 2019 •

edited

ChengJin01 commented May 6, 2019 •

edited

AntonKatilin commented May 6, 2019 •

edited

AntonKatilin commented May 6, 2019 •

edited

ChengJin01 commented May 6, 2019 •

edited

ChengJin01 commented May 7, 2019 •

edited

ChengJin01 commented May 7, 2019 •

edited

ChengJin01 commented May 8, 2019 •

edited

ChengJin01 commented May 9, 2019 •

edited

ChengJin01 commented May 10, 2019 •

edited

ChengJin01 commented Apr 28, 2022 •

edited