Failure of cmdLineTester_criu_nonPortableRestore in JDK17 CRIU builds

[hangshao0]

Failure link

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly/18/tapResults/

Optional info

• intermittent failure: No

Failure output (captured from console output)

Testing: Create Criu Checkpoint Image once and no restore - TestSingleThreadModeCheckpointException
Test start time: 2022/08/06 03:41:14 Atlantic Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -XX:+CRIURestoreNonPortableMode " org.openj9.criu.TestSingleThreadModeCheckpointException 1 1 true
Time spent starting: 2 milliseconds
Time spent executing: 2768 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] Pre-checkpoint
 [OUT] PreSnapshotHook() before synchronized on java.lang.Object@aea52cbc: org.openj9.criu.TestSingleThreadModeCheckpointException@aa154945 name: main
 [OUT] PreSnapshotHook() within synchronized on java.lang.Object@aea52cbc: org.openj9.criu.TestSingleThreadModeCheckpointException@aa154945 name: main
 [OUT] PreSnapshotHook() after synchronized on java.lang.Object@aea52cbc: org.openj9.criu.TestSingleThreadModeCheckpointException@aa154945 name: main
 [OUT] finished script
 [ERR] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 35:  1526 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
>> Success condition was not found: [Output match: TestSingleThreadModeCheckpointException: PASSED]
>> Required condition was found: [Output match: Pre-checkpoint]
>> Failure condition was not found: [Output match: TestSingleThreadModeCheckpointException: FAILED]
>> Failure condition was found: [Output match: Killed]
>> Failure condition was not found: [Output match: CRIU is not enabled]
>> Failure condition was not found: [Output match: Operation not permitted]
>> Failure condition was not found: [Output match: ERR]

Testing: Create and Restore Criu Checkpoint Image once - TestSingleThreadModeRestoreException
Test start time: 2022/08/06 03:41:18 Atlantic Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -XX:+CRIURestoreNonPortableMode " org.openj9.criu.TestSingleThreadModeRestoreException 1 1 false
Time spent starting: 4 milliseconds
Time spent executing: 4801 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] Pre-checkpoint
 [OUT] PreSnapshotHook() before synchronized on java.lang.Object@1363395a: org.openj9.criu.TestSingleThreadModeRestoreException@94880a96 name: main
 [OUT] PreSnapshotHook() within synchronized on java.lang.Object@1363395a: org.openj9.criu.TestSingleThreadModeRestoreException@94880a96 name: main
 [OUT] PreSnapshotHook() after synchronized on java.lang.Object@1363395a: org.openj9.criu.TestSingleThreadModeRestoreException@94880a96 name: main
 [OUT] newThreadOwnMonitor() before synchronized on java.lang.Object@1363395a: org.openj9.criu.TestSingleThreadModeRestoreException@94880a96 name: Thread-3
 [OUT] newThreadOwnMonitor() before Thread.sleep(): org.openj9.criu.TestSingleThreadModeRestoreException@94880a96 name: Thread-3
 [OUT] newThreadOwnMonitor() interrupted: org.openj9.criu.TestSingleThreadModeRestoreException@94880a96 name: Thread-3
 [OUT] newThreadOwnMonitor() after synchronized on java.lang.Object@1363395a: org.openj9.criu.TestSingleThreadModeRestoreException@94880a96 name: Thread-3
 [OUT] Removed testOutput file
 [OUT] finished script
 [ERR] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 35:  1561 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
>> Success condition was not found: [Output match: org.eclipse.openj9.criu.RestoreException: Exception thrown when running user post-restore]
>> Required condition was found: [Output match: Killed]
>> Required condition was found: [Output match: Pre-checkpoint]
>> Failure condition was not found: [Output match: CRIU is not enabled]
>> Failure condition was not found: [Output match: Operation not permitted]
>> Failure condition was not found: [Output match: ERR]

[babsingh]

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly/19/tapResults/

Testing: Create CRIU checkpoint image and restore three times - testSystemNanoTime
Test start time: 2022/08/09 03:49:12 Eastern Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -XX:+CRIURestoreNonPortableMode " "org.openj9.criu.TimeChangeTest testSystemNanoTime" 3 3 false
Time spent starting: 18 milliseconds
Time spent executing: 9556 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] System.nanoTime() before CRIU checkpoint: 35571076262748281
 [OUT] FAILED: System.nanoTime() after CRIU restore: 35571080585718732, the elapse time is: 4322970451 ns, w/ MAX_TARDINESS_NS : 4000000000
 [OUT] Removed testOutput file
 [OUT] finished script
 [ERR] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 35: 10655 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
 [ERR]  10655: Error (criu/files-reg.c:1994): File home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/output_16600264355607/cmdLineTester_criu_nonPortableRestore_2/testOutput has bad size 193 (expect 60)
 [ERR]  10655: Error (criu/files.c:1200): Unable to open fd=1 id=0x2e
 [ERR] Error (criu/cr-restore.c:2447): Restoring FAILED.
 [ERR]  10655: Error (criu/files-reg.c:1994): File home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_x86-64_linux_criu_Nightly_testList_1/aqa-tests/TKG/output_16600264355607/cmdLineTester_criu_nonPortableRestore_2/testOutput has bad size 193 (expect 60)
 [ERR]  10655: Error (criu/files.c:1200): Unable to open fd=1 id=0x2e
 [ERR] Error (criu/cr-restore.c:2447): Restoring FAILED.
>> Success condition was found: [Output match: Killed]
>> Required condition was found: [Output match: System.nanoTime() before CRIU checkpoint:]
>> Required condition was not found: [Output match: PASSED: System.nanoTime() after CRIU restore:]
>> Failure condition was not found: [Output match: CRIU is not enabled]
>> Failure condition was not found: [Output match: Operation not permitted]
>> Failure condition was found: [Output match: FAILED: System.nanoTime() after CRIU restore:]
>> Required condition was found: [Output match: Error]