cmdLineTester_criu_nonPortableRestore MethodTypeDeadlockTest - Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/669 - ub20-390-4
cmdLineTester_criu_nonPortableRestore_8

21:23:13  Testing: Create and Restore Criu Checkpoint Image once - MethodTypeDeadlockTest
21:23:13  Test start time: 2024/02/27 02:23:12 Coordinated Universal Time
21:23:13  Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java " -Xgcpolicy:gencon -Xgcthreads1  -XX:+ThrowOnDelayedCheckpointOperation -XX:sleepMillisecondsForNotCheckpointSafe=20 -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 MethodTypeDeadlockTest 1 false false
21:23:13  Time spent starting: 20 milliseconds
21:23:18  Time spent executing: 4416 milliseconds
21:23:18  Test result: FAILED
21:23:18  Output from test:
21:23:18   [OUT] start running script
21:23:18   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
21:23:18   [OUT] export LD_BIND_NOT=on
21:23:18   [OUT] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xgcpolicy:gencon -Xgcthreads1  -XX:+ThrowOnDelayedCheckpointOperation -XX:sleepMillisecondsForNotCheckpointSafe=20 -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_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest MethodTypeDeadlockTest 1
21:23:18   [OUT] Pre-checkpoint
21:23:18   [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Tue Feb 27 02:23:13 UTC 2024, System.currentTimeMillis(): 1709000593324, System.nanoTime(): 1709000593322992818
21:23:18   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
21:23:18   [OUT] initiate restore
21:23:18   [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
21:23:18   [OUT] Error (criu/arch/s390/crtools.c:776): Cannot open core for virt pid 3149047: No such file or directory
21:23:18   [OUT] Error (criu/cr-restore.c:2142): Restoring regs for 3149047 failed: No such file or directory
21:23:18   [OUT] Error (criu/cr-restore.c:2520): Killing processes because of failure on restore.
21:23:18   [OUT] The Network was unlocked so some data or a connection may have been lost.
21:23:18   [OUT] Error (criu/cr-restore.c:2547): Restoring FAILED.
21:23:18   [OUT] Removed test output files
21:23:18   [OUT] finished script
21:23:18   [ERR] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 3149042 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
21:23:18  >> Success condition was not found: [Output match: User requested Java dump using]
21:23:18  >> Success condition was not found: [Output match: TEST PASSED]
21:23:18  >> Failure condition was not found: [Output match: TEST FAILED]
21:23:18  >> Required condition was found: [Output match: Pre-checkpoint]
21:23:18  >> Success condition was not found: [Output match: Checkpoint blocked because thread]
21:23:18  >> Required condition was found: [Output match: Killed]
21:23:18  >> Failure condition was not found: [Output match: CRIU is not enabled]
21:23:18  >> Failure condition was not found: [Output match: Operation not permitted]
21:23:18  >> Success condition was not found: [Output match: Thread pid mismatch]
21:23:18  >> Success condition was not found: [Output match: do not match expected]
21:23:18  >> Success condition was not found: [Output match: Unable to create a thread:]
21:23:18  >> Failure condition was not found: [Output match: TEST FAILED]
21:23:18  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

[pshipton]

@tajila

[tajila]

@ymanton Have you seen this type of failure before?

[ymanton]

Haven't seen that one before. It's in CRIU code that is 390-specific. The failure is on the restore side, but it looks like something happened on the checkpoint side and some file that's expected to be found in the checkpoint image directory isn't there.

21:23:18   [OUT] Error (criu/arch/s390/crtools.c:776): Cannot open core for virt pid 3149047: No such file or directory

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_s390x_linux_OMR_testList_0/556 - ub20-390-4
cmdLineTester_criu_nonPortableRestore_2

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_s390x_linux_OMR_testList_1/439 - ub20-390-4

[tajila]

@r30shah ^^

[r30shah]

Taking a look.

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.functional_s390x_linux_Nightly_testList_0/176 - ub20-390-1
cmdLineTester_criu_nonPortableRestore_5
Testing: Create and Restore Criu Checkpoint Image once - MethodTypeDeadlockTest

19:49:01   [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
19:49:01   [OUT] Error (criu/arch/s390/crtools.c:776): Cannot open core for virt pid 3443241: No such file or directory
19:49:01   [OUT] Error (criu/cr-restore.c:2142): Restoring regs for 3443241 failed: No such file or directory
19:49:01   [OUT] Error (criu/cr-restore.c:2520): Killing processes because of failure on restore.
19:49:01   [OUT] The Network was unlocked so some data or a connection may have been lost.
19:49:01   [OUT] Error (criu/cr-restore.c:2547): Restoring FAILED.

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.functional_s390x_linux_Nightly_testList_1/180 - ub20-390-6
cmdLineTester_criu_nonPortableRestore_9
Testing: Create and Restore Criu Checkpoint Image once - NotCheckpointSafeDeadlock

 [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
 [OUT] Error (criu/arch/s390/crtools.c:776): Cannot open core for virt pid 2027961: No such file or directory
 [OUT] Error (criu/cr-restore.c:2142): Restoring regs for 2027961 failed: No such file or directory
 [OUT] Error (criu/cr-restore.c:2520): Killing processes because of failure on restore.
 [OUT] The Network was unlocked so some data or a connection may have been lost.
 [OUT] Error (criu/cr-restore.c:2547): Restoring FAILED.

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/748 - ub20-390-3a
cmdLineTester_criu_nonPortableRestore_5

01:34:59  Testing: Envvar test6
01:34:59  Test start time: 2024/03/23 05:34:59 Coordinated Universal Time
01:34:59  Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java " -Xgcpolicy:optthruput  -Xtrace:print=j9vm.735" org.openj9.criu.EnvVarFileTest EnvVarFileTest6 1 false false
01:34:59  Time spent starting: 3 milliseconds
01:35:02  Time spent executing: 3441 milliseconds
01:35:02  Test result: FAILED
01:35:02  Output from test:
01:35:02   [OUT] start running script
01:35:02   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
01:35:02   [OUT] export LD_BIND_NOT=on
01:35:02   [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xgcpolicy:optthruput  -Xtrace:print=j9vm.735 -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.EnvVarFileTest EnvVarFileTest6 1
01:35:02   [OUT] Pre-checkpoint
01:35:02   [OUT] main: Sat Mar 23 05:34:59 UTC 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1711172099335, System.nanoTime(): 1711172099333163704
01:35:02   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
01:35:02   [OUT] initiate restore
01:35:02   [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
01:35:02   [OUT] Error (criu/arch/s390/crtools.c:776): Cannot open core for virt pid 3504917: No such file or directory
01:35:02   [OUT] Error (criu/cr-restore.c:2142): Restoring regs for 3504917 failed: No such file or directory
01:35:02   [OUT] Error (criu/cr-restore.c:2520): Killing processes because of failure on restore.
01:35:02   [OUT] The Network was unlocked so some data or a connection may have been lost.
01:35:02   [OUT] Error (criu/cr-restore.c:2547): Restoring FAILED.
01:35:02   [OUT] Removed test output files
01:35:02   [OUT] finished script
01:35:02   [ERR] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 3504912 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
01:35:02  >> Success condition was not found: [Output match: Post-checkpoint]
01:35:02  >> Failure condition was not found: [Output match: failed properties test]
01:35:02  >> Required condition was found: [Output match: Pre-checkpoint]
01:35:02  >> Success condition was not found: [Output match: Failed to load options from the options file]
01:35:02  >> Failure condition was not found: [Output match: CRIU is not enabled]
01:35:02  >> Failure condition was not found: [Output match: Operation not permitted]
01:35:02  >> Success condition was not found: [Output match: Thread pid mismatch]
01:35:02  >> Success condition was not found: [Output match: do not match expected]
01:35:02  >> Success condition was not found: [Output match: Unable to create a thread:]
01:35:02  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]
01:35:02  >> Failure condition was not found: [Output match: Restore arg: -Dprop1=val1]
01:35:02  >> Failure condition was not found: [Output match: Restore arg: -Dprop2=val2]
01:35:02  >> Failure condition was not found: [Output match: Restore arg: -Dprop3=val3]
01:35:02  >> Failure condition was not found: [Output match: User requested Java dump using]
``

[pshipton]

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/687 - rh8-390-1
cmdLineTester_criu_nonPortableRestore_5

21:00:35  Testing: Create and Restore Criu Checkpoint Image once - MethodTypeDeadlockTest
21:00:35  Test start time: 2024/03/22 21:00:34 Eastern Standard Time
21:00:35  Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java " -Xgcpolicy:optthruput  -XX:+ThrowOnDelayedCheckpointOperation -XX:sleepMillisecondsForNotCheckpointSafe=20 -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 MethodTypeDeadlockTest 1 false false
21:00:35  Time spent starting: 13 milliseconds
21:00:38  Time spent executing: 3769 milliseconds
21:00:38  Test result: FAILED
21:00:38  Output from test:
21:00:38   [OUT] start running script
21:00:38   [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
21:00:38   [OUT] export LD_BIND_NOT=on
21:00:38   [OUT] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/jdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xgcpolicy:optthruput  -XX:+ThrowOnDelayedCheckpointOperation -XX:sleepMillisecondsForNotCheckpointSafe=20 -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_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.DeadlockTest MethodTypeDeadlockTest 1
21:00:38   [OUT] Pre-checkpoint
21:00:38   [OUT] main: Fri Mar 22 21:00:34 EDT 2024, Performing CRIUSupport.checkpointJVM(), System.currentTimeMillis(): 1711155634292, System.nanoTime(): 1711155634287871148
21:00:38   [OUT] JVMJITM044W Some or all compiled code in the code cache invalidated post restore.
21:00:38   [OUT] initiate restore
21:00:38   [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
21:00:38   [OUT] Error (criu/arch/s390/crtools.c:776): Cannot open core for virt pid 163351: No such file or directory
21:00:38   [OUT] Error (criu/cr-restore.c:2142): Restoring regs for 163351 failed: No such file or directory
21:00:38   [OUT] Error (criu/cr-restore.c:2520): Killing processes because of failure on restore.
21:00:38   [OUT] The Network was unlocked so some data or a connection may have been lost.
21:00:38   [OUT] Error (criu/cr-restore.c:2547): Restoring FAILED.
21:00:38   [OUT] Removed test output files
21:00:38   [OUT] finished script
21:00:38   [ERR] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_s390x_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 163326 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
21:00:38  >> Success condition was not found: [Output match: User requested Java dump using]
21:00:38  >> Success condition was not found: [Output match: TEST PASSED]
21:00:38  >> Failure condition was not found: [Output match: TEST FAILED]
21:00:38  >> Required condition was found: [Output match: Pre-checkpoint]
21:00:38  >> Success condition was not found: [Output match: Checkpoint blocked because thread]
21:00:38  >> Required condition was found: [Output match: Killed]
21:00:38  >> Failure condition was not found: [Output match: CRIU is not enabled]
21:00:38  >> Failure condition was not found: [Output match: Operation not permitted]
21:00:38  >> Success condition was not found: [Output match: Thread pid mismatch]
21:00:38  >> Success condition was not found: [Output match: do not match expected]
21:00:38  >> Success condition was not found: [Output match: Unable to create a thread:]
21:00:38  >> Failure condition was not found: [Output match: TEST FAILED]
21:00:38  >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]