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.29k stars 722 forks source link

Inconsistent Results between OpenJ9 and Other JDKs in Execution #18834

Open Qeryu opened 10 months ago

Qeryu commented 10 months ago

Java -version output

openjdk version "1.8.0_402-internal"  
OpenJDK Runtime Environment (build 1.8.0_402-internal_2024_01_05_11_05-b00)  
Eclipse OpenJ9 VM (build master-1b60ab828, JRE 1.8.0 Linux amd64-64-Bit Compressed References 20240105_000000 (JIT enabled, AOT enabled)  
OpenJ9   - 1b60ab828  
OMR      - 3a4787401  
JCL      - b058bf977e based on jdk8u402-b05)

javac 1.8.0_402-internal

Summary of problem

When executing this test case with OpenJ9 JDK8, it produces results that are inconsistent with those obtained when using other JDKs.

After forcing JIT compilation with the -Xjit:count=0 option, the program produces abnormal results; however, when JIT compilation is stopped using the -Xint option, the program executes correctly. This suggests that the issue may lie with the JIT.

Further testing revealed that when the Global Value Propagation is disabled using the -Xjit:disableGlobalVP option, the program executes correctly. I hope this information can assist you in identifying the cause and fixing the bug.

class Test {
    final int j = 400;
    long a;

    void e() {
        long[] b = new long[j];
        for (int c = 1; c < 97; ++c) {
            b[(c / 2) % j] = c;
        }

        for (int d = 0; d < b.length; d++)
            a += b[d];

        for (int n = 6; n < 96; ++n)
            try {
                int f = 5 / 0;
            } catch (ArithmeticException g) {
            }
    }

    void h() {
        for (int d = 0; d < 200; d++)
            e();
        System.out.println(a);
    }

    public static void main(String[] i) {
        Test p = new Test();
        p.h();
    }
}
$ OpenJDK21-release/.../java Test
480000

$ openj9-openjdk-jdk8/.../java Test
397704
$ openj9-openjdk-jdk8/.../java Test
392520
$ openj9-openjdk-jdk8/.../java Test
391872
$ openj9-openjdk-jdk8/.../java Test
395112

$ openj9-openjdk-jdk8/.../java -Xint Test
480000
$ openj9-openjdk-jdk8/.../java -Xjit:count=0 Test
354288
$ openj9-openjdk-jdk8/.../java -Xjit:disableGlobalVP Test
480000
pshipton commented 10 months ago

@hzongaro fyi

hzongaro commented 10 months ago

The -Xjit:disableGlobalVP could be a red herring. I'm able to reproduce the incorrect output with this:

$ java -Xjit:count=1,disableAsyncCompilation,optLevel=hot,{Test.e*}\(log=test.gvp.log,optDetails,lastOptIndex=248,lastOptSubIndex=18,traceCG\) Test
360600

but not with this:

$ java -Xjit:count=1,disableAsyncCompilation,optLevel=hot,{Test.e*}\(log=test.gvp.log,optDetails,lastOptIndex=248,lastOptSubIndex=17,traceCG\) Test
480000

Looking at the log, it looks like GPR_0208 might be getting reused to hold both the value that's supposed to be used for the value that's being stored into an array element and the computation of the array index:

[   659] 248.16   O^O LAZY CLOBBERING: setParentSupportsLazyClobber(0x7fa6ea88ab40)
[   660] 248.17   O^O IntegerSubEvaluator: register is not NULL, or second operand is not a 32 bit constant. Register value: 0
[   661] 248.18   O^O LAZY CLOBBERING: reuse register GPR_0208 from 0x7fa6ea88a5a0 for 0x7fa6ea88ab40
LAZY CLOBBERING: node 0x7fa6ea88a5a0 register GPR_0208 refcount=1 canClobber=true
LAZY CLOBBERING: node 0x7fa6ea88a9b0 register GPR_0208 refcount=1 canClobber=true
------------------------------
 n589n    (  0)  lstorei  <array-shadow>[#230  Shadow] [flags 0x80000604 0x0 ] (cannotOverflow storeAlreadyEvaluated )  [0x7fa6ea88a7d0] bci=[-1,24,8] rc=0 vc=2810 vn=- li=37 udi=- nc=2 flg=0x1000
 n590n    (  0)    aladd (X>=0 internalPtr )                                                          [0x7fa6ea88a820] bci=[-1,24,8] rc=0 vc=2810 vn=- li=37 udi=- nc=2 flg=0x8100
 n894n    (  2)      ==>aRegLoad (in *GPR_0129) (X!=0 SeenRealReference )
 n592n    (  0)      lshl (X>=0 )                                                                     [0x7fa6ea88a8c0] bci=[-1,24,8] rc=0 vc=2810 vn=- li=37 udi=9 nc=2 flg=0x100
 n593n    (  0)        i2l (in GPR_0208) (highWordZero X>=0 )                                         [0x7fa6ea88a910] bci=[-1,24,8] rc=0 vc=2810 vn=- li=37 udi=46496 nc=1 flg=0x4100
 n594n    (  0)          irem (in GPR_0208) (cannotOverflow )                                         [0x7fa6ea88a960] bci=[-1,21,8] rc=0 vc=2810 vn=- li=37 udi=46496 nc=2 flg=0x1000
 n595n    (  0)            iushr (in GPR_0208) (X>=0 cannotOverflow )                                 [0x7fa6ea88a9b0] bci=[-1,17,8] rc=0 vc=2810 vn=- li=37 udi=46496 nc=2 flg=0x1100
 n582n    (  0)              isub (in GPR_0208) (X>=0 cannotOverflow )                                [0x7fa6ea88a5a0] bci=[-1,25,7] rc=0 vc=2810 vn=- li=37 udi=46496 nc=2 flg=0x1100
 n895n    (  2)                ==>iRegLoad (in GPR_0130) (X>=0 cannotOverflow SeenRealReference )
 n795n    (  0)                iconst -2 (X!=0 X<=0 )                                                 [0x7fa6ea88e830] bci=[-1,25,7] rc=0 vc=2810 vn=- li=37 udi=- nc=0 flg=0x204
 n558n    (  1)              ==>iconst 1 (X!=0 X>=0 )
 n559n    (  1)            ==>iconst 400 (X!=0 X>=0 cannotOverflow )
 n1029n   (  0)        iconst 3 (X!=0 X>=0 )                                                          [0x7fa6eab23160] bci=[-1,24,8] rc=0 vc=2810 vn=- li=37 udi=1 nc=0 flg=0x104
 n600n    (  0)    i2l (in GPR_0208) (highWordZero X>=0 lazyClobber )                                 [0x7fa6ea88ab40] bci=[-1,23,8] rc=0 vc=2810 vn=- li=37 udi=46496 nc=1 flg=0x6100
 n582n    (  0)      ==>isub (in GPR_0208) (X>=0 cannotOverflow )
------------------------------

 [0x7fa6eab0b620]       lea     GPR_0208, dword ptr [GPR_0130+0x2]              # LEA4RegMem, SymRef [#468 +2]
 [0x7fa6eab0b7f0]       shr     GPR_0208, 0x01  # SHR4RegImm1
 [0x7fa6eab0ba50]       mov     GPR_0225, 0x51eb851f    # MOV4RegImm4
 [0x7fa6eab0bd30]       assocreg                        # assocreg
        POST: [GPR_0193 : eax] [GPR_0192 : edx] [*GPR_0129 : r9d] [GPR_0130 : r10d] [&GPR_0144 : r11d]
 [0x7fa6eab0bae0]       imul    GPR_0208                # IMUL4AccReg
         PRE: [GPR_0225 : eax] [GPR_0224 : edx]
        POST: [GPR_0225 : eax] [GPR_0224 : edx]
 [0x7fa6eab0bdb0]       sar     GPR_0224, 0x07  # SAR4RegImm1
 [0x7fa6eab0be40]       imul    GPR_0224, GPR_0224, 0x00000190  # IMUL4RegRegImm4
 [0x7fa6eab0c130]       assocreg                        # assocreg
        POST: [GPR_0225 : eax] [GPR_0224 : edx] [*GPR_0129 : r9d] [GPR_0130 : r10d] [&GPR_0144 : r11d]
 [0x7fa6eab0bee0]       sub     GPR_0208, GPR_0224              # SUB4RegReg
         PRE: [GPR_0225 : eax] [GPR_0224 : edx]
        POST: [GPR_0225 : eax] [GPR_0224 : edx]
 [0x7fa6eab0c1b0]       mov     qword ptr [*GPR_0129+8*GPR_0208], GPR_0208              # S8MemReg, SymRef  <array-shadow>[#230  Shadow] [flags 0x80000604 0x0 ]

@BradleyWood, may I ask you to take a look at this problem?