Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
fuzzy000 opened this issue Apr 28, 2020 · 13 comments · Fixed by #9419
Closed

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

fuzzy000 opened this issue Apr 28, 2020 · 13 comments · Fixed by #9419

Comments

@fuzzy000
Copy link

Java -version output

The issue happened in following versions:

openjdk version "1.8.0_232"
OpenJDK Runtime Environment (build 1.8.0_232-b09)
Eclipse OpenJ9 VM (build openj9-0.17.0, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20191017_442 (JIT enabled, AOT enabled)
OpenJ9   - 77c1cf708
OMR      - 20db4fbc
JCL      - 97b5ec8f383 based on jdk8u232-b09)
openjdk version "11.0.5" 2019-10-15
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.5+10)
Eclipse OpenJ9 VM AdoptOpenJDK (build openj9-0.17.0, JRE 11 Linux amd64-64-Bit Compressed References 20191016_358 (JIT enabled, AOT enabled)
OpenJ9   - 77c1cf708
OMR      - 20db4fbc
JCL      - 2a7af5674b based on jdk-11.0.5+10)

Summary of problem

We made some changes to a class file in the JUnit project (org.junit.internal.runners.ErrorReportingRunner), and let several JVMs run the corresponding test file (org.junit.internal.runners.ErrorReportingRunnerTest). Here we only kept two JUnit tests in the test file to focus on the issue.

OpenJDK(1.8.0_232) OpenJDK(9.0.4) OpenJDK(11.0.5)
1) VerifyError
2) VerifyError
1) VerifyError
2) VerifyError
1) VerifyError
2) VerifyError
J9(1.8.0_232) J9(9.0.4) J9(11.0.5)
1) NullPointerException
2) IllegalArgumentException
1) VerifyError
2) VerifyError
1) NullPointerException
2) IllegalArgumentException

OpenJDK series throws VerifyError, which was caused by the class ErrorReportingRunner. It looks like J9(1.8.0_232) and J9(11.0.5) just wrongly take the class ErrorReportingRunner as a valid class file and execute the tests.

There is also a discrepancy in the behaviors of J9(9.0.4) and J9(1.8.0_232), J9(11.0.5). Maybe there are some problems in the verification part of those VMs?

Diagnostic files

ErrorReportingRunnerTest.zip

  1. Extract it
  2. In directory ErrorReportingRunnerTest, run command java -cp sootOutput/junit-junit/:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest

Execution environment

  • OS and version: Ubuntu 16.04.6 LTS
  • CPU model: Intel(R) Xeon(R) CPU E5-4610 v4 @ 1.80GHz
  • Number of CPU cores: 4CPUs, each has 10 cores
  • Size of physical memory: 16384 MB * 20
@DanHeidinga
Copy link
Member

@ChengJin01 can you take a look at this?

@ChengJin01
Copy link

ChengJin01 commented Apr 28, 2020

Will investigate to see what happened in there.

@ChengJin01
Copy link

ChengJin01 commented Apr 28, 2020

I reproduced the issue locally with OpenJDK11/Hotspot, OpenJDK8/OpenJ9, OpenJDK9/OpenJ9 and OpenJDK11/OpenJ9 as follows:

[1] jdk11_hotspot (VerifyError was captured on OpenJDK11/Hotspot)
$ jdk11_hotspot/bin/java -version
openjdk version "11.0.7" 2020-04-14
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.7+10)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.7+10, mixed mode)

jdk11_hotspot/bin/java -cp sootOutput/junit-junit/:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
.E.E
Time: 0.013
There were 2 failures:
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.VerifyError: (class: org/junit/internal/runners/ErrorReportingRunner, 
method: <init> signature: (Ljava/lang/Class;Ljava/lang/Throwable;)V) Constructor must call super() or this()
	at org.junit.internal.runners.ErrorReportingRunnerTest.givenInvalidTestClassErrorAsCause(ErrorReportingRunnerTest.java:50)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.VerifyError: (class: org/junit/internal/runners/ErrorReportingRunner, 
method: <init> signature: (Ljava/lang/Class;Ljava/lang/Throwable;)V) Constructor must call super() or this()
	at org.junit.runners.model.RunnerBuilder.safeRunnerForClass(RunnerBuilder.java:76)
	at org.junit.runners.model.RunnerBuilder.runners(RunnerBuilder.java:125)
	at org.junit.runners.model.RunnerBuilder.runners(RunnerBuilder.java:111)


[2] jdk8u252-b09 (VerifyError was NOT captured on OpenJDK8/OpenJ9)
$ jdk8u252-b09/bin/java  -version
openjdk version "1.8.0_252"
OpenJDK Runtime Environment (build 1.8.0_252-202004271709-b09)
Eclipse OpenJ9 VM (build master-a63afad22, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20200427_622 (JIT enabled, AOT enabled)
OpenJ9   - a63afad22
OMR      - 9b1d13cb9
JCL      - 53474073 based on jdk8u252-b09)

$ jdk8u252-b09/bin/java -cp sootOutput/junit-junit:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
...
Time: 0.019
There were 2 failures:
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.NullPointerException
	at org.junit.internal.runners.ErrorReportingRunner.run(ErrorReportingRunner.java:48)
	at org.junit.internal.runners.ErrorReportingRunnerTest.givenInvalidTestClassErrorAsCause(ErrorReportingRunnerTest.java:52)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.IllegalArgumentException: The display name must not be empty.
	at org.junit.runner.Description.<init>(Description.java:167)
	at org.junit.runner.Description.<init>(Description.java:162)


[3]jdk9_openj9_9_0_4 (VerifyError was captured on OpenJDK9/OpenJ9)

$ jdk9_openj9_9_0_4/bin/java -version
openjdk version "9.0.4-adoptopenjdk"
OpenJDK Runtime Environment (build 9.0.4-adoptopenjdk+12)
Eclipse OpenJ9 VM (build openj9-0.9.0, JRE 9 Linux amd64-64-Bit Compressed References 20180814_248 (JIT enabled, AOT enabled)
OpenJ9   - 24e53631
OMR      - fad6bf6e
JCL      - feec4d2ae based on jdk-9.0.4+12)

jdk9_openj9_9_0_4/bin/java -cp sootOutput/junit-junit:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
.E.E
Time: 0.013
There were 2 failures:
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.VerifyError: JVMVRFY012 stack shape inconsistent; 
class=org/junit/internal/runners/ErrorReportingRunner, 
method=<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V, pc=22
	at org.junit.internal.runners.ErrorReportingRunnerTest.givenInvalidTestClassErrorAsCause(ErrorReportingRunnerTest.java:50)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.VerifyError: JVMVRFY012 stack shape inconsistent; 
class=org/junit/internal/runners/ErrorReportingRunner, 
method=<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V, pc=22
	at org.junit.runners.model.RunnerBuilder.safeRunnerForClass(RunnerBuilder.java:76)
...

[4]jdk11_openj9_x86_64_04_15_2020  (VerifyError was NOT captured on OpenJDK11/OpenJ9)

$ jdk11_openj9_x86_64_04_15_2020/bin/java  -version
openjdk version "11.0.7-internal" 2020-04-14
OpenJDK Runtime Environment (build 11.0.7-internal+0-adhoc.jincheng.openj9-openjdk-jdk11x8664)
Eclipse OpenJ9 VM (build master-7067c2dfa, JRE 11 Linux amd64-64-Bit Compressed References 20200415_000000 (JIT enabled, AOT enabled)
OpenJ9   - 7067c2dfa
OMR      - f06e65669
JCL      - 163e88f282 based on jdk-11.0.7+10)

$ /home/jincheng/X86_64_OPENJ9/jdk11_openj9_x86_64_04_15_2020/bin/java -cp sootOutput/junit-junit:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
...
Time: 0.028
There were 2 failures:
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.NullPointerException
	at org.junit.internal.runners.ErrorReportingRunner.run(ErrorReportingRunner.java:48)
	at org.junit.internal.runners.ErrorReportingRunnerTest.givenInvalidTestClassErrorAsCause(ErrorReportingRunnerTest.java:52)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.IllegalArgumentException: The display name must not be empty.
	at org.junit.runner.Description.<init>(Description.java:167)
...

against the bytecode in question at:

> !j9method 0x00000000001972D0
J9Method at 0x1972d0 {
  Fields for J9Method:
	0x0: U8* bytecodes = !j9x 0x00007F89184D7FB0
	0x8: struct J9ConstantPool* constantPool = !j9constantpool 0x0000000000196810 (flags = 0x0)
	0x10: void* methodRunAddress = !j9x 0x0000000000000006
	0x18: void* extra = !j9x 0x000000000000176F
}
Signature: org/junit/internal/runners/ErrorReportingRunner.<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V !bytecodes 0x00000000001972D0
ROM Method: !j9rommethod 0x00007F89184D7F9C
Next Method: !j9method 0x00000000001972F0

!bytecodes 0x00000000013D7BA0

> !bytecodes 0x00000000001972D0
  Name: <init>
  Signature: (Ljava/lang/Class;Ljava/lang/Throwable;)V
  Access Flags (3040001): public 
  Max Stack: 3
  Argument Count: 3
  Temp Count: 3

    0 iconst5 
    1 istore 4
    3 iconst1 
    4 istore 5
    6 iconst1 
    7 anewarray 98 java/lang/Class
   10 astore3 
   11 ldcw 125 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Class,java.lang.Throwable)> **** Executed Line: **** 3 **** $r2 = newarray (java.lang.Class)[1]
   14 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   17 iinc 5 -1
   20 iload 5
   22 ifle 56
   25 iload 4
   27 iconstm1 
   28 iadd 
   29 istore 4
   31 iload 4
   33 ifge 45
   36 aload3 
   37 iconst0 
   38 aload1 
   39 aastore 
   40 ldc 53 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Class,java.lang.Throwable)> **** Executed Line: **** 4 **** $r2[0] = r3
   42 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   45 aload0 
   46 aload2 
   47 aload3 
   48 invokespecial 81 org/junit/internal/runners/ErrorReportingRunner.<init>(Ljava/lang/Throwable;[Ljava/lang/Class;)V
   51 ldc 21 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Class,java.lang.Throwable)> **** Executed Line: **** 5 **** specialinvoke r0.<org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])>(r1, $r2)
   53 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   56 nop
   57 returnFromConstructor 

Meanwhile, VerifyError never occurred if disable with -Xverify:none on OpenJDK9/OpenJ9:

$ jdk9_openj9_9_0_4/bin/java -Xverify:none -cp sootOutput/junit-junit:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
...
Time: 0.049
There were 2 failures:
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.NullPointerException
	at org.junit.internal.runners.ErrorReportingRunner.run(ErrorReportingRunner.java:48)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.IllegalArgumentException: The display name must not be empty.
	at org.junit.runner.Description.<init>(Description.java:167)
	at org.junit.runner.Description.<init>(Description.java:162)

It seems the code in verifier is likely out of sync or some new changes related to verifier were only merged for OpenJDK8 & OpenJDK11 given that only OpenJDK9/OpenJ9 captured VerifyError.

Need to further analyze to see what changes in verifier caused the issue.

@ChengJin01
Copy link

ChengJin01 commented Apr 29, 2020

Also, I tried disabling ClassRelationshipVerifier (lazy verification) & sharedclasses but still ended up with the same result:

.../jdk8u252-b09/bin/java -XX:-ClassRelationshipVerifier -Xshareclasses:none -cp sootOutput/junit-junit:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
...
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.NullPointerException
	at org.junit.internal.runners.ErrorReportingRunner.run(ErrorReportingRunner.java:48)
	at org.junit.internal.runners.ErrorReportingRunnerTest.givenInvalidTestClassErrorAsCause(ErrorReportingRunnerTest.java:52)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.IllegalArgumentException: The display name must not be empty.
	at org.junit.runner.Description.<init>(Description.java:167)
	at org.junit.runner.Description.<init>(Description.java:162)

.../jdk11_openj9_x86_64_04_15_2020/bin/java -XX:-ClassRelationshipVerifier -Xshareclasses:none -cp sootOutput/junit-junit:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
...
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.NullPointerException
	at org.junit.internal.runners.ErrorReportingRunner.run(ErrorReportingRunner.java:48)
	at org.junit.internal.runners.ErrorReportingRunnerTest.givenInvalidTestClassErrorAsCause(ErrorReportingRunnerTest.java:52)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.IllegalArgumentException: The display name must not be empty.
	at org.junit.runner.Description.<init>(Description.java:167)

@DanHeidinga
Copy link
Member

@ChengJin01 Can you post the exception tables from the method you pasted the bytecode for? We need that to see if there's a path that doesn't call super or another ctor of the same class

@ChengJin01
Copy link

ChengJin01 commented Apr 29, 2020

@DanHeidinga , there is no exception table for the method based on the DDR output:

> !methodforname   org/junit/internal/runners/ErrorReportingRunner.<init>
Searching for methods named 'org/junit/internal/runners/ErrorReportingRunner.<init>' in VM=0x00007F893400EF90...
!j9method 0x00000000001972D0 --> org/junit/internal/runners/ErrorReportingRunner.<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V
!j9method 0x00000000001972F0 --> org/junit/internal/runners/ErrorReportingRunner.<init>(Ljava/lang/Throwable;[Ljava/lang/Class;)V
Found 2 method(s) named org/junit/internal/runners/ErrorReportingRunner.<init>
> !j9method 0x00000000001972D0
J9Method at 0x1972d0 {
  Fields for J9Method:
	0x0: U8* bytecodes = !j9x 0x00007F89184D7FB0
	0x8: struct J9ConstantPool* constantPool = !j9constantpool 0x0000000000196810 (flags = 0x0)
	0x10: void* methodRunAddress = !j9x 0x0000000000000006
	0x18: void* extra = !j9x 0x000000000000176F
}
Signature: org/junit/internal/runners/ErrorReportingRunner.<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V !bytecodes 0x00000000001972D0
ROM Method: !j9rommethod 0x00007F89184D7F9C
Next Method: !j9method 0x00000000001972F0
> !bytecodes 0x00000000001972D0
  Name: <init>
  Signature: (Ljava/lang/Class;Ljava/lang/Throwable;)V
  Access Flags (3040001): public 
  Max Stack: 3
  Argument Count: 3
  Temp Count: 3

    0 iconst5 
    1 istore 4
    3 iconst1 
    4 istore 5  <----- store 1 to locals[5]
    6 iconst1 
    7 anewarray 98 java/lang/Class
   10 astore3 
   11 ldcw 125 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Class,java.lang.Throwable)> **** Executed Line: **** 3 **** $r2 = newarray (java.lang.Class)[1]
   14 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   17 iinc 5 -1    locals[5] = locals[5] - 1 = 0
   20 iload 5      
   22 ifle 56  <---- jump to 56 when locals[5] <= 0
   25 iload 4
   27 iconstm1 
   28 iadd 
   29 istore 4
   31 iload 4
   33 ifge 45
   36 aload3 
   37 iconst0 
   38 aload1 
   39 aastore 
   40 ldc 53 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Class,java.lang.Throwable)> **** Executed Line: **** 4 **** $r2[0] = r3
   42 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   45 aload0 
   46 aload2 
   47 aload3 
--> 48 invokespecial 81 org/junit/internal/runners/ErrorReportingRunner.<init>(Ljava/lang/Throwable;[Ljava/lang/Class;)V
   51 ldc 21 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Class,java.lang.Throwable)> **** Executed Line: **** 5 **** specialinvoke r0.<org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])>(r1, $r2)
   53 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   56 nop   <--------------------
   57 returnFromConstructor 

  Debug Info:
    Line Number Table (9):
      Line:    21 PC:     6
      Line:    21 PC:    11
      Line:    21 PC:    25
      Line:    21 PC:    31
      Line:    21 PC:    36
      Line:    21 PC:    40
      Line:    21 PC:    45
      Line:    21 PC:    51
      Line:    22 PC:    57

    Variables (0):

Given that it jumps to the index 56 as locals[5] is 0 at index 22 (22 ifle 56) , the other ctor (including the super) should be skipped in this way.

The corresponding class file also shows there is no exception table is the init method
image

public class org.junit.internal.runners.ErrorReportingRunner extends org.junit.runner.Runner
  minor version: 0
  major version: 49 <-------
  flags: (0x0021) ACC_PUBLIC, ACC_SUPER
  this_class: #2                          // org/junit/internal/runners/ErrorReportingRunner
  super_class: #13                        // org/junit/runner/Runner
  interfaces: 0, fields: 2, methods: 8, attributes: 1
...

Given the major version is 49 (< 51) , it seems the stackamp along with the exeception table was created via simulateStack() during the runtime verification.

#define CFR_MAJOR_VERSION_REQUIRING_STACKMAPS 51
	BOOLEAN classVersionRequiresStackmaps = romClass->majorVersion >= CFR_MAJOR_VERSION_REQUIRING_STACKMAPS;
			createStackMaps = !classVersionRequiresStackmaps && (verifyData->ignoreStackMaps || !hasStackMaps);

			if (verifyData->stackMapsCount) {
				if (createStackMaps) {
----->    result = simulateStack (verifyData);
				} else {
					result = decompressStackMaps (verifyData, argCount, stackMapData);
				}
			}

@ChengJin01
Copy link

ChengJin01 commented Apr 29, 2020

The bytecode of another init method without the exception table is:

Signature: 
org/junit/internal/runners/ErrorReportingRunner.<init>(Ljava/lang/Throwable;[Ljava/lang/Class;)V 
!bytecodes 0x00000000001972F0
ROM Method: !j9rommethod 0x00007F89184D8008
Next Method: !j9method 0x0000000000197310
> bytecodes 0x00000000001972F0
Unrecognised command: bytecodes
> !bytecodes 0x00000000001972F0
  Name: <init>
  Signature: (Ljava/lang/Throwable;[Ljava/lang/Class;)V
  Access Flags (3240081): public varargs 
  Max Stack: 2
  Argument Count: 3
  Temp Count: 6

    0 iconst5 
    1 istore3 
    2 iconst5 
    3 istore 4
    5 iconst1 
    6 istore 5
    8 iconst5 
    9 istore 6
   11 iconst5 
   12 istore 7
   14 aload0 
   15 invokespecial 82 org/junit/runner/Runner.<init>()V <-------
   18 ldc 11 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 3 **** specialinvoke r0.<org.junit.runner.Runner: void <init>()>()
   20 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   23 iload 6
   25 iconstm1 
   26 iadd 
   27 istore 6
   29 iload 6
   31 ifge 192
   34 iload 5
   36 iconstm1 
   37 iadd 
   38 istore 5
   40 iload 5
   42 ifle 276
   45 aload2 
   46 ifnull 73
   49 ldc 40 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 4 **** if r1 == null goto $r2 = new java.lang.NullPointerException
   51 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   54 aload2 
   55 arraylength 
   56 istore 6
   58 ldc 23 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 5 **** $i0 = lengthof r1
   60 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   63 iload 6
   65 ifne 96
   68 ldc 3 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 6 **** if $i0 != 0 goto r3 = r1
   70 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   73 new 131 java/lang/NullPointerException
   76 astore0 
   77 ldcw 109 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 7 **** $r2 = new java.lang.NullPointerException
   80 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   83 aload0 
   84 ldc 47 (java.lang.String) Test classes cannot be null or empty
   86 invokespecial 80 java/lang/NullPointerException.<init>(Ljava/lang/String;)V
   89 ldc 18 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 8 **** specialinvoke $r2.<java.lang.NullPointerException: void <init>(java.lang.String)>("Test classes cannot be null or empty")
   91 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
   94 aload0 
   95 athrow 
   96 aload2 
   97 astore 5
   99 ldc 2 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 10 **** r3 = r1
  101 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  104 iinc 4 -1
  107 iload 4
  109 ifle 132
  112 iload 4
  114 lookupswitch pairs 1
        default         73
              4         63
  132 aload 5
  134 arraylength 
  135 istore 6
  137 ldc 49 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 11 **** i1 = lengthof r3
  139 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  142 iconst0 
  143 istore 8
  145 ldc 9 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 12 **** i2 = 0
  147 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  150 iload 8
  152 iload 6
  154 ificmpge 233
  157 ldc 15 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 13 **** if i2 >= i1 goto $r4 = specialinvoke r0.<org.junit.internal.runners.ErrorReportingRunner: java.lang.String getClassNames(java.lang.Class[])>(r1)
  159 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  162 aload 5
  164 iload 8
  166 aaload 
  167 astore 4
  169 ldc 63 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 14 **** r7 = r3[i2]
  171 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  174 aload 4
  176 ifnonnull 222
  179 ldc 42 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 15 **** if r7 != null goto i2 = i2 + 1
  181 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  184 iload3 
  185 iconstm1 
  186 iadd 
  187 istore0 
  188 iload0 
  189 ifge 73
  192 new 131 java/lang/NullPointerException
  195 astore0 
  196 ldc 8 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 16 **** $r8 = new java.lang.NullPointerException
  198 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  201 iinc 7 -1
  204 iload 7
  206 ifge 192
  209 aload0 
  210 ldc 30 (java.lang.String) Test class cannot be null
  212 invokespecial 80 java/lang/NullPointerException.<init>(Ljava/lang/String;)V
  215 ldc 39 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 17 **** specialinvoke $r8.<java.lang.NullPointerException: void <init>(java.lang.String)>("Test class cannot be null")
  217 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  220 aload0 
  221 athrow 
  222 iinc 8 1
  225 ldc 5 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 19 **** i2 = i2 + 1
  227 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  230 goto 150
  233 aload0 
  234 aload2 
  235 invokespecial 84 org/junit/internal/runners/ErrorReportingRunner.getClassNames([Ljava/lang/Class;)Ljava/lang/String;
  238 astore2 
  239 ldc 35 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 21 **** $r4 = specialinvoke r0.<org.junit.internal.runners.ErrorReportingRunner: java.lang.String getClassNames(java.lang.Class[])>(r1)
  241 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  244 aload0 
  245 aload2 
  246 putfield 99 org/junit/internal/runners/ErrorReportingRunner.classNames Ljava/lang/String;
  249 ldc 22 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 22 **** r0.<org.junit.internal.runners.ErrorReportingRunner: java.lang.String classNames> = $r4
  251 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  254 aload0 
  255 aload1 
  256 invokespecial 67 org/junit/internal/runners/ErrorReportingRunner.getCauses(Ljava/lang/Throwable;)Ljava/util/List;
  259 astore1 
  260 ldc 27 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 23 **** $r6 = specialinvoke r0.<org.junit.internal.runners.ErrorReportingRunner: java.util.List getCauses(java.lang.Throwable)>(r5)
  262 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  265 aload0 
  266 aload1 
  267 putfield 105 org/junit/internal/runners/ErrorReportingRunner.causes Ljava/util/List;
  270 ldcw 117 (java.lang.String) <org.junit.internal.runners.ErrorReportingRunner: void <init>(java.lang.Throwable,java.lang.Class[])> **** Executed Line: **** 24 **** r0.<org.junit.internal.runners.ErrorReportingRunner: java.util.List causes> = $r6
  273 invokestatic 91 Print.logPrint(Ljava/lang/String;)V
  276 returnFromConstructor 

  Debug Info:
    Line Number Table (53):
      Line:    24 PC:    14
      Line:    24 PC:    18
      Line:    24 PC:    23
      Line:    24 PC:    29
      Line:    24 PC:    34
      Line:    24 PC:    40
      Line:    25 PC:    45
      Line:    25 PC:    49
      Line:    25 PC:    54
      Line:    25 PC:    58
      Line:    25 PC:    63
      Line:    25 PC:    68
      Line:    26 PC:    73
      Line:    26 PC:    77
      Line:    26 PC:    83
      Line:    26 PC:    89
      Line:    26 PC:    94
      Line:    28 PC:    96
      Line:    28 PC:    99
      Line:    28 PC:   104
      Line:    28 PC:   107
      Line:    28 PC:   112
      Line:    28 PC:   132
      Line:    28 PC:   137
      Line:    28 PC:   142
      Line:    28 PC:   145
      Line:    28 PC:   150
      Line:    28 PC:   157
      Line:    28 PC:   162
      Line:    28 PC:   169
      Line:    29 PC:   174
      Line:    29 PC:   179
      Line:    29 PC:   184
      Line:    29 PC:   188
      Line:    30 PC:   192
      Line:    30 PC:   196
      Line:    30 PC:   201
      Line:    30 PC:   204
      Line:    30 PC:   209
      Line:    30 PC:   215
      Line:    30 PC:   220
      Line:    28 PC:   222
      Line:    28 PC:   225
      Line:    28 PC:   230
      Line:    33 PC:   233
      Line:    33 PC:   239
      Line:    33 PC:   244
      Line:    33 PC:   249
      Line:    34 PC:   254
      Line:    34 PC:   260
      Line:    34 PC:   265
      Line:    34 PC:   270
      Line:    35 PC:   276

    Variables (0):

@DanHeidinga
Copy link
Member

@ChengJin01 I'd start by looking atsimulateStacks and how it propogates the uninitalizedThis which may happen (or not) in the mergeStacks code.

The other place I'd dig for this is https://github.com/eclipse/openj9/blob/1b35e0a4fd77a8c0c04965af8ac04d21fa4ad659/runtime/bcverify/bcverify.c#L2540

@ChengJin01
Copy link

ChengJin01 commented Apr 29, 2020

@DanHeidinga,

To figure out why VerifyError was thrown out on OpenJDK9 with v0.9.0-release, I compared the master branch and the v0.9.0-release branch in rtverify.c (not difference found in bcverify.c) as follows:
https://github.com/eclipse/openj9/blob/master/runtime/bcverify/rtverify.c#L318

	if (!verifyData->createdStackMap) { <------------
		/* 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;
			goto _finished;
		}
	}

against
https://github.com/eclipse/openj9/blob/v0.9.0-release/runtime/bcverify/rtverify.c#L310

			/* If stack maps created */
			/* Only perform second verification pass with a valid J9Class */
			if ((result == BCV_SUCCESS) && clazz) {
				if (isInitMethod) {
					/* CMVC 199785: Jazz103 45899: Only run this when the stack has been built correctly */
					setInitializedThisStatus(verifyData);
				}

So the only difference is the check on uninitializedThis is disabled in matchStack() when the stackmap is created in which case uninitializedThis is set up via setInitializedThisStatus() (for class version < 51) to fixed the issue raised in #5676. Enabling the check by removing if (!verifyData->createdStackMap) will end up with VerifyError in the test in this issue:

$ ../jdk11_openj9_bcv_gdb_04_29_v3/bin/java -cp sootOutput/junit-junit:hamcrest-all-1.3.jar org.junit.runner.JUnitCore org.junit.internal.runners.ErrorReportingRunnerTest
JUnit version 4.13
...
1) givenInvalidTestClassErrorAsCause(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.VerifyError: JVMVRFY012 stack shape inconsistent; class=org/junit/internal/runners/ErrorReportingRunner, 
method=<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V, pc=22
	at org.junit.internal.runners.ErrorReportingRunnerTest.givenInvalidTestClassErrorAsCause(ErrorReportingRunnerTest.java:50)
...
2) givenInvalidTestClass_integrationTest(org.junit.internal.runners.ErrorReportingRunnerTest)
java.lang.VerifyError: JVMVRFY012 stack shape inconsistent; class=org/junit/internal/runners/ErrorReportingRunner, 
method=<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V, pc=22
	at org.junit.runners.model.RunnerBuilder.safeRunnerForClass(RunnerBuilder.java:76)

Even though VerifyError was captured on OpenJDK9/OpenJ9 with the check on uninitializedThis enabled for the created stackmap, I don't think it is really accurate for ErrorReportingRunner.<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V given that the expected VerifyError message should be something like

J9NLS_BCV_ERR_INIT_NOT_CALL_INIT=<init> does not call this <init> or super <init>

on return of the ctor method rather than at pc = 22 (22 ifle 56),

		case RTV_RETURN:
		...
			/* If this is <init>, need to ensure that the uninitialized_this
			 * has been initialized.  Can be determined from the stack map's
			 * flag
			 */
			if (isInitMethod) {
				if (liveStack->uninitializedThis == (UDATA)TRUE){
		----> errorType = J9NLS_BCV_ERR_INIT_NOT_CALL_INIT__ID;

which means we need to ensure both this issue and the previous issue in #5676 works with a new fix.

@ChengJin01
Copy link

ChengJin01 commented Apr 29, 2020

I double-checked the JVM Spec from Java 7 to 11 as to uninitializedThis when invoking invokespecial as follows:
Java 7 VM Spec

4.10 Verification of class File:
invokespecial:
The rule for invokespecial of an <init> method is the sole motivation for passing back 
a distinct exception stack frame. The concern is that invokespecial can cause a 
superclass <init> method to be invoked, and that invocation could fail, 
leaving this uninitialized.

The original frame holds an uninitialized object in a local and has flag uninitializedThis.
Normal termination of invokespecial initializes the uninitialized object and turns off 
the uninitializedThis flag. But if the invocation of an <init> method throws an exception, 
the uninitialized object might be left in a partially initialized state, and needs to 
be made permanently unusable. This is represented by an exception frame containing the broken
 object (the new value of the local) and the uninitializedThis flag (the old flag). 
 There is no way to get from an apparentlyinitialized object bearing the uninitializedThis 
 flag to a properly initialized object, so the object is permanently unusable. 
 If not for this case, the exception stack frame could be the same as the input stack frame.

and Java 8, 9, 10 & 11 VM Spec (without any change)

The rule for invokespecial of an <init> method is the sole motivation for passing back 
a distinct exception stack frame. The concern is that when initializing an object within its constructor,
invokespecial can cause a superclass <init> method to be invoked, and that invocation could fail,
leaving this uninitialized.

In this situation, the original frame holds an uninitialized object in local variable 0 and 
has flag flagThisUninit. Normal termination of invokespecial initializes the uninitialized 
object and turns off the flagThisUninit flag. But if the invocation of an <init> method throws an exception, 
the uninitialized object might be left in a partially initialized state, and needs to be made 
permanently unusable. This is represented by an exception frame containing the broken object 
(the new value of the local) and the flagThisUninit flag (the old flag). 
There is no way to get from an apparently-initialized object bearing the flagThisUninit flag 
to a properly initialized object, so the object is permanently unusable.

If not for this situation, the flags of the exception stack frame would always be the same 
as the flags of the input stack frame.

So the check of uninitializedThis applies to an exception stack frame which we already covered in the existing code.

Now that ErrorReportingRunner.<init>(Ljava/lang/Class;Ljava/lang/Throwable;)V (without exception) also expects the similar result as compared to the RI's behaviour,

method: <init> signature: (Ljava/lang/Class;Ljava/lang/Throwable;)V) 
Constructor must call super() or this()

my understanding is the expected result (the escape path is from an IF statement rather than an exception) is undocumented in the existing VM spec but actually covered on Hotspot. If so, we might need to figure out how to get this work on the created stackmaps (e.g. in simulateStacks).

@ChengJin01
Copy link

ChengJin01 commented Apr 29, 2020

  1. I went through the code in simulateStacks & setInitializedThisStatus and didn't find out anything fundamentally incorrect in logic when generating stackmaps & setting up the uninitializedThis flag.

  2. the existing code in matchStack is to address an issue with try/catch exception, which is also correct in throwing out verification error with inconsistent stackmap.

		/* 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;
			goto _finished;
		}

Even though the failing .classes (version = 51) in there comes with stackmap & exception table, the code above also covers the case of generated stackmaps (version < 51).

  1. I double-checked the issue in Spring app fails on OpenJ9 with a profiler with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" #5676, which seems pretty much the same issue as mentioned above as follows:
>  !dumpromclass  0x00007F2D10B0A078
ROM Size: 0x2788 (10120)
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 <---- (JDK 1.2)
...
  Name: <init>
  Signature: ()V
  Access Flags (1020001): public 
  Max Stack: 15
  Caught Exceptions (4):
     start   end   handler   catch type
     -----   ---   -------   ----------
     18  32  32   (any)
     13  36  36   java/lang/RuntimeException
     13  36  36   java/lang/Error
     13  36  37   java/lang/Throwable
  Argument Count: 1
  Temp Count: 2

    0 ldcw 153 (int/float) 0x00003DCE
    3 ldc2lw 198 (long) 0x00007F2CD83F57E0
    6 invokestatic 118 com/yourkit/runtime/Callback.yjpMethodEntry(IJ)J
    9 lstorew 1 <-----------
   13 aload0
   14 dup 
   15 invokespecial 94 Target.<init>()V <-----------
   18 invokestatic 28 Target$$EnhancerBySpringCGLIB$$fdc9b9d7.CGLIB$BIND_CALLBACKS(Ljava/lang/Object;)V
   21 ldcw 153 (int/float) 0x00003DCE
   24 lloadw 1
   28 invokestatic 119 com/yourkit/runtime/Callback.yjpMethodExit(IJ)V
   31 genericReturn 
   32 invokestatic 116 com/yourkit/probes/builtin/CpuTracingSupport.onUncaughtException()V
   35 athrow 
   36 athrow 
   37 new 37 java/lang/reflect/UndeclaredThrowableException
   40 dupx1 
   41 swap 
   42 invokespecial 38 java/lang/reflect/UndeclaredThrowableException.<init>(Ljava/lang/Throwable;)V
   45 athrow 

The only differences is the stackmaps were generated as the failing class version is 46.0 / JDK1.2.
So technically VerifyError should be captured in this case e.g. (verified with a build by disabling the check of generated stackmaps)

Caused by: java.lang.VerifyError: JVMVRFY012 stack shape inconsistent; 
class=Target$$EnhancerBySpringCGLIB$$fdc9b9d7, method=<init>()V, pc=9

But we let it pass by enabling the check of the generated stackmaps to match the RI's behaviour given that the check was ignored on Hotspot.

  1. Even though the existing code is to address the case of try/catch exception for invokespecial in the ctor method, the code logic in mergeStacks/simulateStack remains the same & already covers the case of if/else statement for invokespecial in the ctor method. That is to say, there is no need to change anything in code to capture VerifyError except the check on the generated stackmaps

To sum up,

  1. the existing code is correct in address the issue with try/catch exception for invokespecial in a ctor method, whether the stackmaps are generated or not.
  2. The check on the ctor method at Spring app fails on OpenJ9 with a profiler with "java.lang.VerifyError: JVMVRFY012 stack shape inconsistent" #5676 is ignored by Hotspot most likely because the class version 46.0 (JDK1.2) is too low.
  3. The failing class version in this issue is 49 (Java 5), in which case VerifyError should be captured.
.../ErrorReportingRunnerTest/
sootOutput/junit-junit/org/junit/internal/runners/ErrorReportingRunner.class
  Last modified Apr. 28, 2020; size 21655 bytes
  MD5 checksum 4e08583efa6b9abb9996b65c6215e7ec
  Compiled from "ErrorReportingRunner.java"
public class org.junit.internal.runners.ErrorReportingRunner extends org.junit.runner.Runner
  minor version: 0
  major version: 49 <--------- Java SE 5.0

To match the RI's behaviour in all cases above, we might as well replace the check on generated maps (Java version >= 51) with the check on a decent java version (e.g. Java 5). e.g.

	if (romClass->majorVersion >= 49) { <------------------
		/* 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;
			goto _finished;
		}
	}

@fuzzy000
Copy link
Author

fuzzy000 commented May 1, 2020

Thanks for your hard work!

By the way, may you also check these two issues? #9357 #9336 @DanHeidinga

@DanHeidinga
Copy link
Member

@fuzzy000 we're still working our way though this one =)

The other two are both in the milestone for our next release and will get attention before then. These are tricky issues that take time and discussion to ensure we're implementing the spec correctly and fixing any issues in the best way.

They're definitely on the list though!

ChengJin01 pushed a commit to ChengJin01/openj9 that referenced this issue Jun 19, 2020
The change is to add the check of BCV_SPECIAL when merging & matching
stacks to ensure the uninitializedThis flag is correctly set up during
the generation of stackmaps so as to match the RI's behavior at runtime
verification.[ci skip]

Fixes: eclipse-openj9#9385

Signed-off-by: Cheng Jin <[email protected]>
DanHeidinga pushed a commit to DanHeidinga/openj9 that referenced this issue Jun 19, 2020
The change is to add the check of BCV_SPECIAL when merging & matching
stacks to ensure the uninitializedThis flag is correctly set up during
the generation of stackmaps so as to match the RI's behavior at runtime
verification.[ci skip]

Fixes: eclipse-openj9#9385

Signed-off-by: Cheng Jin <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants