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

CRIU SystemCheckpointException: Could not dump the JVM processes, err=-52 or -70 #17457

Open
JasonFengJ9 opened this issue May 24, 2023 · 4 comments
Labels
arch:power arch:x86 criu Used to track CRIU snapshot related work test failure

Comments

@JasonFengJ9
Copy link
Member

Failure link

From an internal build(rhel7lert-11):

java version "11.0.20-beta" 2023-07-18
IBM Semeru Runtime Certified Edition 11.0.20+2-202305232206 (build 11.0.20-beta+2-202305232206)
Eclipse OpenJ9 VM 11.0.20+2-202305232206 (build master-37e239e9e, JRE 11 Linux ppc64le-64-Bit Compressed References 20230523_585 (JIT enabled, AOT enabled)
OpenJ9   - 37e239e9e
OMR      - 779c51b95
JCL      - fd2b7aa3f2 based on jdk-11.0.20+2)

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

Optional info

Failure output (captured from console output)

[2023-05-23T23:08:00.099Z] variation: -Xint -XX:+CRIURestoreNonPortableMode
[2023-05-23T23:08:00.099Z] JVM_OPTIONS:  -Xint -XX:+CRIURestoreNonPortableMode 

[2023-05-23T23:08:00.099Z] TESTING:
[2023-05-23T23:08:00.587Z] *** Starting test suite: J9 Criu Command-Line Option Tests ***
[2023-05-23T23:08:00.587Z] Testing: Create Criu Checkpoint Image without Restore
[2023-05-23T23:08:01.008Z] Test start time: 2023/05/23 16:08:00 Pacific Standard Time
[2023-05-23T23:08:01.008Z] Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_testList_2/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_testList_2/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_testList_2/openjdkbinary/j2sdk-image/bin/java " -Xint -XX:+CRIURestoreNonPortableMode " org.openj9.criu.CRIUSimpleTest 1 1 true
[2023-05-23T23:08:01.008Z] Time spent starting: 101 milliseconds
[2023-05-23T23:08:01.938Z] Time spent executing: 1034 milliseconds
[2023-05-23T23:08:01.938Z] Test result: FAILED
[2023-05-23T23:08:01.938Z] Output from test:
[2023-05-23T23:08:01.938Z]  [OUT] start running script
[2023-05-23T23:08:01.938Z]  [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
[2023-05-23T23:08:01.938Z]  [OUT] export LD_BIND_NOT=on
[2023-05-23T23:08:01.938Z]  [OUT] Total checkpoint(s) 1:
[2023-05-23T23:08:01.938Z]  [OUT] Pre-checkpoint
[2023-05-23T23:08:01.938Z]  [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Tue May 23 16:08:01 PDT 2023, System.currentTimeMillis(): 1684883281144, System.nanoTime(): 840666207826807
[2023-05-23T23:08:01.938Z]  [OUT] Exception in thread "main" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-52
[2023-05-23T23:08:01.938Z]  [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
[2023-05-23T23:08:01.938Z]  [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:649)
[2023-05-23T23:08:01.938Z]  [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:77)
[2023-05-23T23:08:01.938Z]  [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:65)
[2023-05-23T23:08:01.938Z]  [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:61)
[2023-05-23T23:08:01.938Z]  [OUT] 	at org.openj9.criu.CRIUSimpleTest.checkpoints(CRIUSimpleTest.java:43)
[2023-05-23T23:08:01.938Z]  [OUT] 	at org.openj9.criu.CRIUSimpleTest.main(CRIUSimpleTest.java:33)
[2023-05-23T23:08:01.938Z]  [OUT] finished script
[2023-05-23T23:08:01.938Z] >> Success condition was not found: [Output match: Killed]
[2023-05-23T23:08:01.938Z] >> Required condition was found: [Output match: Pre-checkpoint]
[2023-05-23T23:08:01.938Z] >> Failure condition was not found: [Output match: Post-checkpoint]
[2023-05-23T23:08:01.938Z] >> Failure condition was not found: [Output match: CRIU is not enabled]
[2023-05-23T23:08:01.938Z] >> Failure condition was not found: [Output match: Removed testOutput file]
[2023-05-23T23:08:01.938Z] >> Failure condition was not found: [Output match: Operation not permitted]
[2023-05-23T23:08:01.938Z] >> Failure condition was not found: [Output match: ERR]
[2023-05-23T23:08:01.938Z] >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

[2023-05-23T23:08:01.938Z] Number of PASSED tests: 0 out of 1
[2023-05-23T23:08:01.938Z] Number of FAILED tests: 1 out of 1
[2023-05-23T23:08:01.938Z] 
[2023-05-23T23:08:01.938Z] ---SUMMARY OF FAILED TESTS---
[2023-05-23T23:08:01.938Z] Create Criu Checkpoint Image without Restore
[2023-05-23T23:08:01.938Z] -----------------------------
[2023-05-23T23:08:01.938Z] 
[2023-05-23T23:08:01.938Z] -----------------------------------
[2023-05-23T23:08:01.938Z] cmdLineTester_criu_keepCheckpoint_4_FAILED

FYI @tajila

@JasonFengJ9 JasonFengJ9 added test failure arch:power criu Used to track CRIU snapshot related work labels May 24, 2023
@JasonFengJ9
Copy link
Member Author

JDK11 x86-64_linux(rhel8x86-rt1-4)

[2023-05-25T23:11:14.074Z] variation: -Xjit:count=0 -XX:+CRIURestoreNonPortableMode
[2023-05-25T23:11:14.074Z] JVM_OPTIONS:  -Xjit:count=0 -XX:+CRIURestoreNonPortableMode 

[2023-05-25T23:11:14.490Z] TESTING:
[2023-05-25T23:11:14.915Z] *** Starting test suite: J9 Criu Command-Line Option Tests ***
[2023-05-25T23:11:14.915Z] Testing: Create Criu Checkpoint Image without Restore
[2023-05-25T23:11:14.915Z] Test start time: 2023/05/25 16:11:14 Pacific Standard Time
[2023-05-25T23:11:14.915Z] Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_x86-64_linux_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_x86-64_linux_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_x86-64_linux_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -XX:+CRIURestoreNonPortableMode " org.openj9.criu.CRIUSimpleTest 1 1 true
[2023-05-25T23:11:14.915Z] Time spent starting: 46 milliseconds
[2023-05-25T23:11:35.790Z] Time spent executing: 17688 milliseconds
[2023-05-25T23:11:35.790Z] Test result: FAILED
[2023-05-25T23:11:35.790Z] Output from test:
[2023-05-25T23:11:35.790Z]  [OUT] start running script
[2023-05-25T23:11:35.790Z]  [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
[2023-05-25T23:11:35.790Z]  [OUT] export LD_BIND_NOT=on
[2023-05-25T23:11:35.790Z]  [OUT] Total checkpoint(s) 1:
[2023-05-25T23:11:35.790Z]  [OUT] Pre-checkpoint
[2023-05-25T23:11:35.790Z]  [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Thu May 25 16:11:27 PDT 2023, System.currentTimeMillis(): 1685056287455, System.nanoTime(): 3961060131922872
[2023-05-25T23:11:35.790Z]  [OUT] Exception in thread "main" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-52
[2023-05-25T23:11:35.790Z]  [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
[2023-05-25T23:11:35.790Z]  [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:649)
[2023-05-25T23:11:35.790Z]  [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:77)
[2023-05-25T23:11:35.790Z]  [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:65)
[2023-05-25T23:11:35.790Z]  [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:61)
[2023-05-25T23:11:35.790Z]  [OUT] 	at org.openj9.criu.CRIUSimpleTest.checkpoints(CRIUSimpleTest.java:43)
[2023-05-25T23:11:35.790Z]  [OUT] 	at org.openj9.criu.CRIUSimpleTest.main(CRIUSimpleTest.java:33)
[2023-05-25T23:11:35.790Z]  [OUT] finished script
[2023-05-25T23:11:35.790Z] >> Success condition was not found: [Output match: Killed]
[2023-05-25T23:11:35.790Z] >> Required condition was found: [Output match: Pre-checkpoint]
[2023-05-25T23:11:35.790Z] >> Failure condition was not found: [Output match: Post-checkpoint]
[2023-05-25T23:11:35.790Z] >> Failure condition was not found: [Output match: CRIU is not enabled]
[2023-05-25T23:11:35.790Z] >> Failure condition was not found: [Output match: Removed testOutput file]
[2023-05-25T23:11:35.790Z] >> Failure condition was not found: [Output match: Operation not permitted]
[2023-05-25T23:11:35.790Z] >> Failure condition was not found: [Output match: ERR]
[2023-05-25T23:11:35.790Z] >> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

[2023-05-25T23:11:35.790Z] ---TEST RESULTS---
[2023-05-25T23:11:35.790Z] Number of PASSED tests: 0 out of 1
[2023-05-25T23:11:35.790Z] Number of FAILED tests: 1 out of 1
[2023-05-25T23:11:35.790Z] 
[2023-05-25T23:11:35.790Z] ---SUMMARY OF FAILED TESTS---
[2023-05-25T23:11:35.790Z] Create Criu Checkpoint Image without Restore
[2023-05-25T23:11:35.790Z] -----------------------------
[2023-05-25T23:11:35.790Z] 
[2023-05-25T23:11:35.790Z] -----------------------------------
[2023-05-25T23:11:35.790Z] cmdLineTester_criu_keepCheckpoint_5_FAILED

@JasonFengJ9 JasonFengJ9 changed the title CRIU ppc64le_linux SystemCheckpointException: Could not dump the JVM processes, err=-52 CRIU ppc64le_linux/x86-64_linux SystemCheckpointException: Could not dump the JVM processes, err=-52 May 26, 2023
@JasonFengJ9 JasonFengJ9 changed the title CRIU ppc64le_linux/x86-64_linux SystemCheckpointException: Could not dump the JVM processes, err=-52 CRIU SystemCheckpointException: Could not dump the JVM processes, err=-52 Jul 3, 2023
@JasonFengJ9 JasonFengJ9 changed the title CRIU SystemCheckpointException: Could not dump the JVM processes, err=-52 CRIU SystemCheckpointException: Could not dump the JVM processes, err=-52 or -70 Sep 8, 2023
@pshipton
Copy link
Member

pshipton commented Sep 15, 2023

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/604 - ub20p8j91
cmdLineTester_criu_nonPortableRestore_2

Testing: Create and Restore Criu Checkpoint Image once - TestDelayedOperations
Test start time: 2023/09/15 05:34:08 Eastern Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -XX:+CRIURestoreNonPortableMode " org.openj9.criu.TestDelayedOperations 1 1 false false
Time spent starting: 3 milliseconds
Time spent executing: 3943 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
 [OUT] export LD_BIND_NOT=on
 [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xjit:count=0 -XX:+CRIURestoreNonPortableMode  -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.TestDelayedOperations 1 1
 [OUT] currentThread : Thread[Thread-0,5,main] with name : Thread-0, current thread name: Thread-0, Fri Sep 15 05:34:10 EDT 2023, System.currentTimeMillis(): 1694770450669, System.nanoTime(): 11731526788127289
 [OUT] Pre-checkpoint - currentThread : Thread[Thread-0,5,main]
 [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: Thread-0, Fri Sep 15 05:34:10 EDT 2023, System.currentTimeMillis(): 1694770450817, System.nanoTime(): 11731526936122413
 [OUT] PreCheckpointHook() before threadAwaiting.interrupt() - currentThread : Thread[Thread-0,5,main], current thread name: Thread-0, Fri Sep 15 05:34:10 EDT 2023, System.currentTimeMillis(): 1694770450823, System.nanoTime(): 11731526942790195
 [OUT] PreCheckpointHook() after threadAwaiting.interrupt(), current thread name: Thread-0, Fri Sep 15 05:34:10 EDT 2023, System.currentTimeMillis(): 1694770450824, System.nanoTime(): 11731526943209829
 [OUT] Exception in thread "Thread-0" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-52
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:679)
 [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:77)
 [OUT] 	at org.openj9.criu.TestDelayedOperations.lambda$testDelayedThreadInterrupt$0(TestDelayedOperations.java:71)
 [OUT] 	at java.base/java.lang.Thread.run(Thread.java:839)
 [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
 [OUT] Removed test output files
 [OUT] finished script
>> Success condition was not found: [Output match: TestDelayedOperations.testDelayedThreadInterrupt(): PASSED]
>> Required condition was not found: [Output match: Killed]
>> Required condition was found: [Output match: Pre-checkpoint]
>> Failure condition was not found: [Output match: TestDelayedOperations.testDelayedThreadInterrupt(): FAILED]
>> Failure condition was not found: [Output match: CRIU is not enabled]
>> Failure condition was not found: [Output match: Operation not permitted]
>> Success condition was not found: [Output match: Thread pid mismatch]
>> Success condition was not found: [Output match: do not match expected]
>> Success condition was not found: [Output match: Unable to create a thread:]
>> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]
>> Failure condition was not found: [Output match: User requested Java dump using]


Testing: Envvar test12
Test start time: 2023/09/15 05:35:17 Eastern Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -XX:+CRIURestoreNonPortableMode  -Xtrace:print=j9criu.16" org.openj9.criu.EnvVarFileTest EnvVarFileTest12 1
Time spent starting: 2 milliseconds
Time spent executing: 3927 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
 [OUT] export LD_BIND_NOT=on
 [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xjit:count=0 -XX:+CRIURestoreNonPortableMode  -Xtrace:print=j9criu.16 -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.EnvVarFileTest EnvVarFileTest12 1
 [OUT] Pre-checkpoint
 [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Fri Sep 15 05:35:19 EDT 2023, System.currentTimeMillis(): 1694770519325, System.nanoTime(): 11731595444739604
 [OUT] Exception in thread "main" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-52
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:679)
 [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:77)
 [OUT] 	at org.openj9.criu.EnvVarFileTest.envVarFileTest12(EnvVarFileTest.java:333)
 [OUT] 	at org.openj9.criu.EnvVarFileTest.main(EnvVarFileTest.java:72)
 [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
 [OUT] Removed test output files
 [OUT] finished script
>> Success condition was not found: [Output match: Killed]
>> Failure condition was not found: [Output match: failed properties test]
>> Required condition was found: [Output match: Pre-checkpoint]
>> Success condition was not found: [Output match: Failed to load options from the options file]
>> Failure condition was not found: [Output match: CRIU is not enabled]
>> Failure condition was not found: [Output match: Operation not permitted]
>> Success condition was not found: [Output match: Thread pid mismatch]
>> Success condition was not found: [Output match: do not match expected]
>> Success condition was not found: [Output match: Unable to create a thread:]
>> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]
>> Success condition was not found: [Output match: Restore arg: -Dprop1=val1]
>> Success condition was not found: [Output match: Restore arg: -Dprop2=val2]
>> Success condition was not found: [Output match: Restore arg: -Dprop3=val3]
>> Failure condition was not found: [Output match: User requested Java dump using]

cmdLineTester_criu_nonPortableRestoreJDK11Up_0

Testing: Create CRIU checkpoint image and restore once - testThreadPark
Test start time: 2023/09/15 05:50:54 Eastern Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xjit -XX:+CRIURestoreNonPortableMode  -Xtrace:print={j9criu} --add-exports=java.base/jdk.internal.misc=ALL-UNNAMED --add-exports=java.base/openj9.internal.criu=ALL-UNNAMED" "org.openj9.criu.JDK11UpTimeoutAdjustmentTest testThreadPark" 1 1 false false
Time spent starting: 48 milliseconds
Time spent executing: 22542 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
 [OUT] export LD_BIND_NOT=on
 [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xjit -XX:+CRIURestoreNonPortableMode  -Xtrace:print={j9criu} --add-exports=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_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.JDK11UpTimeoutAdjustmentTest testThreadPark 1 1
 [OUT] Start test name: testThreadPark
 [OUT] Before starting testThreadPark, current thread name: main, Fri Sep 15 05:50:55 EDT 2023, System.currentTimeMillis(): 1694771455141, System.nanoTime(): 11732531260338171
 [OUT] testThreadPark NO C/R before park(), current thread name: main, Fri Sep 15 05:50:55 EDT 2023, System.currentTimeMillis(): 1694771455226, System.nanoTime(): 11732531345799370
 [OUT] testThreadPark NO C/R after park(), current thread name: main, Fri Sep 15 05:51:05 EDT 2023, System.currentTimeMillis(): 1694771465228, System.nanoTime(): 11732541347956815
 [OUT] PASSED: expected park time 10000000000 ns, but the actual elapsed time was: 10000123587ns (~10000ms) with startNanoTime = 11732531346028366ns, and endNanoTime = 11732541346151953ns, CheckpointRestoreNanoTimeDelta: 0ns (~0ms)
 [OUT] testThreadPark before park(), current thread name: Thread-0, Fri Sep 15 05:51:05 EDT 2023, System.currentTimeMillis(): 1694771465249, System.nanoTime(): 11732541368052811
 [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Fri Sep 15 05:51:05 EDT 2023, System.currentTimeMillis(): 1694771465248, System.nanoTime(): 11732541367948182
 [OUT] 09:51:05.255*0xa0700          j9criu.9        > Java_org_eclipse_openj9_criu_CRIUSupport_checkpointJVMImpl
 [OUT] 09:51:05.255 0xa0700          j9criu.18       - Taking a checkpoint with active clinit
 [OUT] 09:51:05.261 0xa0700          j9criu.13       - Before checkpoint, checkpointNanoTimeMonotonic = 11732541380643492, checkpointNanoUTCTime = 1694771465261596262
 [OUT] 09:51:05.537 0xa0700          j9criu.12       - Current syslogOptions: error,vital
 [OUT] 09:51:05.537 0xa0700          j9criu.7        - Before checkpoint criu_dump(), j9time_nano_time() returns 11732541656911587, j9time_current_time_nanos() returns 1694771465537864282
 [OUT] 09:51:05.574 0xa0700          j9criu.15       - After checkpoint criu_dump(), j9time_nano_time() returns 11732541693649570, j9time_current_time_nanos() returns 1694771465574602555
 [OUT] 09:51:05.576 0xa0700          j9criu.10       < Java_org_eclipse_openj9_criu_CRIUSupport_checkpointJVMImpl
 [OUT] Exception in thread "main" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-52
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:679)
 [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVMNoSetup(CRIUTestUtils.java:105)
 [OUT] 	at org.openj9.criu.JDK11UpTimeoutAdjustmentTest.test(JDK11UpTimeoutAdjustmentTest.java:83)
 [OUT] 	at org.openj9.criu.JDK11UpTimeoutAdjustmentTest.main(JDK11UpTimeoutAdjustmentTest.java:40)
 [OUT] testThreadPark after park(), current thread name: Thread-0, Fri Sep 15 05:51:15 EDT 2023, System.currentTimeMillis(): 1694771475249, System.nanoTime(): 11732551368969295
 [OUT] PASSED: expected park time 10000000000 ns, but the actual elapsed time was: 10000168016ns (~10000ms) with startNanoTime = 11732541368694474ns, and endNanoTime = 11732551368862490ns, CheckpointRestoreNanoTimeDelta: 0ns (~0ms)
 [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
 [OUT] Removed test output files
 [OUT] finished script
>> Success condition was found: [Output match: PASSED: expected park time]
>> Required condition was not found: [Output match: Killed]
>> Required condition was found: [Output match: Start test name: testThreadPark]
>> 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: FAILED: expected sleep time]
>> Success condition was not found: [Output match: Unable to create a thread:]
>> Success condition was not found: [Output match: Thread pid mismatch]
>> Success condition was not found: [Output match: do not match expected]
>> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]
>> Failure condition was not found: [Output match: User requested Java dump using]

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/605 - ub20p8j91
cmdLineTester_criu_nonPortableRestore_Xtrace_methodtrace_3

Testing: Restore trace options test with -Xtrace before checkpoint - 1
Test start time: 2023/09/16 02:48:29 Eastern Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xgcpolicy:optthruput  -Xtrace:print=mt,methods=org/eclipse/openj9/criu/CRIUSupport.registerRestoreOptionsFile()" org.openj9.criu.OptionsFileTest TraceOptionsTest1 1
Time spent starting: 59 milliseconds
Time spent executing: 2989 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
 [OUT] export LD_BIND_NOT=on
 [OUT] /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xgcpolicy:optthruput  -Xtrace:print=mt,methods=org/eclipse/openj9/criu/CRIUSupport.registerRestoreOptionsFile() -cp /home/jenkins/workspace/Test_openjdk11_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.OptionsFileTest TraceOptionsTest1 1
 [OUT] 06:48:29.651*0xa0700              mt.0        > org/eclipse/openj9/criu/CRIUSupport.registerRestoreOptionsFile(Ljava/nio/file/Path;)Lorg/eclipse/openj9/criu/CRIUSupport; bytecode method, this = 0x81051768
 [OUT] 06:48:29.651 0xa0700              mt.18       - this: org/eclipse/openj9/criu/CRIUSupport@0000000081051768 method arguments: (sun/nio/fs/UnixPath@0000000081048680)
 [OUT] 06:48:29.653 0xa0700              mt.6        < org/eclipse/openj9/criu/CRIUSupport.registerRestoreOptionsFile(Ljava/nio/file/Path;)Lorg/eclipse/openj9/criu/CRIUSupport; bytecode method
 [OUT] 06:48:29.653 0xa0700              mt.28       - return value: org/eclipse/openj9/criu/CRIUSupport@0000000081051768
 [OUT] Pre-checkpoint
 [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Sat Sep 16 02:48:29 EDT 2023, System.currentTimeMillis(): 1694846909685, System.nanoTime(): 11807985804414776
 [OUT] Exception in thread "main" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-52
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:679)
 [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:77)
 [OUT] 	at org.openj9.criu.OptionsFileTest.traceOptionsTest1(OptionsFileTest.java:193)
 [OUT] 	at org.openj9.criu.OptionsFileTest.main(OptionsFileTest.java:51)
 [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
 [OUT] Removed test output files
 [OUT] finished script
>> Success condition was not found: [Output match: Killed]
>> Required condition was found: [Output match: Pre-checkpoint]
>> Success condition was not found: [Output match: terminateRemainingThreads]
>> Success condition was not found: [Output match: java/lang/System.getProperties()Ljava/util/Properties;]
>> Success condition was not found: [Output match: Post-checkpoint]
>> Success condition was not found: [Output match: User requested Java dump]
>> Failure condition was not found: [Output match: org.eclipse.openj9.criu.JVMRestoreException]
>> Failure condition was not found: [Output match: CRIU is not enabled]
>> Failure condition was not found: [Output match: Operation not permitted]
>> Success condition was not found: [Output match: Thread pid mismatch]
>> Success condition was not found: [Output match: do not match expected]
>> Success condition was not found: [Output match: Unable to create a thread:]
>> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]
``

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/545 - ub18-ppcle-2

Testing: Restore trace options test with no trace options specified before checkpoint - 1
Test start time: 2023/09/16 01:18:39 Eastern Standard Time
Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java " -Xgcpolicy:optavgpause " org.openj9.criu.OptionsFileTest TraceOptionsTest1 1
Time spent starting: 3 milliseconds
Time spent executing: 3406 milliseconds
Test result: FAILED
Output from test:
 [OUT] start running script
 [OUT] export GLIBC_TUNABLES=glibc.cpu.hwcaps=-XSAVEC,-XSAVE,-AVX2,-ERMS,-AVX,-AVX_Fast_Unaligned_Load
 [OUT] export LD_BIND_NOT=on
 [OUT] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/openjdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xgcpolicy:optavgpause  -cp /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_1/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.OptionsFileTest TraceOptionsTest1 1
 [OUT] Pre-checkpoint
 [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Sat Sep 16 01:18:40 EDT 2023, System.currentTimeMillis(): 1694841520092, System.nanoTime(): 11802399624707407
 [OUT] Exception in thread "main" org.eclipse.openj9.criu.SystemCheckpointException: Could not dump the JVM processes, err=-52
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVMImpl(Native Method)
 [OUT] 	at openj9.criu/org.eclipse.openj9.criu.CRIUSupport.checkpointJVM(CRIUSupport.java:680)
 [OUT] 	at org.openj9.criu.CRIUTestUtils.checkPointJVM(CRIUTestUtils.java:77)
 [OUT] 	at org.openj9.criu.OptionsFileTest.traceOptionsTest1(OptionsFileTest.java:193)
 [OUT] 	at org.openj9.criu.OptionsFileTest.main(OptionsFileTest.java:51)
 [OUT] Error (criu/protobuf.c:72): Unexpected EOF on (empty-image)
 [OUT] Removed test output files
 [OUT] finished script
>> Success condition was not found: [Output match: Killed]
>> Required condition was found: [Output match: Pre-checkpoint]
>> Success condition was not found: [Output match: terminateRemainingThreads]
>> Success condition was not found: [Output match: java/lang/System.getProperties()Ljava/util/Properties;]
>> Success condition was not found: [Output match: TEST PASSED]
>> Success condition was not found: [Output match: User requested Java dump]
>> Success condition was not found: [Output match: Post-checkpoint]
>> Failure condition was not found: [Output match: org.eclipse.openj9.criu.JVMRestoreException]
>> Failure condition was not found: [Output match: TEST FAILED]
>> Failure condition was not found: [Output match: CRIU is not enabled]
>> Failure condition was not found: [Output match: Operation not permitted]
>> Success condition was not found: [Output match: Thread pid mismatch]
>> Success condition was not found: [Output match: do not match expected]
>> Success condition was not found: [Output match: Unable to create a thread:]
>> Failure condition was not found: [Output match: Could not dump the JVM processes, err=-70]

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

No branches or pull requests

2 participants