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.27k stars 721 forks source link

cmdLineTester_criu_nonPortableRestore_4_FAILED Can't read request: Bad address Segmentation error vmState=0x00000000 #18322

Open JasonFengJ9 opened 11 months ago

JasonFengJ9 commented 11 months ago

Failure link

From an internal build(ubu22s390x-svl-rt6-1):

java version "11.0.21" 2023-10-17
IBM Semeru Runtime Certified Edition 11.0.21.0 (build 11.0.21+9)
Eclipse OpenJ9 VM 11.0.21.0 (build v0.41.0-release-9c5799b80, JRE 11 Linux s390x-64-Bit Compressed References 20231018_672 (JIT enabled, AOT enabled)
OpenJ9   - 9c5799b80
OMR      - fa7b6ddc7
JCL      - 6f4cc08025 based on jdk-11.0.21+9)

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

Optional info

Failure output (captured from console output)

[2023-10-18T22:10:57.650Z] variation: -Xjit:count=0 -XX:+CRIURestoreNonPortableMode
[2023-10-18T22:10:57.650Z] JVM_OPTIONS:  -Xjit:count=0 -XX:+CRIURestoreNonPortableMode 

[2023-10-18T22:47:05.446Z] Testing: criuCheckpoint dump options test with no dump options specified before checkpoint
[2023-10-18T22:47:05.446Z] Test start time: 2023/10/18 22:46:50 Coordinated Universal Time
[2023-10-18T22:47:05.446Z] Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -XX:+CRIURestoreNonPortableMode  -Xdump:java:events=criuRestore" org.openj9.criu.OptionsFileTest criuDumpOptionsTest 1
[2023-10-18T22:47:05.446Z] Time spent starting: 21 milliseconds
[2023-10-18T22:49:19.552Z] Time spent executing: 144608 milliseconds
[2023-10-18T22:49:19.552Z] Test result: FAILED
[2023-10-18T22:49:19.552Z] Output from test:
[2023-10-18T22:49:19.552Z]  [OUT] start running script
[2023-10-18T22:49:19.552Z]  [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
[2023-10-18T22:49:19.552Z]  [OUT] export LD_BIND_NOT=on
[2023-10-18T22:49:19.552Z]  [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/openjdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xjit:count=0 -XX:+CRIURestoreNonPortableMode  -Xdump:java:events=criuRestore -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.OptionsFileTest criuDumpOptionsTest 1
[2023-10-18T22:49:19.552Z]  [OUT] Pre-checkpoint
[2023-10-18T22:49:19.552Z]  [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Wed Oct 18 22:48:02 UTC 2023, System.currentTimeMillis(): 1697669282517, System.nanoTime(): 1697669168496735614
[2023-10-18T22:49:19.552Z]  [OUT] Can't read request: Bad address
[2023-10-18T22:49:19.552Z]  [OUT] Can't receive response: Invalid argument
[2023-10-18T22:49:19.552Z]  [OUT] Unhandled exception
[2023-10-18T22:49:19.552Z]  [OUT] Type=Segmentation error vmState=0x00000000
[2023-10-18T22:49:19.552Z]  [OUT] J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
[2023-10-18T22:49:19.552Z]  [OUT] Handler1=000003FFA4ECD9A0 Handler2=000003FFA4DB33D8 InaccessibleAddress=0000000000000000
[2023-10-18T22:49:19.552Z]  [OUT] gpr0=0000000000000081 gpr1=0000000000000000 gpr2=0000000000000000 gpr3=0000000000000000
[2023-10-18T22:49:19.552Z]  [OUT] gpr4=000003FF00000000 gpr5=0000000000000000 gpr6=0000000000000000 gpr7=0000000000000000
[2023-10-18T22:49:19.552Z]  [OUT] gpr8=0000000000000000 gpr9=000003FF40007EA8 gpr10=000003FFA0254760 gpr11=000003FFA0254738
[2023-10-18T22:49:19.552Z]  [OUT] gpr12=000003FFA5B30F90 gpr13=000000000000001C gpr14=000003FFA5715714 gpr15=000003FFA4C7E5A8
[2023-10-18T22:49:19.552Z]  [OUT] psw=000003FFA571224E mask=0705000180000000 fpc=00000000 bea=000003FFA571570E
[2023-10-18T22:49:19.552Z]  [OUT] fpr0 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr1 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr2 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr3 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr4 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr5 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr6 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr7 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr11 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] fpr15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.552Z]  [OUT] Module=/lib/s390x-linux-gnu/libc.so.6
[2023-10-18T22:49:19.552Z]  [OUT] Module_base_address=000003FFA5680000 Symbol=_pthread_cleanup_pop
[2023-10-18T22:49:19.552Z]  [OUT] Symbol_address=000003FFA5712240
[2023-10-18T22:49:19.552Z]  [OUT] Target=2_90_20231018_672 (Linux 5.15.0-86-generic)
[2023-10-18T22:49:19.552Z]  [OUT] CPU=s390x (4 logical CPUs) (0x1f5c26000 RAM)
[2023-10-18T22:49:19.553Z]  [OUT] ----------- Stack Backtrace -----------
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP039I Processing dump event "abort", detail "" at 2023/10/18 22:48:49 - please wait.
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/core.20231018.224849.1402571.0001.dmp' in response to an event
[2023-10-18T22:49:19.553Z]  [OUT] _pthread_cleanup_pop+0xe (0x000003FFA571224E [libc.so.6+0x9224e])
[2023-10-18T22:49:19.553Z]  [OUT] pthread_cond_wait+0x254 (0x000003FFA5715714 [libc.so.6+0x95714])
[2023-10-18T22:49:19.553Z]  [OUT] omrthread_monitor_wait+0x354 (0x000003FFA4D09C14 [libj9thr29.so+0x9c14])
[2023-10-18T22:49:19.553Z]  [OUT] internalAcquireVMAccessNoMutexWithMask+0x84 (0x000003FFA4F1C44C [libj9vm29.so+0x9c44c])
[2023-10-18T22:49:19.553Z]  [OUT] internalAcquireVMAccess+0x78 (0x000003FFA4F1C250 [libj9vm29.so+0x9c250])
[2023-10-18T22:49:19.553Z]  [OUT] FinalizeWorkerThreadGlue+0x2a6 (0x000003FF9EDB1D1E [libj9gc29.so+0x31d1e])
[2023-10-18T22:49:19.553Z]  [OUT] omrsig_protect+0x366 (0x000003FFA4DB4546 [libj9prt29.so+0x34546])
[2023-10-18T22:49:19.553Z]  [OUT] gpProtectedFinalizeWorkerThread+0x52 (0x000003FF9EDB1432 [libj9gc29.so+0x31432])
[2023-10-18T22:49:19.553Z]  [OUT] thread_wrapper+0x114 (0x000003FFA4D05A14 [libj9thr29.so+0x5a14])
[2023-10-18T22:49:19.553Z]  [OUT]  (0x000003FFA5716296 [libc.so.6+0x96296])
[2023-10-18T22:49:19.553Z]  [OUT]  (0x000003FFA578FD5E [libc.so.6+0x10fd5e])
[2023-10-18T22:49:19.553Z]  [OUT] ---------------------------------------
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP039I Processing dump event "gpf", detail "" at 2023/10/18 22:48:49 - please wait.
[2023-10-18T22:49:19.553Z]  [OUT] Exception in thread "main" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-70
[2023-10-18T22:49:19.553Z]  [OUT]   at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
[2023-10-18T22:49:19.553Z]  [OUT]   at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:679)
[2023-10-18T22:49:19.553Z]  [OUT]   at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:77)
[2023-10-18T22:49:19.553Z]  [OUT]   at org.openj9.criu.OptionsFileTest.criuDumpOptionsTest(OptionsFileTest.java:265)
[2023-10-18T22:49:19.553Z]  [OUT]   at org.openj9.criu.OptionsFileTest.main(OptionsFileTest.java:63)
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/core.20231018.224849.1402571.0001.dmp
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/javacore.20231018.224849.1402571.0003.txt' in response to an event
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/core.20231018.224849.1402571.0002.dmp' in response to an event
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP010I System dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/core.20231018.224849.1402571.0002.dmp
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/javacore.20231018.224849.1402571.0004.txt' in response to an event
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/javacore.20231018.224849.1402571.0004.txt
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/Snap.20231018.224849.1402571.0005.trc' in response to an event
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/Snap.20231018.224849.1402571.0005.trc
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP032I JVM requested JIT dump using '/home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/jitdump.20231018.224849.1402571.0006.dmp' in response to an event
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP051I JIT dump occurred in 'Finalizer thread' thread 0x0000000001EDFE00
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP010I JIT dump written to /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_testList_0/aqa-tests/TKG/output_16976665965882/cmdLineTester_criu_nonPortableRestore_4/jitdump.20231018.224849.1402571.0006.dmp
[2023-10-18T22:49:19.553Z]  [OUT] JVMDUMP013I Processed dump event "gpf", detail "".
[2023-10-18T22:49:19.553Z]  [OUT] Unhandled exception
[2023-10-18T22:49:19.553Z]  [OUT] Type=Segmentation error vmState=0x00000000
[2023-10-18T22:49:19.553Z]  [OUT] J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
[2023-10-18T22:49:19.553Z]  [OUT] Handler1=000003FFA4ECD610 Handler2=000003FFA4DB33D8 InaccessibleAddress=0000000000000000
[2023-10-18T22:49:19.553Z]  [OUT] gpr0=000003FFA4E09A44 gpr1=0000000000000000 gpr2=0000000000000000 gpr3=0000000000000000
[2023-10-18T22:49:19.553Z]  [OUT] gpr4=000003FF00000000 gpr5=0000000000000000 gpr6=0000000000000000 gpr7=0000000000000000
[2023-10-18T22:49:19.553Z]  [OUT] gpr8=0000000000000000 gpr9=000003FF6C002478 gpr10=000003FFA00E9428 gpr11=000003FFA00E9400
[2023-10-18T22:49:19.553Z]  [OUT] gpr12=000003FF9FF75000 gpr13=0000000000000000 gpr14=000003FFA5715714 gpr15=000003FF8266E5B8
[2023-10-18T22:49:19.553Z]  [OUT] psw=000003FFA571224E mask=0705000180000000 fpc=00000000 bea=000003FFA571570E
[2023-10-18T22:49:19.553Z]  [OUT] fpr0 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr1 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr2 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr3 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr4 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr5 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr6 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr7 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr11 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] fpr15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-10-18T22:49:19.553Z]  [OUT] Module=/lib/s390x-linux-gnu/libc.so.6
[2023-10-18T22:49:19.553Z]  [OUT] Module_base_address=000003FFA5680000 Symbol=_pthread_cleanup_pop
[2023-10-18T22:49:19.553Z]  [OUT] Symbol_address=000003FFA5712240
[2023-10-18T22:49:19.553Z]  [OUT] Target=2_90_20231018_672 (Linux 5.15.0-86-generic)
[2023-10-18T22:49:19.553Z]  [OUT] CPU=s390x (4 logical CPUs) (0x1f5c26000 RAM)
[2023-10-18T22:49:19.553Z]  [OUT] ----------- Stack Backtrace -----------
[2023-10-18T22:49:19.553Z]  [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
[2023-10-18T22:49:19.553Z]  [OUT] Removed test output files
[2023-10-18T22:49:19.553Z]  [OUT] finished script
[2023-10-18T22:49:19.553Z] >> Success condition was not found: [Output match: Killed]
[2023-10-18T22:49:19.553Z] >> Required condition was found: [Output match: Pre-checkpoint]
[2023-10-18T22:49:19.553Z] >> Success condition was not found: [Output match: Processing dump event "criuRestore"]
[2023-10-18T22:49:19.553Z] >> Success condition was not found: [Output match: Post-checkpoint]
[2023-10-18T22:49:19.553Z] >> Failure condition was not found: [Output match: org.eclipse.openj9.criu.JVMRestoreException]
[2023-10-18T22:49:19.553Z] >> Failure condition was not found: [Output match: CRIU is not enabled]
[2023-10-18T22:49:19.553Z] >> Failure condition was not found: [Output match: Operation not permitted]
[2023-10-18T22:49:19.553Z] >> Success condition was not found: [Output match: Thread pid mismatch]
[2023-10-18T22:49:19.553Z] >> Success condition was not found: [Output match: do not match expected]
[2023-10-18T22:49:19.553Z] >> Success condition was not found: [Output match: Unable to create a thread:]
[2023-10-18T22:49:19.553Z] >> Failure condition was found: [Output match: Could not dump the JVM processes, err=-70]
[2023-10-18T22:49:19.553Z] >> Failure condition was not found: [Output match: User requested Java dump using]

[2023-10-18T22:56:30.524Z] cmdLineTester_criu_nonPortableRestore_4_FAILED

50x internal grinder - not reproduced

r30shah commented 10 months ago

FYI @VermaSh