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

Error. compiler crashed (exit code 4) - cannot access unnamed package #20786

Closed
JasonFengJ9 opened this issue Dec 9, 2024 · 21 comments · Fixed by #20849
Closed

Error. compiler crashed (exit code 4) - cannot access unnamed package #20786

JasonFengJ9 opened this issue Dec 9, 2024 · 21 comments · Fixed by #20849

Comments

@JasonFengJ9
Copy link
Member

JasonFengJ9 commented Dec 9, 2024

Failure link

From internal Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0 (ubu20x86-svl-rt2-1)

java version "21.0.6-beta" 2025-01-21
IBM Semeru Runtime Certified Edition 21.0.6+6-202412071603 (build 21.0.6-beta+6-202412071603)
Eclipse OpenJ9 VM 21.0.6+6-202412071603 (build master-501751012f, JRE 21 Linux amd64-64-Bit Compressed References 20241207_325 (JIT enabled, AOT enabled)
OpenJ9   - 501751012f
OMR      - b893b2be2
JCL      - 71fff4eae based on jdk-21.0.6+6)

Rerun in Grinder - Change TARGET to run only the failed test targets

Optional info

Failure output (captured from console output)

[2024-12-07T18:58:32.648Z] variation: Mode650
[2024-12-07T18:58:32.648Z] JVM_OPTIONS:  -XX:-UseCompressedOops -Xverbosegclog 

[2024-12-07T18:58:53.178Z] TEST: jdk/incubator/vector/Byte256VectorLoadStoreTests.java

[2024-12-07T18:58:53.180Z] warning: using incubating module(s): jdk.incubator.vector
[2024-12-07T18:58:53.180Z] /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/incubator/vector/Byte256VectorLoadStoreTests.java:34: error: cannot access unnamed package
[2024-12-07T18:58:53.180Z] import java.lang.foreign.MemorySegment;
[2024-12-07T18:58:53.180Z] ^
[2024-12-07T18:58:53.180Z]   /org/testng/internal/annotations/DefaultAnnotationTransformer.class
[2024-12-07T18:58:53.180Z] 1 error
[2024-12-07T18:58:53.180Z] 1 warning
[2024-12-07T18:58:53.180Z] printing javac parameters to: /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/TKG/output_17335904872610/jdk_vector_1/work/scratch/2/javac.20241207_105852.args
[2024-12-07T18:58:53.180Z] 
[2024-12-07T18:58:53.180Z] TEST RESULT: Error. compiler crashed (exit code 4)

[2024-12-07T19:23:24.065Z] jdk_vector_1_FAILED

javac.20241207_105852.args

--add-modules
jdk.incubator.vector,java.base
--add-exports
java.base/jdk.internal.vm.annotation=ALL-UNNAMED
-d
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/TKG/output_17335904872610/jdk_vector_1/work/classes/0/jdk/incubator/vector/Byte256VectorLoadStoreTests.d
-sourcepath
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/incubator/vector
-classpath
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/incubator/vector:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/TKG/output_17335904872610/jdk_vector_1/work/classes/0/jdk/incubator/vector/Byte256VectorLoadStoreTests.d:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar
--enable-preview
--source=21
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/jdk/incubator/vector/Byte256VectorLoadStoreTests.java

50x internal Grinder - failed at rhel8x86-svl-rt1-1 and passed in the other 3 machines (rhel9x86-rt-2, rtj-rhel8x86-rtp-test-xemvx-1, cent9x86-rtp-rt1-1)

openjdk21_j9_extended.openjdk_x86-64_linux jdk_security3_1_FAILED

[2024-12-07T18:01:05.476Z] TEST: javax/security/auth/PrivateCredentialPermission/MoreThenOnePrincipals.java

[2024-12-07T18:01:05.477Z] /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/javax/security/auth/PrivateCredentialPermission/MoreThenOnePrincipals.java:24: error: cannot access unnamed package
[2024-12-07T18:01:05.477Z] import com.sun.security.auth.NTUserPrincipal;
[2024-12-07T18:01:05.477Z] ^
[2024-12-07T18:01:05.477Z]   /org/testng/internal/annotations/DefaultAnnotationTransformer.class
[2024-12-07T18:01:05.477Z] 1 error
[2024-12-07T18:01:05.477Z] printing javac parameters to: /home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/TKG/output_17335904872610/jdk_security3_1/work/scratch/1/javac.20241207_100055.args
[2024-12-07T18:01:05.477Z] 
[2024-12-07T18:01:05.477Z] TEST RESULT: Error. compiler crashed (exit code 4)

javac.20241207_100055.args

--add-modules
jdk.security.auth
-d
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/TKG/output_17335904872610/jdk_security3_1/work/classes/2/javax/security/auth/PrivateCredentialPermission/MoreThenOnePrincipals.d
-sourcepath
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/javax/security/auth/PrivateCredentialPermission
-classpath
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/javax/security/auth/PrivateCredentialPermission:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/TKG/output_17335904872610/jdk_security3_1/work/classes/2/javax/security/auth/PrivateCredentialPermission/MoreThenOnePrincipals.d:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar
/home/jenkins/workspace/Test_openjdk21_j9_extended.openjdk_x86-64_linux_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/javax/security/auth/PrivateCredentialPermission/MoreThenOnePrincipals.java
Copy link

github-actions bot commented Dec 9, 2024

Issue Number: 20786
Status: Open
Recommended Components: comp:test, comp:infra, comp:vm

@JasonFengJ9 JasonFengJ9 changed the title jdk_vector_1 FAILED - cannot access unnamed package Error. compiler crashed (exit code 4) - cannot access unnamed package Dec 9, 2024
@pshipton
Copy link
Member

I'm not sure what to make of this. The compile error doesn't make sense, and I don't know why /org/testng/internal/annotations/DefaultAnnotationTransformer.class is mentioned.
@llxia are there any recent testng changes, or any reason why it wouldn't be working properly on some machines?

@pshipton
Copy link
Member

pshipton commented Dec 11, 2024

These failures may have a better clue about what's going wrong.

https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/112
https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_1/112
https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_2/112
https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.openjdk_x86-64_mac_Nightly_testList_0/81
https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.openjdk_x86-64_mac_Nightly_testList_1/81
https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.openjdk_x86-64_mac_Nightly_testList_2/81

ZipException opening "guice-5.1.0.jar": invalid CEN header (bad header size)
ZipException opening "testng-7.3.0.jar": invalid CEN header (bad header size)
ZipException opening "junit-platform-console-standalone-1.9.2.jar": invalid CEN header (bad signature)
ZipException opening "testng-7.3.0.jar": invalid CEN header (bad header size)
ZipException opening "jcommander-1.82.jar": invalid CEN header (bad header size)

@pshipton
Copy link
Member

pshipton commented Dec 11, 2024

This is blocking proper running of openjdk tests on xlinux and xmac. I'll check if it affects 0.49.
Edit:
It doesn't seem to affect 0.49 testing.
https://openj9-jenkins.osuosl.org/job/Build_JDK23_x86-64_mac_Release/13/

@pshipton
Copy link
Member

I see these aqatest changes between the last working and first failing, but it may not be the correct repo/thing to look at.
adoptium/aqa-tests@5c12653...354b5b7

@pshipton
Copy link
Member

The jars in the error messages aren't included in the list of third party dependent jars.

@llxia
Copy link
Contributor

llxia commented Dec 11, 2024

There is jtreg change adoptium/TKG#645. But I am not sure if it is related to this issue

@pshipton
Copy link
Member

I didn't see a TKG change between last working and first failing.

@pshipton
Copy link
Member

pshipton commented Dec 11, 2024

I see the following in failure output, which includes the problematic jar files. Are we somehow missing some third party dependent jars?
22:53:30 -classpath /home/jenkins/workspace/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/lang/annotation/typeAnnotations:/home/jenkins/workspace/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/aqa-tests/TKG/output_17338027463909/jdk_lang_0/work/classes/2/java/lang/annotation/typeAnnotations/TestExecutableGetAnnotatedType.d:/home/jenkins/workspace/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/jvmtest/openjdk/jtreg/lib/testng-7.3.0.jar:/home/jenkins/workspace/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/jvmtest/openjdk/jtreg/lib/guice-5.1.0.jar:/home/jenkins/workspace/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/jvmtest/openjdk/jtreg/lib/jcommander-1.82.jar /home/jenkins/workspace/Test_openjdk23_j9_sanity.openjdk_x86-64_linux_Nightly_testList_0/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/lang/annotation/typeAnnotations/TestExecutableGetAnnotatedType.java

@llxia
Copy link
Contributor

llxia commented Dec 11, 2024

The jars in the error messages aren't included in the list of third party dependent jars.

The jars in the error are from jtreg tar: https://ci.adoptium.net/job/test.getDependency/lastSuccessfulBuild/artifact/jtreg_7_3_1_1.tar.gz

image

Since the latest jtreg jar got generated on Dec 11 (today), rerun the test in Grinder: https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/45785/

@pshipton
Copy link
Member

Not sure why the grinder is running jdk_security3, which is an extended.openjdk target.

@pshipton
Copy link
Member

pshipton commented Dec 11, 2024

Trying failed test targets.
https://openj9-jenkins.osuosl.org/job/Grinder/4021/ - still failing

@llxia
Copy link
Contributor

llxia commented Dec 11, 2024

09:44:57  import org.junit.jupiter.api.Test;
09:44:57  ^
09:44:57    ZipException opening "junit-platform-console-standalone-1.9.2.jar": invalid CEN header (bad header size)
09:44:57  1 error
09:44:57  printing javac parameters to: /var/tmp/javac.20241211_084442.args
09:44:57  
09:44:57  TEST RESULT: Error. compiler crashed (exit code 4)
09:44:57  --------------------------------------------------
09:48:52  TEST: java/lang/RuntimeTests/shutdown/ShutdownHooks.java
...
not ok 1 - jdk_lang_0
  ---
    output:
      |
        Failed test cases: 
        TEST: java/lang/Long/ToString.java
        TEST: java/lang/RuntimeTests/shutdown/ShutdownHooks.java
        TEST: java/lang/String/CompactString/CompareToIgnoreCase.java
        TEST: java/lang/String/CompactString/RegionMatches.java
        Test results: passed: 922; error: 4
    duration_ms: 1314400
  ...

@pshipton
Copy link
Member

OpenJ9 code changes.

e1af88f...6a1113a
eclipse-openj9/openj9-omr@b893b2b...937b947

@0xdaryl pls take a look, I'm guessing a x86 change is causing the problem.

@hzongaro
Copy link
Member

Taking a look. . . .

@pshipton
Copy link
Member

pshipton commented Dec 11, 2024

Simple grinder on the failing JVM
https://openj9-jenkins.osuosl.org/job/Grinder/4024 (failed)
Checking if running just an individual test fails https://openj9-jenkins.osuosl.org/job/Grinder/4026 - this passed

Same grinder on the older JVM passed.
https://openj9-jenkins.osuosl.org/job/Grinder/4025

I tried to create a simple test case, but it doesn't recreate the problem. Maybe with the correct JIT options.

import java.io.*;
import java.util.*;
import java.util.zip.*;

public class ReadZip {
public static void main(String[] args) throws Exception {
        ZipFile zip = new ZipFile(args[0]);
        ZipFile zip2 = new ZipFile(args[0]);
        Enumeration<? extends ZipEntry> e = zip.entries();
        while (e.hasMoreElements()) {
                ZipEntry ze = e.nextElement();
                System.out.println(ze.getName());
                ZipEntry ze1 = zip2.getEntry(ze.getName());
                InputStream in = zip2.getInputStream(ze1);
                byte buf[] = new byte[2048];
                while (in.read(buf) > 0);
                in.close();
        }
}
}

@hzongaro
Copy link
Member

I tried capturing core files and jitdumps when a ZipException was thrown from jdk/nio/zipfs/ZipFileSystem.initCEN, but that ended up producing dozens of core files. I wasn't able to spot an obvious problem from the jitdumps.

Now I'm trying to work back through some recent pull requests to figure out which might have introduced/exposed the problem.

@hzongaro
Copy link
Member

hzongaro commented Dec 14, 2024

I'm able to reproduce this failure intermittently locally. Unfortunately if I try to capture a log file for when it first compiles jdk/nio/zipfs/ZipFileSystem.initCEN, the problem disappears. I was able to capture a little bit of debug information at one of the points in that method where the exception might be thrown.

JVMDUMP055I Processing dump event "throw", detail "java/util/zip/ZipException", exception "invalid CEN header (bad signature) pos == 7586 cen[pos:pos+
3]== {80 75 5 6} limit == 7187368 cen.length == 7608 ENDHDR == 22" at 2024/12/13 17:42:44 - please wait.

This is in the middle of a loop at that's iterating over elements of the array cen. The value of limit is set just before the loop to cen.length - ENDHDR, so it looks like limit is being corrupted, and the loop iterates longer than it is supposed to.

I'll try to see whether I can figure out how that might happen from a jitdump.

@pshipton
Copy link
Member

@hzongaro can you identify the problem change so we can back it out until the problem can be resolved?

@hzongaro
Copy link
Member

I think I've figured out where in the generated code things are going awry, but I haven't yet figured out whether a recent change caused it. I suspect it was a latent problem that's just suddenly become more apparent.

The problem actually occurs before the loop in ZipFileSystem.initCEN. It looks like the array cen is allocated with the correct size (int)(end.cenlen + ENDHDR), but garbage is stored in limit, which should be equal to (cen.length - ENDHDR).

Trees before instruction selection
n1n       BBStart <block_4> (freq 8)                                                          [0x7f4bfb0051f0] bci=[-1,44,1568] rc=0 vc=4537 vn=- li=4 udi=- nc=1
n7612n      GlRegDeps                                                                         [0x7f4bfb653b10] bci=[-1,44,1568] rc=1 vc=4537 vn=- li=4 udi=- nc=1
n7613n        aRegLoad eax   this<'this' parm Ljdk/nio/zipfs/ZipFileSystem;>[#417  Parm] [flags 0xc0000107 0x0 ] (X!=0 X>=0 SeenRealReference )  [0x7f4bfb653b60] bci=[-1,44,1568] rc=9 vc=4537 vn=- li=4 udi=- nc=0 flg=0x8104
n95n      NULLCHK on n91n [#32]                                                               [0x7f4bfb070d70] bci=[-1,48,1568] rc=0 vc=4537 vn=- li=4 udi=- nc=1
n94n        lloadi  jdk/nio/zipfs/ZipFileSystem$END.cenlen J[#432  Shadow +8] [flags 0x604 0x0 ] (cannotOverflow )  [0x7f4bfb070d20] bci=[-1,48,1568] rc=4 vc=4537 vn=- li=4 udi=- nc=1 flg=0x1000
n91n          l2a (X>=0 )                                                                     [0x7f4bfb070c30] bci=[-1,45,1568] rc=3 vc=4537 vn=- li=4 udi=- nc=1 flg=0x100
n9583n          iu2l                                                                          [0x7f4bfb72a320] bci=[-1,45,1568] rc=1 vc=4537 vn=- li=4 udi=- nc=1
n9582n            iloadi  jdk/nio/zipfs/ZipFileSystem.end Ljdk/nio/zipfs/ZipFileSystem$END;[#422  Shadow +76] [flags 0x80607 0x0 ]  [0x7f4bfb72a2d0] bci=[-1,45,1568] rc=1 vc=4537 vn=- li=4 udi=- nc=1
n7613n              ==>aRegLoad
   ...
n2n       BBEnd </block_4>                                                                    [0x7f4bfb005240] bci=[-1,59,1568] rc=0 vc=4537 vn=- li=4 udi=- nc=0
n3n       BBStart <block_6> (freq 8) (extension of previous block)                            [0x7f4bfb005290] bci=[-1,73,1570] rc=0 vc=4537 vn=- li=6 udi=- nc=0
   ...
n4n       BBEnd </block_6>                                                                    [0x7f4bfb0052e0] bci=[-1,108,1575] rc=0 vc=4537 vn=- li=6 udi=- nc=0
n5n       BBStart <block_8> (freq 10) (extension of previous block)                           [0x7f4bfb005330] bci=[-1,122,1579] rc=0 vc=4537 vn=- li=8 udi=- nc=0
n172n     treetop                                                                             [0x7f4bfb072580] bci=[-1,134,1579] rc=0 vc=4537 vn=- li=8 udi=- nc=1
n171n       newarray  jitNewArray[#102  helper Method] [flags 0x400 0x0 ] (X!=0 )             [0x7f4bfb072530] bci=[-1,134,1579] rc=5 vc=4537 vn=- li=8 udi=- nc=2 flg=0x4
n169n         isub                                                                            [0x7f4bfb072490] bci=[-1,133,1579] rc=2 vc=4537 vn=- li=8 udi=- nc=2
n168n           l2i                                                                           [0x7f4bfb072440] bci=[-1,132,1579] rc=3 vc=4537 vn=- li=8 udi=- nc=1
n94n              ==>lloadi
n7085n          iconst -22 (X!=0 X<=0 )                                                       [0x7f4bfb5f9650] bci=[-1,129,1579] rc=1 vc=4537 vn=- li=8 udi=- nc=0 flg=0x204
n170n         iconst 8   ; array type is byte (X!=0 X>=0 )                                    [0x7f4bfb0724e0] bci=[-1,134,1579] rc=1 vc=4537 vn=- li=8 udi=- nc=0 flg=0x104
   ...
n6n       BBEnd </block_8>                                                                    [0x7f4bfb005380] bci=[-1,159,1580] rc=0 vc=4537 vn=- li=8 udi=- nc=0
n7n       BBStart <block_10> (freq 9) (extension of previous block)                           [0x7f4bfb0053d0] bci=[-1,0,1561] rc=0 vc=4537 vn=- li=10 udi=- nc=0
   ...
n7021n    BBEnd </block_10>                                                                   [0x7f4bfb5f8250] bci=[-1,186,1584] rc=0 vc=4537 vn=- li=10 udi=- nc=0
n7020n    BBStart <block_472> (freq 9) (extension of previous block)                          [0x7f4bfb5f8200] bci=[-1,186,1584] rc=0 vc=4537 vn=- li=472 udi=- nc=0
   ...
n236n     istore  limit<auto slot 5>[#452  Auto] [flags 0x3 0x0 ]                             [0x7f4bfb073980] bci=[-1,197,1586] rc=0 vc=4537 vn=- li=472 udi=- nc=1
n168n       ==>l2i

Note that the value stored to limit in block_472 is the original value loaded from end.cenlen, cast to int.

In the Mixed Mode Disassembly, the value of end.cenlen is loaded into rbx, but instruction 0x7f4b8ff08d71 in the outline code for the call to jitNewArray at L0146 reuses rbx before the value is stored in limit.

Code from Mixed Mode Disassembly
0x7f4b8ff06b14 00000154 [0x7f4bfb879280]                                    fence Relative [ 00007F4BFB050210 ] # fence BBStart <block_4> (frequency 8)

 \\ jdk/nio/zipfs/ZipFileSystem.initCEN()[B
 \\   45 JBgetfield 407 jdk/nio/zipfs/ZipFileSystem.end Ljdk/nio/zipfs/ZipFileSystem$END;

0x7f4b8ff06b14 00000154 [0x7f4bfb879860] 41 8b 51 4c                        mov edx, dword ptr [r9+0x4c]                # L4RegMem, SymRef  jdk/nio/zipfs/ZipFileSystem.end Ljdk/nio/zipfs/ZipFileSystem$END;[#1180  Shadow +76] [flags 0x80607 0x0 ]

 \\ jdk/nio/zipfs/ZipFileSystem.initCEN()[B
 \\   48 JBgetfield 336 jdk/nio/zipfs/ZipFileSystem$END.cenlen J

0x7f4b8ff06b18 00000158 [0x7f4bfb879970] 48 8b 5a 08                        mov rbx, qword ptr [rdx+0x8]                # L8RegMem, SymRef  jdk/nio/zipfs/ZipFileSystem$END.cenlen J[#1179  Shadow +8] [flags 0x604 0x0 ]

...

0x7f4b8ff06b41 00000181 [0x7f4bfb87b180]                                    fence Relative [ 00007F4BFB050470 ] # fence BBStart <block_8> (frequency 10) (extension of previous block)

 \\ jdk/nio/zipfs/ZipFileSystem.initCEN()[B
 \\  133 JBl2i

0x7f4b8ff06b41 00000181 [0x7f4bfb87b630] 44 8d 6b 16                        lea r13d, dword ptr [rbx+0x16]              # LEA4RegMem, SymRef [#1184 +22]
0x7f4b8ff06b45 00000185 [0x7f4bfb87b720]                                    Label L0144:                        # label # (Start of internal control flow)

 \\ jdk/nio/zipfs/ZipFileSystem.initCEN()[B
 \\  134 JBnewarray byte

0x7f4b8ff06b45 00000185 [0x7f4bfb87d5b0] 41 81 fd ff ff ff 7f               cmp r13d, 0x7fffffff        # CMP4RegImm4
0x7f4b8ff06b4c 0000018c [0x7f4bfb87d640] 0f 83 1c 22 00 00                  jae Outlined Label L0146                    # JAE4
0x7f4b8ff06b52 00000192 [0x7f4bfb87d770] 48 8b 45 60                        mov rax, qword ptr [rbp+0x60]               # L8RegMem, SymRef [#1185 +96]
0x7f4b8ff06b56 00000196 [0x7f4bfb87d800] 41 8b fd                           mov edi, r13d               # MOV4RegReg
0x7f4b8ff06b59 00000199 [0x7f4bfb87d890] 81 ff 01 00 00 00                  cmp edi, 0x00000001 # CMP4RegImm4
0x7f4b8ff06b5f 0000019f [0x7f4bfb87d920] 81 d7 00 00 00 00                  adc edi, 0x00000000 # ADC4RegImm4
0x7f4b8ff06b65 000001a5 [0x7f4bfb87d9b0] 48 81 c7 0f 00 00 00               add rdi, 0x0000000f # ADD8RegImm4
0x7f4b8ff06b6c 000001ac [0x7f4bfb87da40] 48 81 e7 f8 ff ff ff               and rdi, 0xfffffffffffffff8 # AND8RegImm4
0x7f4b8ff06b73 000001b3 [0x7f4bfb87dad0] 48 8b cf                           mov rcx, rdi                # MOV8RegReg
0x7f4b8ff06b76 000001b6 [0x7f4bfb87db60] 48 03 f8                           add rdi, rax                # ADD8RegReg
0x7f4b8ff06b79 000001b9 [0x7f4bfb87dc80] 48 3b 7d 68                        cmp rdi, qword ptr [rbp+0x68]               # CMP8RegMem, SymRef [#1186 +104]
0x7f4b8ff06b7d 000001bd [0x7f4bfbb535a0]                                    vfpSave                     # AdjustFramePtr
0x7f4b8ff06b7d 000001bd [0x7f4bfb87dd10] 0f 87 eb 21 00 00                  ja  Outlined Label L0146                    # JA4
0x7f4b8ff06b83 000001c3 [0x7f4bfbb54e50] 48 89 9c 24 10 01 00 00            mov qword ptr [rsp+0x110], rbx              # S8MemReg, #SPILL8, SymRef  <#SPILL8_2004 0x7f4bfbb30e90>[#2004  Auto +272] [flags 0x80000000 0x0 ]
...

 \\ jdk/nio/zipfs/ZipFileSystem.initCEN()[B
 \\  197 JBistore 5

0x7f4b8ff06c69 000002a9 [0x7f4bfb898bb0] 89 5c 24 7c                        mov dword ptr [rsp+0x7c], ebx               # S4MemReg, SymRef  limit<auto slot 5>[#1215  Auto +124] [flags 0x3 0x0 ]

...

0x7f4b8ff08d6e 000023ae [0x7f4bfb87b990]                                    Outlined Label L0146:                       # label

 \\ jdk/nio/zipfs/ZipFileSystem.initCEN()[B
 \\    0 JBaload0

0x7f4b8ff08d6e 000023ae [0x7f4bfbb54cc0] 4d 8b f9                           mov r15, r9         # MOV8RegReg
0x7f4b8ff08d71 000023b1 [0x7f4bfbb54c30] 48 8b df                           mov rbx, rdi                # MOV8RegReg
0x7f4b8ff08d74 000023b4 [0x7f4bfbb54ba0] 4c 8b f1                           mov r14, rcx                # MOV8RegReg
0x7f4b8ff08d77 000023b7 [0x7f4bfbb54b10] 48 89 84 24 f8 00 00 00            mov qword ptr [rsp+0xf8], rax               # S8MemReg, #SPILL8, SymRef  <#SPILL8_2003 0x7f4bfbb30c40>[#2003  Auto +248] [flags 0x80000000 0x0 ]

 \\ jdk/nio/zipfs/ZipFileSystem.initCEN()[B
 \\  134 JBnewarray byte

0x7f4b8ff08d7f 000023bf [0x7f4bfb87baf0] ba 08 00 00 00                     mov edx, 0x00000008 # MOV4RegImm4
0x7f4b8ff08d84 000023c4 [0x7f4bfb87c910] 49 8b f5                           mov rsi, r13                # MOV8RegReg
0x7f4b8ff08d87 000023c7 [0x7f4bfb87c9a0] 48 8b fd                           mov rdi, rbp                # MOV8RegReg
0x7f4b8ff08d8a 000023ca [0x7f4bfb87d1b0]                                    assocreg                        # assocreg
0x7f4b8ff08d8a 000023ca [0x7f4bfb87cf50] e8 e1 3e ae 7b                     call        jitNewArray             # CALLImm4 (00007F4C0B9ECC70)# CALLImm4
0x7f4b8ff08d8f 000023cf [0x7f4bfbb54970] 4d 8b cf                           mov r9, r15         # MOV8RegReg
0x7f4b8ff08d92 000023d2 [0x7f4bfbb548a0] 4c 8b bc 24 f8 00 00 00            mov r15, qword ptr [rsp+0xf8]               # L8RegMem, #SPILL8, SymRef  <#SPILL8_2002 0x7f4bfbb30c40>[#2002  Auto +248] [flags 0x80000000 0x0 ]#, spilled for acall
0x7f4b8ff08d9a 000023da [0x7f4bfbb54780] 48 8b fb                           mov rdi, rbx                # MOV8RegReg
0x7f4b8ff08d9d 000023dd [0x7f4bfbb546f0] 49 8b d7                           mov rdx, r15                # MOV8RegReg
0x7f4b8ff08da0 000023e0 [0x7f4bfbb54660] 49 8b ce                           mov rcx, r14                # MOV8RegReg
0x7f4b8ff08da3 000023e3 [0x7f4bfbb545d0] 48 87 c2                           xchg        rdx, rax                # XCHG8RegReg
0x7f4b8ff08da6 000023e6 [0x7f4bfb87d380] 48 8b c2                           mov rax, rdx                # MOV8RegReg
0x7f4b8ff08da9 000023e9 [0x7f4bfb87d410] e9 28 de ff ff                     jmp Label L0145                     # JMP4

I'm just trying to get traces of Register Allocation to figure out how things go wrong.

@hzongaro
Copy link
Member

I've figured out the cause of the problem. It was in fact a recent change, shortly prior to the range of OpenJ9 commits e1af88f...6a1113a

The relevant instructions before register allocation:

 [0x7f3cd2f7a180]       fence Relative [ 00007F3CD274F470 ]     # fence BBStart <block_8> (frequency 9) (extension of previous block)
 [0x7f3cd2f7a630]       lea     GPR_0146, dword ptr [GPR_0114+0x16]             # LEA4RegMem, SymRef [#1184 +22]
 [0x7f3cd2f7a720]       Label L0144:                    # label # (Start of internal control flow)
 [0x7f3cd2f7c5b0]       cmp     GPR_0146, 0x7fffffff    # CMP4RegImm4
 [0x7f3cd2f7c640]       jae     Outlined Label L0146                    # JAE4
 [0x7f3cd2f7c770]       mov     GPR_0147, qword ptr [GPR_0000+0x60]             # L8RegMem, SymRef [#1185 +96]
 [0x7f3cd2f7c800]       mov     GPR_0144, GPR_0146              # MOV4RegReg
 [0x7f3cd2f7c890]       cmp     GPR_0144, 0x00000001    # CMP4RegImm4
 [0x7f3cd2f7c920]       adc     GPR_0144, 0x00000000    # ADC4RegImm4
 [0x7f3cd2f7c9b0]       add     GPR_0144, 0x0000000f    # ADD8RegImm4
 [0x7f3cd2f7ca40]       and     GPR_0144, 0xfffffffffffffff8    # AND8RegImm4
 [0x7f3cd2f7cad0]       mov     GPR_0145, GPR_0144              # MOV8RegReg
 [0x7f3cd2f7cb60]       add     GPR_0144, GPR_0147              # ADD8RegReg
 [0x7f3cd2f7cc80]       cmp     GPR_0144, qword ptr [GPR_0000+0x68]             # CMP8RegMem, SymRef [#1186 +104]
 [0x7f3cd2f7cd10]       ja      Outlined Label L0146                    # JA4
 [0x7f3cd2f7ce40]       prefetchnta     dword ptr [GPR_0144+0xc0]               # PREFETCHNTA, SymRef [#1187 +192]
 [0x7f3cd2f7cf60]       mov     qword ptr [GPR_0000+0x60], GPR_0144             # S8MemReg, SymRef [#1188 +96]
 [0x7f3cd2f7d080]       prefetchnta     dword ptr [GPR_0144+0x100]              # PREFETCHNTA, SymRef [#1189 +256]
 [0x7f3cd2f7d1a0]       prefetchnta     dword ptr [GPR_0144+0x140]              # PREFETCHNTA, SymRef [#1190 +320]
 [0x7f3cd2f7d2c0]       prefetchnta     dword ptr [GPR_0144+0x180]              # PREFETCHNTA, SymRef [#1191 +384]
 [0x7f3cd2f7d350]       sub     GPR_0145, 0x00000008    # SUB8RegImms
 [0x7f3cd2f7d540]       cmp     GPR_0145, 0x00000040    # CMP8RegImms
 [0x7f3cd2f7d5d0]       jg      Outlined Label L0148                    # JG4
 [0x7f3cd2f7d700]       lea     GPR_0144, qword ptr [GPR_0147+0x8]              # LEA8RegMem, SymRef [#1192 +8]
 [0x7f3cd2f7d790]       xor     GPR_0175, GPR_0175              # XOR4RegReg
 [0x7f3cd2f7d880]       Label L0150:                    # label
 [0x7f3cd2f7d9b0]       mov     qword ptr [GPR_0144], GPR_0175          # S8MemReg
 [0x7f3cd2f7da40]       add     GPR_0144, 0x00000008    # ADD8RegImms
 [0x7f3cd2f7dad0]       sub     GPR_0145, 0x00000008    # SUB8RegImms
 [0x7f3cd2f7db60]       jg      Label L0150                     # JG4
 [0x7f3cd2f7e200]       Label L0149:                    # label
 [0x7f3cd2f7e330]       mov     dword ptr [GPR_0147], 0x00049300        # S4MemImm4
 [0x7f3cd2f7e4e0]       mov     dword ptr [GPR_0147+0x4], GPR_0146              # S4MemReg, SymRef [#1196 +4]
 [0x7f3cd2f7e910]       assocreg                        # assocreg
        POST: [GPR_0149 : eax] [GPR_0150 : ecx] [GPR_0151 : edx] [GPR_0152 : edi] [GPR_0153 : esi] [GPR_0154 : r8d] [GPR_0155 : r9d] [GPR_0156 : r10d] [GPR_0157 : r11d]
 [0x7f3cd2f7e6b0]       Label L0145:                    # label # (End of internal control flow)

and after register allocation

 [0x7f3cd2f7a180]       fence Relative [ 00007F3CD274F470 ]     # fence BBStart <block_8> (frequency 9) (extension of previous block)
[0x7f3cd2f7a630]       lea     r13d, dword ptr [rbx+0x16]              # LEA4RegMem, SymRef [#1184 +22]
[0x7f3cd2f7a720]       Label L0144:                    # label # (Start of internal control flow)
[0x7f3cd2f7c5b0]       cmp     r13d, 0x7fffffff        # CMP4RegImm4
[0x7f3cd2f7c640]       jae     Outlined Label L0146                    # JAE4
[0x7f3cd2f7c770]       mov     rax, qword ptr [rbp+0x60]               # L8RegMem, SymRef [#1185 +96]
[0x7f3cd2f7c800]       mov     edi, r13d               # MOV4RegReg
[0x7f3cd2f7c890]       cmp     edi, 0x00000001 # CMP4RegImm4
[0x7f3cd2f7c920]       adc     edi, 0x00000000 # ADC4RegImm4
[0x7f3cd2f7c9b0]       add     rdi, 0x0000000f # ADD8RegImm4
[0x7f3cd2f7ca40]       and     rdi, 0xfffffffffffffff8 # AND8RegImm4
[0x7f3cd2f7cad0]       mov     rcx, rdi                # MOV8RegReg
[0x7f3cd2f7cb60]       add     rdi, rax                # ADD8RegReg
[0x7f3cd2f7cc80]       cmp     rdi, qword ptr [rbp+0x68]               # CMP8RegMem, SymRef [#1186 +104]
[0x7f3cd32b4270]       vfpSave                 # AdjustFramePtr
[0x7f3cd2f7cd10]       ja      Outlined Label L0146                    # JA4
[0x7f3cd32b7090]       mov     qword ptr [vfp], rbx            # S8MemReg, #SPILL8, SymRef  <#SPILL8_2004 0x7f3cd3258660>[#2004  Auto] [flags 0x80000000 0x0 ]
[0x7f3cd2f7ce40]       prefetchnta     dword ptr [rdi+0xc0]            # PREFETCHNTA, SymRef [#1187 +192]
[0x7f3cd2f7cf60]       mov     qword ptr [rbp+0x60], rdi               # S8MemReg, SymRef [#1188 +96]
[0x7f3cd2f7d080]       prefetchnta     dword ptr [rdi+0x100]           # PREFETCHNTA, SymRef [#1189 +256]
[0x7f3cd2f7d1a0]       prefetchnta     dword ptr [rdi+0x140]           # PREFETCHNTA, SymRef [#1190 +320]
[0x7f3cd2f7d2c0]       prefetchnta     dword ptr [rdi+0x180]           # PREFETCHNTA, SymRef [#1191 +384]
[0x7f3cd2f7d350]       sub     rcx, 0x00000008 # SUB8RegImms
[0x7f3cd2f7d540]       cmp     rcx, 0x00000040 # CMP8RegImms
[0x7f3cd32b2650]       vfpSave                 # AdjustFramePtr
[0x7f3cd2f7d5d0]       jg      Outlined Label L0148                    # JG4
[0x7f3cd2f7d700]       lea     rdi, qword ptr [rax+0x8]                # LEA8RegMem, SymRef [#1192 +8]
[0x7f3cd2f7d790]       xor     edx, edx                # XOR4RegReg
[0x7f3cd2f7d880]       Label L0150:                    # label
[0x7f3cd2f7d9b0]       mov     qword ptr [rdi], rdx            # S8MemReg
[0x7f3cd2f7da40]       add     rdi, 0x00000008 # ADD8RegImms
[0x7f3cd2f7dad0]       sub     rcx, 0x00000008 # SUB8RegImms
[0x7f3cd2f7db60]       jg      Label L0150                     # JG4
[0x7f3cd2f7e200]       Label L0149:                    # label
[0x7f3cd2f7e330]       mov     dword ptr [rax], 0x00049300     # S4MemImm4
[0x7f3cd2f7e4e0]       mov     dword ptr [rax+0x4], r13d               # S4MemReg, SymRef [#1196 +4]
[0x7f3cd2f7e910]       assocreg                        # assocreg
[0x7f3cd2f7e6b0]       Label L0145:                    # label # (End of internal control flow)

Looking at the trace of register allocation, notice that at the jump to L0150 below, the allocator is marking GPR_0114 as eligible for better spill placement. However, better spill placement is only supposed to be enabled outside of sections of code marked as "Internal control flow". Looking at the instructions above, L0144 and L0145 are marked as the start and end of internal control flow, respectively, and the jump to L0150 appears between them.

 [0x7f3cd2f7e910]       assocreg                        # assocreg
 [0x7f3cd2f7e910]       assocreg                        # assocreg
 [0x7f3cd2f7e4e0]       mov     dword ptr [GPR_0147+0x4], GPR_0146              # S4MemReg, SymRef [#1196 +4]
 [0x7f3cd2f7e4e0]       mov     dword ptr [rax+0x4], r13d               # S4MemReg, SymRef [#1196 +4]
 [0x7f3cd2f7e330]       mov     dword ptr [GPR_0147], 0x00049300        # S4MemImm4
 [0x7f3cd2f7e330]       mov     dword ptr [rax], 0x00049300     # S4MemImm4
 [0x7f3cd2f7e200]       Label L0149:                    # label
 [0x7f3cd2f7e200]       Label L0149:                    # label
 [0x7f3cd2f7db60]       jg      Label L0150                     # JG4details:                      Saved better spill placement for GPR_0114, mask = cd22.

The reason the register allocator thinks that that jump is not within a range of instructions marked for internal control flow is that later in the instruction stream there appears a Start of internal control flow label that is missing its corresponding End of internal control flow label:

 [0x7f3cd3023a60]       Label L0637:                    # label # (Start of internal control flow)
 [0x7f3cd3023b00]       cmp     eax, esi                # CMP4RegReg
 [0x7f3cd3023b90]       jge     Label L0638                     # JGE4
 [0x7f3cd3023c30]       Label L0639:                    # label
 [0x7f3cd3023cd0]       imul    edi, edi, 0x0000001f    # IMUL4RegRegImm4
 [0x7f3cd3023e00]       movsx   ecx, byte ptr [rbx+1*rax+0x8]           # MOVSXReg4Mem1, SymRef [#1384 +8]
 [0x7f3cd3023e90]       add     rdi, rcx                # ADD8RegReg
 [0x7f3cd3023f20]       inc     rax                     # INC8Reg
 [0x7f3cd3023fb0]       cmp     eax, esi                # CMP4RegReg
 [0x7f3cd3024040]       jl      Label L0639                     # JL4
 [0x7f3cd3024340]       assocreg                        # assocreg
 [0x7f3cd30240e0]       Label L0638:                    # label
 [0x7f3cd3025bf0]       mov     edi, edi                # MOVZXReg8Reg4
 [0x7f3cd3025ec0]       mov     rax, qword ptr [vfp]            # L8RegMem, SymRef  this<'this' parm Ljdk/nio/zipfs/ZipFileSystem;>[#1385  Parm] [flags 0xc0000107 0x0 ]
 [0x7f3cd30265b0]       assocreg                        # assocreg
 [0x7f3cd3026340]       vgnop Site:00007F3CD3026230, Label L0038        # vgnop
 [0x7f3cd3026800]       fence Relative [ 00007F3CD2C47014 ]     # fence BBEnd </block_333>

I'm just testing a fix and will open a pull request. The problem only affects JDK 21 and 23 on x86.

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.

4 participants