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

cmdLineTester_criu_nonPortableRestore CheckpointDeadlock Success conditions not found #19618

Open
pshipton opened this issue Jun 4, 2024 · 13 comments
Assignees
Labels
criu Used to track CRIU snapshot related work test failure

Comments

@pshipton
Copy link
Member

pshipton commented Jun 4, 2024

https://openj9-jenkins.osuosl.org/job/Test_openjdk22_j9_sanity.functional_aarch64_linux_Nightly_testList_1/88
cmdLineTester_criu_nonPortableRestore_10

00:49:16  Testing: Create and Restore Criu Checkpoint Image once - CheckpointDeadlock
00:49:16  Test start time: 2024/06/04 00:49:13 Eastern Standard Time
00:49:16  Running command: bash /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest CheckpointDeadlock 1 false false
00:49:16  Time spent starting: 4 milliseconds
00:50:17  Time spent executing: 54528 milliseconds
00:50:17  Test result: FAILED
00:50:17  Output from test:
00:50:17   [OUT] start running script
00:50:17   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
00:50:17   [OUT] export LD_BIND_NOT=on
00:50:17   [OUT] /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest CheckpointDeadlock 1
00:50:17   [OUT] Pre-checkpoint
00:50:17   [OUT] main: Tue Jun 04 00:49:40 EDT 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1717476598388, System.nanoTime(): 100179210725040
00:50:17   [OUT] Precheckpoint hook inside monitor
00:50:17   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
00:50:17   [OUT] TEST FAILED
00:50:17   [OUT] initiate restore
00:50:17   [OUT] Removed test output files
00:50:17   [OUT] finished script
00:50:17   [ERR] /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 1484409 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
00:50:17  >> Success condition was not found: [Output match: User requested Java dump using]
00:50:17  >> Success condition was not found: [Output match: TEST PASSED]
00:50:17  >> Required condition was found: [Output match: Pre-checkpoint]
00:50:17  >> Failure condition was found: [Output match: Killed]
00:50:17  >> Failure condition was not found: [Output match: CRIU is not enabled]
00:50:17  >> Failure condition was not found: [Output match: Operation not permitted]
00:50:17  >> Success condition was not found: [Output match: Thread pid mismatch]
00:50:17  >> Success condition was not found: [Output match: do not match expected]
00:50:17  >> Success condition was not found: [Output match: Unable to create a thread:]
00:50:17  >> Failure condition was found: [Output match: TEST FAILED]
00:50:17  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]
@pshipton pshipton added test failure criu Used to track CRIU snapshot related work labels Jun 4, 2024
@pshipton
Copy link
Member Author

pshipton commented Jun 4, 2024

@tajila fyi

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/696 - ub22-aarch64-1
cmdLineTester_criu_nonPortableRestore_10

01:08:57  Testing: Create and Restore Criu Checkpoint Image once - CheckpointDeadlock
01:08:57  Test start time: 2024/06/26 05:08:52 Coordinated Universal Time
01:08:57  Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest CheckpointDeadlock 1 false false
01:08:57  Time spent starting: 6 milliseconds
01:10:09  Time spent executing: 72178 milliseconds
01:10:09  Test result: FAILED
01:10:09  Output from test:
01:10:09   [OUT] start running script
01:10:09   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
01:10:09   [OUT] export LD_BIND_NOT=on
01:10:09   [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest CheckpointDeadlock 1
01:10:09   [OUT] Pre-checkpoint
01:10:09   [OUT] main: Wed Jun 26 05:09:27 UTC 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1719378567251, System.nanoTime(): 2002155077664178
01:10:09   [OUT] Precheckpoint hook inside monitor
01:10:09   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
01:10:09   [OUT] TEST FAILED
01:10:09   [OUT] initiate restore
01:10:09   [OUT] Removed test output files
01:10:09   [OUT] finished script
01:10:09   [ERR] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 4182119 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
01:10:09  >> Success condition was not found: [Output match: User requested Java dump using]
01:10:09  >> Success condition was not found: [Output match: TEST PASSED]
01:10:09  >> Required condition was found: [Output match: Pre-checkpoint]
01:10:09  >> Failure condition was found: [Output match: Killed]
01:10:09  >> Failure condition was not found: [Output match: CRIU is not enabled]
01:10:09  >> Failure condition was not found: [Output match: Operation not permitted]
01:10:09  >> Success condition was not found: [Output match: Thread pid mismatch]
01:10:09  >> Success condition was not found: [Output match: do not match expected]
01:10:09  >> Success condition was not found: [Output match: Unable to create a thread:]
01:10:09  >> Failure condition was found: [Output match: TEST FAILED]
01:10:09  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

@JasonFengJ9
Copy link
Member

JasonFengJ9 commented Jun 26, 2024

JDK22 aarch64_linux(sles15-aarch64-6)

[2024-06-22T18:22:11.284Z] variation: -XX:+DebugOnRestore -Xjit:count=0
[2024-06-22T18:22:11.284Z] JVM_OPTIONS:  -XX:+DebugOnRestore -Xjit:count=0 

[2024-06-22T18:39:25.468Z] Testing: Create and Restore Criu Checkpoint Image once - CheckpointDeadlock
[2024-06-22T18:39:25.468Z] Test start time: 2024/06/22 18:39:13 Coordinated Universal Time
[2024-06-22T18:39:25.468Z] Running command: bash /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_testList_0/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest CheckpointDeadlock 1 false false
[2024-06-22T18:39:25.468Z] Time spent starting: 5 milliseconds
[2024-06-22T18:40:41.359Z] Time spent executing: 79379 milliseconds
[2024-06-22T18:40:41.359Z] Test result: FAILED
[2024-06-22T18:40:41.359Z] Output from test:
[2024-06-22T18:40:41.359Z]  [OUT] start running script
[2024-06-22T18:40:41.359Z]  [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
[2024-06-22T18:40:41.359Z]  [OUT] export LD_BIND_NOT=on
[2024-06-22T18:40:41.359Z]  [OUT] /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_testList_0/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest CheckpointDeadlock 1
[2024-06-22T18:40:41.359Z]  [OUT] Pre-checkpoint
[2024-06-22T18:40:41.359Z]  [OUT] main: Sat Jun 22 18:39:51 UTC 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1719081609416, System.nanoTime(): 911980863383290
[2024-06-22T18:40:41.359Z]  [OUT] Precheckpoint hook inside monitor
[2024-06-22T18:40:41.359Z]  [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
[2024-06-22T18:40:41.359Z]  [OUT] TEST FAILED
[2024-06-22T18:40:41.359Z]  [OUT] initiate restore
[2024-06-22T18:40:41.359Z]  [OUT] Removed test output files
[2024-06-22T18:40:41.359Z]  [OUT] finished script
[2024-06-22T18:40:41.359Z]  [ERR] /home/jenkins/workspace/Test_openjdk22_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 17655 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
[2024-06-22T18:40:41.359Z] >> Success condition was not found: [Output match: User requested Java dump using]
[2024-06-22T18:40:41.359Z] >> Success condition was not found: [Output match: TEST PASSED]
[2024-06-22T18:40:41.359Z] >> Required condition was found: [Output match: Pre-checkpoint]
[2024-06-22T18:40:41.359Z] >> Failure condition was found: [Output match: Killed]
[2024-06-22T18:40:41.359Z] >> Failure condition was not found: [Output match: CRIU is not enabled]
[2024-06-22T18:40:41.359Z] >> Failure condition was not found: [Output match: Operation not permitted]
[2024-06-22T18:40:41.359Z] >> Success condition was not found: [Output match: Thread pid mismatch]
[2024-06-22T18:40:41.359Z] >> Success condition was not found: [Output match: do not match expected]
[2024-06-22T18:40:41.359Z] >> Success condition was not found: [Output match: Unable to create a thread:]
[2024-06-22T18:40:41.359Z] >> Failure condition was found: [Output match: TEST FAILED]
[2024-06-22T18:40:41.360Z] >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

[2024-06-22T19:37:17.633Z] cmdLineTester_criu_nonPortableRestore_10_FAILED

15x grinder - passed

@pshipton
Copy link
Member Author

pshipton commented Aug 2, 2024

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_aarch64_linux_OMR_testList_0/510
cmdLineTester_criu_nonPortableRestore_10

07:13:29  Testing: Create and Restore Criu Checkpoint Image once - CheckpointDeadlock
07:13:29  Test start time: 2024/08/02 11:13:20 Coordinated Universal Time
07:13:29  Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_aarch64_linux_OMR_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_aarch64_linux_OMR_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_aarch64_linux_OMR_testList_0/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest CheckpointDeadlock 1 false false
07:13:29  Time spent starting: 4 milliseconds
07:14:30  Time spent executing: 61380 milliseconds
07:14:30  Test result: FAILED
07:14:30  Output from test:
07:14:30   [OUT] start running script
07:14:30   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
07:14:30   [OUT] export LD_BIND_NOT=on
07:14:30   [OUT] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_aarch64_linux_OMR_testList_0/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_aarch64_linux_OMR_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest CheckpointDeadlock 1
07:14:30   [OUT] Pre-checkpoint
07:14:30   [OUT] main: Fri Aug 02 11:13:43 UTC 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1722597223938, System.nanoTime(): 5220811764119551
07:14:30   [OUT] Precheckpoint hook inside monitor
07:14:30   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
07:14:30   [OUT] TEST FAILED
07:14:30   [OUT] initiate restore
07:14:30   [OUT] Removed test output files
07:14:30   [OUT] finished script
07:14:30   [ERR] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_aarch64_linux_OMR_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 161324 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
07:14:30  >> Success condition was not found: [Output match: User requested Java dump using]
07:14:30  >> Success condition was not found: [Output match: TEST PASSED]
07:14:30  >> Required condition was found: [Output match: Pre-checkpoint]
07:14:30  >> Failure condition was found: [Output match: Killed]
07:14:30  >> Failure condition was not found: [Output match: CRIU is not enabled]
07:14:30  >> Failure condition was not found: [Output match: Operation not permitted]
07:14:30  >> Success condition was not found: [Output match: Thread pid mismatch]
07:14:30  >> Success condition was not found: [Output match: do not match expected]
07:14:30  >> Success condition was not found: [Output match: Unable to create a thread:]
07:14:30  >> Failure condition was found: [Output match: TEST FAILED]
07:14:30  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

@pshipton
Copy link
Member Author

pshipton commented Sep 5, 2024

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.functional_s390x_linux_OpenJDK21_testList_1/32
cmdLineTester_criu_nonPortableRestore_10

09:58:51  Testing: Create and Restore Criu Checkpoint Image once - CheckpointDeadlock
09:58:51  Test start time: 2024/09/05 09:58:48 Eastern Standard Time
09:58:51  Running command: bash /home/jenkins/workspace/Test_openjdk21_j9_sanity.functional_s390x_linux_OpenJDK21_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk21_j9_sanity.functional_s390x_linux_OpenJDK21_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk21_j9_sanity.functional_s390x_linux_OpenJDK21_testList_1/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest CheckpointDeadlock 1 false false
09:58:51  Time spent starting: 8 milliseconds
10:01:09  Time spent executing: 135358 milliseconds
10:01:09  Test result: FAILED
10:01:09  Output from test:
10:01:09   [OUT] start running script
10:01:09   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
10:01:09   [OUT] export LD_BIND_NOT=on
10:01:09   [OUT] /home/jenkins/workspace/Test_openjdk21_j9_sanity.functional_s390x_linux_OpenJDK21_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk21_j9_sanity.functional_s390x_linux_OpenJDK21_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest CheckpointDeadlock 1
10:01:09   [OUT] Pre-checkpoint
10:01:09   [OUT] main: Thu Sep 05 10:00:06 EDT 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1725544836761, System.nanoTime(): 1725544836759036130
10:01:09   [OUT] Precheckpoint hook inside monitor
10:01:09   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
10:01:09   [OUT] TEST FAILED
10:01:09   [OUT] initiate restore
10:01:09   [OUT] Removed test output files
10:01:09   [OUT] finished script
10:01:09   [ERR] /home/jenkins/workspace/Test_openjdk21_j9_sanity.functional_s390x_linux_OpenJDK21_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 3469151 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
10:01:09  >> Success condition was not found: [Output match: User requested Java dump using]
10:01:09  >> Success condition was not found: [Output match: TEST PASSED]
10:01:09  >> Required condition was found: [Output match: Pre-checkpoint]
10:01:09  >> Failure condition was found: [Output match: Killed]
10:01:09  >> Failure condition was not found: [Output match: CRIU is not enabled]
10:01:09  >> Failure condition was not found: [Output match: Operation not permitted]
10:01:09  >> Success condition was not found: [Output match: Thread pid mismatch]
10:01:09  >> Success condition was not found: [Output match: do not match expected]
10:01:09  >> Success condition was not found: [Output match: Unable to create a thread:]
10:01:09  >> Failure condition was found: [Output match: TEST FAILED]
10:01:09  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

@pshipton
Copy link
Member Author

pshipton commented Sep 5, 2024

https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.functional_s390x_linux_Nightly_testList_1/62
cmdLineTester_criu_nonPortableRestore_10

03:19:48  Testing: Create and Restore Criu Checkpoint Image once - NotCheckpointSafeDeadlock
03:19:48  Test start time: 2024/09/05 03:19:37 Eastern Standard Time
03:19:48  Running command: bash /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  -XX:+ThrowOnDelayedCheckpointOperation -Xtrace:print=j9vm.731 --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest NotCheckpointSafeDeadlock 1 false false
03:19:48  Time spent starting: 9 milliseconds
03:21:18  Time spent executing: 95241 milliseconds
03:21:18  Test result: FAILED
03:21:18  Output from test:
03:21:18   [OUT] start running script
03:21:18   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
03:21:18   [OUT] export LD_BIND_NOT=on
03:21:18   [OUT] /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  -XX:+ThrowOnDelayedCheckpointOperation -Xtrace:print=j9vm.731 --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest NotCheckpointSafeDeadlock 1
03:21:18   [OUT] Pre-checkpoint
03:21:18   [OUT] main: Thu Sep 05 03:20:25 EDT 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1725520840817, System.nanoTime(): 1725520840815621862
03:21:18   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
03:21:18   [OUT] TEST FAILED
03:21:18   [OUT] initiate restore
03:21:18   [OUT] Removed test output files
03:21:18   [OUT] finished script
03:21:18   [ERR] /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 3290280 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
03:21:18  >> Success condition was not found: [Output match: User requested Java dump using]
03:21:18  >> Success condition was not found: [Output match: TEST PASSED]
03:21:18  >> Required condition was found: [Output match: Pre-checkpoint]
03:21:18  >> Required condition was not found: [Output match: Checkpoint blocked because thread]
03:21:18  >> Failure condition was found: [Output match: Killed]
03:21:18  >> Failure condition was not found: [Output match: CRIU is not enabled]
03:21:18  >> Failure condition was not found: [Output match: Operation not permitted]
03:21:18  >> Success condition was not found: [Output match: Thread pid mismatch]
03:21:18  >> Success condition was not found: [Output match: do not match expected]
03:21:18  >> Success condition was not found: [Output match: Unable to create a thread:]
03:21:18  >> Failure condition was found: [Output match: TEST FAILED]
03:21:18  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

@JasonFengJ9
Copy link
Member

openjdk23_j9_sanity.functional_aarch64_linux

[2024-12-07T22:51:39.227Z] variation: -XX:+DebugOnRestore -Xjit:count=0
[2024-12-07T22:51:39.227Z] JVM_OPTIONS:  -XX:+DebugOnRestore -Xjit:count=0 

[2024-12-07T23:06:23.613Z] Testing: Create and Restore Criu Checkpoint Image once - CheckpointDeadlock
[2024-12-07T23:06:23.613Z] Test start time: 2024/12/07 23:06:23 Coordinated Universal Time
[2024-12-07T23:06:23.613Z] Running command: bash /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_aarch64_linux_testList_0/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest CheckpointDeadlock 1 false false
[2024-12-07T23:06:23.613Z] Time spent starting: 6 milliseconds
[2024-12-07T23:07:49.478Z] Time spent executing: 85887 milliseconds
[2024-12-07T23:07:49.478Z] Test result: FAILED
[2024-12-07T23:07:49.478Z] Output from test:
[2024-12-07T23:07:49.478Z]  [OUT] start running script
[2024-12-07T23:07:49.478Z]  [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
[2024-12-07T23:07:49.478Z]  [OUT] export LD_BIND_NOT=on
[2024-12-07T23:07:49.478Z]  [OUT] /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_aarch64_linux_testList_0/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest CheckpointDeadlock 1
[2024-12-07T23:07:49.478Z]  [OUT] Pre-checkpoint
[2024-12-07T23:07:49.478Z]  [OUT] main: Sat Dec 07 23:07:06 UTC 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1733612843693, System.nanoTime(): 2219130985754979
[2024-12-07T23:07:49.478Z]  [OUT] Precheckpoint hook inside monitor    <--- This should not happen
[2024-12-07T23:07:49.478Z]  [OUT] JVMJITM048W AOT load and compilation disabled pre-checkpoint and post-restore.
[2024-12-07T23:07:49.478Z]  [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
[2024-12-07T23:07:49.478Z]  [OUT] TEST FAILED
[2024-12-07T23:07:49.478Z]  [OUT] initiate restore
[2024-12-07T23:07:49.478Z]  [OUT] Removed test output files
[2024-12-07T23:07:49.478Z]  [OUT] finished script
[2024-12-07T23:07:49.478Z]  [ERR] /home/jenkins/workspace/Test_openjdk23_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 1497400 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
[2024-12-07T23:07:49.478Z] >> Success condition was not found: [Output match: User requested Java dump using]
[2024-12-07T23:07:49.478Z] >> Failure condition was not found: [Output match: AOT load and compilation disabled post restore]
[2024-12-07T23:07:49.478Z] >> Success condition was not found: [Output match: TEST PASSED]
[2024-12-07T23:07:49.478Z] >> Required condition was found: [Output match: Pre-checkpoint]
[2024-12-07T23:07:49.478Z] >> Failure condition was found: [Output match: Killed]
[2024-12-07T23:07:49.478Z] >> Failure condition was not found: [Output match: CRIU is not enabled]
[2024-12-07T23:07:49.478Z] >> Failure condition was not found: [Output match: Operation not permitted]
[2024-12-07T23:07:49.478Z] >> Success condition was not found: [Output match: Thread pid mismatch]
[2024-12-07T23:07:49.478Z] >> Success condition was not found: [Output match: do not match expected]
[2024-12-07T23:07:49.478Z] >> Success condition was not found: [Output match: Unable to create a thread:]
[2024-12-07T23:07:49.478Z] >> Failure condition was found: [Output match: TEST FAILED]
[2024-12-07T23:07:49.478Z] >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

I will have a look.

@JasonFengJ9 JasonFengJ9 self-assigned this Dec 9, 2024
@JasonFengJ9
Copy link
Member

openjdk11_j9_sanity.functional_aarch64_linux(ubu22-aarch64-5)

[2024-12-13T20:01:14.533Z] Running test cmdLineTester_criu_nonPortableRestore_10 ...
[2024-12-13T20:01:14.533Z] ===============================================
[2024-12-13T20:01:14.533Z] cmdLineTester_criu_nonPortableRestore_10 Start Time: Fri Dec 13 20:01:13 2024 Epoch Time (ms): 1734120073400
[2024-12-13T20:01:14.533Z] variation: -XX:+DebugOnRestore -Xjit:count=0
[2024-12-13T20:01:14.533Z] JVM_OPTIONS:  -XX:+DebugOnRestore -Xjit:count=0 

[2024-12-13T20:18:57.636Z] Testing: Create and Restore Criu Checkpoint Image once - NotCheckpointSafeDeadlock
[2024-12-13T20:18:57.636Z] Test start time: 2024/12/13 20:18:47 Coordinated Universal Time
[2024-12-13T20:18:57.637Z] Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_testList_0/jdkbinary/j2sdk-image/bin/java " -XX:+DebugOnRestore -Xjit:count=0  -XX:+ThrowOnDelayedCheckpointOperation -Xtrace:print=j9vm.731 --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED" org.openj9.criu.DeadlockTest NotCheckpointSafeDeadlock 1 false false
[2024-12-13T20:18:57.637Z] Time spent starting: 4 milliseconds
[2024-12-13T20:20:15.586Z] Time spent executing: 82967 milliseconds
[2024-12-13T20:20:15.586Z] Test result: FAILED
[2024-12-13T20:20:15.586Z] Output from test:
[2024-12-13T20:20:15.586Z]  [OUT] start running script
[2024-12-13T20:20:15.587Z]  [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
[2024-12-13T20:20:15.587Z]  [OUT] export LD_BIND_NOT=on
[2024-12-13T20:20:15.587Z]  [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_testList_0/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -XX:+DebugOnRestore -Xjit:count=0  -XX:+ThrowOnDelayedCheckpointOperation -Xtrace:print=j9vm.731 --add-opens java.base/jdk.internal.misc=ALL-UNNAMED  --add-exports java.base/openj9.internal.criu=ALL-UNNAMED -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest NotCheckpointSafeDeadlock 1
[2024-12-13T20:20:15.587Z]  [OUT] Pre-checkpoint
[2024-12-13T20:20:15.587Z]  [OUT] main: Fri Dec 13 20:19:34 UTC 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1734121174902, System.nanoTime(): 2727518812404360
[2024-12-13T20:20:15.587Z]  [OUT] JVMJITM048W AOT load and compilation disabled pre-checkpoint and post-restore.
[2024-12-13T20:20:15.588Z]  [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
[2024-12-13T20:20:15.588Z]  [OUT] TEST FAILED
[2024-12-13T20:20:15.588Z]  [OUT] initiate restore
[2024-12-13T20:20:15.588Z]  [OUT] Removed test output files
[2024-12-13T20:20:15.588Z]  [OUT] finished script
[2024-12-13T20:20:15.588Z]  [ERR] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_aarch64_linux_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 1619871 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
[2024-12-13T20:20:15.588Z] >> Success condition was not found: [Output match: User requested Java dump using]
[2024-12-13T20:20:15.588Z] >> Failure condition was not found: [Output match: AOT load and compilation disabled post restore]
[2024-12-13T20:20:15.588Z] >> Success condition was not found: [Output match: TEST PASSED]
[2024-12-13T20:20:15.588Z] >> Required condition was found: [Output match: Pre-checkpoint]
[2024-12-13T20:20:15.588Z] >> Required condition was not found: [Output match: Checkpoint blocked because thread]
[2024-12-13T20:20:15.588Z] >> Failure condition was found: [Output match: Killed]
[2024-12-13T20:20:15.588Z] >> Failure condition was not found: [Output match: CRIU is not enabled]
[2024-12-13T20:20:15.588Z] >> Failure condition was not found: [Output match: Operation not permitted]
[2024-12-13T20:20:15.588Z] >> Success condition was not found: [Output match: Thread pid mismatch]
[2024-12-13T20:20:15.588Z] >> Success condition was not found: [Output match: do not match expected]
[2024-12-13T20:20:15.588Z] >> Success condition was not found: [Output match: Unable to create a thread:]
[2024-12-13T20:20:15.588Z] >> Failure condition was found: [Output match: TEST FAILED]
[2024-12-13T20:20:15.588Z] >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

This failure appears similar with those above except no [OUT] Precheckpoint hook inside monitor.

Initial investigation shows Thread t1 might have released lock before running CRIU pre-checkpoint hook.

criuSupport.registerPreCheckpointHook(() -> {
synchronized (lock) {
System.out.println("Precheckpoint hook inside monitor");
testResult.testPassed = false;

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
criu Used to track CRIU snapshot related work test failure
Projects
None yet
Development

No branches or pull requests

2 participants