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.29k stars 722 forks source link

cmdLineTester_criu_nonPortableRestoreJDK11Up Create CRIU checkpoint image and restore once - testObjectWaitNotify, not found: [Output match: PASSED: expected wait time] #18150

Closed pshipton closed 1 year ago

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_0/544 - cent8-ppcle-5 cmdLineTester_criu_nonPortableRestoreJDK11Up_2

Testing: Create CRIU checkpoint image and restore once - testObjectWaitNotify
Test start time: 2023/09/15 06:06:06 Coordinated Universal Time
Running command: bash /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_0/openjdkbinary/j2sdk-image/bin/java " -Xjit:count=0 -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 testObjectWaitNotify" 1 1 false false
Time spent starting: 7 milliseconds
Time spent executing: 20234 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_0/openjdkbinary/j2sdk-image/bin/java -XX:+EnableCRIUSupport  -Xjit:count=0 -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_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criu.jar org.openj9.criu.JDK11UpTimeoutAdjustmentTest testObjectWaitNotify 1 1
 [OUT] Start test name: testObjectWaitNotify
 [OUT] Before starting testObjectWaitNotify, current thread name: main, Fri Sep 15 06:06:10 UTC 2023, System.currentTimeMillis(): 1694757970828, System.nanoTime(): 12660350074215948
 [OUT] testObjectWaitNotify() before wait(), current thread name: Thread-0, Fri Sep 15 06:06:11 UTC 2023, System.currentTimeMillis(): 1694757971639, System.nanoTime(): 12660350884971560
 [OUT] Performing CRIUSupport.checkpointJVM(), current thread name: main, Fri Sep 15 06:06:11 UTC 2023, System.currentTimeMillis(): 1694757971643, System.nanoTime(): 12660350888636664
 [OUT] 06:06:11.674*0x95800          j9criu.9        > Java_org_eclipse_openj9_criu_CRIUSupport_checkpointJVMImpl
 [OUT] 06:06:11.675 0x95800          j9criu.18       - Taking a checkpoint with active clinit
 [OUT] 06:06:11.683 0x95800          j9criu.13       - Before checkpoint, checkpointNanoTimeMonotonic = 12660350928935801, checkpointNanoUTCTime = 1694757971683667167
 [OUT] 06:06:11.707 0x95800          j9criu.12       - Current syslogOptions: error,vital
 [OUT] 06:06:11.707 0x95800          j9criu.7        - Before checkpoint criu_dump(), j9time_nano_time() returns 12660350952967670, j9time_current_time_nanos() returns 1694757971707699045
 [OUT] 06:06:13.877 0x95800          j9criu.15       - After checkpoint criu_dump(), j9time_nano_time() returns 12660353122942892, j9time_current_time_nanos() returns 1694757973877674584
 [OUT] 06:06:13.877 0x95800          j9criu.14       - After restore, restoreNanoUTCTime = 1694757973877674584, checkpointNanoUTCTime = 1694757971683667167, checkpointRestoreTimeDelta = 2194007417, restoreNanoTimeMonotonic = 12660353122942892, checkpointNanoTimeMonotonic = 12660350928935801, nanoTimeMonotonicClockDelta = 2194007091
 [OUT] 06:06:13.916 0x95800          j9criu.10       < Java_org_eclipse_openj9_criu_CRIUSupport_checkpointJVMImpl
 [OUT] Before objWait.notify(), current thread name: main, Fri Sep 15 06:06:18 UTC 2023, System.currentTimeMillis(): 1694757978932, System.nanoTime(): 12660355983268193
 [OUT] testObjectWaitNotify() after wait(), current thread name: Thread-0, Fri Sep 15 06:06:19 UTC 2023, System.currentTimeMillis(): 1694757979216, System.nanoTime(): 12660356268216732
 [OUT] End testObjectWaitNotify, current thread name: main, Fri Sep 15 06:06:26 UTC 2023, System.currentTimeMillis(): 1694757986692, System.nanoTime(): 12660363743918159
 [OUT] Removed test output files
 [OUT] finished script
 [ERR] /home/jenkins/workspace/Test_openjdk17_j9_sanity.functional_ppc64le_linux_Nightly_testList_0/aqa-tests/TKG/../../jvmtest/functional/cmdLineTests/criu/criuScript.sh: line 41: 2684690 Killed                  $2 -XX:+EnableCRIUSupport $3 -cp "$1/criu.jar" $4 $5 $6 > testOutput 2>&1
>> Success condition was not found: [Output match: PASSED: expected wait time]
>> Required condition was found: [Output match: Killed]
>> Required condition was found: [Output match: Start test name: testObjectWaitNotify]
>> 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 wait time]
>> Failure condition was not found: [Output match: InterruptedException]
>> 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 commented 1 year ago

@TobiAjila fyi

pshipton commented 1 year ago

Looks like a dup of https://github.com/eclipse-openj9/openj9/issues/17909, moved it there.