From 4bfa4bb6719701f0f7022a1cc5a2bfbe97d4c718 Mon Sep 17 00:00:00 2001 From: Jason Feng Date: Fri, 20 May 2022 15:01:55 -0400 Subject: [PATCH] Add InternalCRIUSupport.getCheckpointRestoreTimeDelta() & tests Return the time in milliseconds elapsed between Checkpoint and Restore; Add tests for Timer.schedule(TimerTask task, long delay) and Timer.schedule(TimerTask task, Date time). Signed-off-by: Jason Feng --- .../internal/criu/InternalCRIUSupport.java | 15 ++ runtime/criusupport/criusupport.hpp | 6 - runtime/criusupport/exports.cmake | 2 - .../criusupport/uma/criusupport_exports.xml | 2 - runtime/jcl/common/criu.cpp | 8 + runtime/jcl/exports.cmake | 1 + runtime/jcl/uma/criu_exports.xml | 1 + .../cmdLineTests/criu/criu_nonPortable.xml | 47 ++++- .../src/org/openj9/criu/TimeChangeTest.java | 187 +++++++++++++++++- 9 files changed, 247 insertions(+), 22 deletions(-) diff --git a/jcl/src/java.base/share/classes/openj9/internal/criu/InternalCRIUSupport.java b/jcl/src/java.base/share/classes/openj9/internal/criu/InternalCRIUSupport.java index f0491bfc2b4..b49cb812807 100644 --- a/jcl/src/java.base/share/classes/openj9/internal/criu/InternalCRIUSupport.java +++ b/jcl/src/java.base/share/classes/openj9/internal/criu/InternalCRIUSupport.java @@ -30,9 +30,24 @@ /*[ENDIF] JAVA_SPEC_VERSION >= 17 */ public final class InternalCRIUSupport { private static boolean criuSupportEnabled = isCRIUSupportEnabledImpl(); + private static long checkpointRestoreNanoTimeDelta; private static native boolean isCRIUSupportEnabledImpl(); private static native boolean isCheckpointAllowedImpl(); + private static native long getCheckpointRestoreNanoTimeDeltaImpl(); + + /** + * Retrieve the elapsed time between Checkpoint and Restore. + * Only support one Checkpoint. + * + * @return the time in nanoseconds. + */ + public static long getCheckpointRestoreNanoTimeDelta() { + if (checkpointRestoreNanoTimeDelta == 0) { + checkpointRestoreNanoTimeDelta = getCheckpointRestoreNanoTimeDeltaImpl(); + } + return checkpointRestoreNanoTimeDelta; + } /** * Queries if CRIU support is enabled. diff --git a/runtime/criusupport/criusupport.hpp b/runtime/criusupport/criusupport.hpp index b19f8634cc5..4c3155566f4 100644 --- a/runtime/criusupport/criusupport.hpp +++ b/runtime/criusupport/criusupport.hpp @@ -28,12 +28,6 @@ extern "C" { -jboolean JNICALL -Java_openj9_internal_criu_InternalCRIUSupport_isCheckpointAllowedImpl(JNIEnv *env, jclass unused); - -jboolean JNICALL -Java_openj9_internal_criu_InternalCRIUSupport_isCRIUSupportEnabledImpl(JNIEnv *env, jclass unused); - void JNICALL Java_org_eclipse_openj9_criu_CRIUSupport_checkpointJVMImpl(JNIEnv *env, jclass unused, jstring imagesDir, jboolean leaveRunning, jboolean shellJob, jboolean extUnixSupport, jint logLevel, jstring logFile, jboolean fileLocks, jstring workDir, jboolean tcpEstablished, jboolean autoDedup, jboolean trackMemory, jboolean unprivileged); diff --git a/runtime/criusupport/exports.cmake b/runtime/criusupport/exports.cmake index eb29860ba7a..cab7f89a21f 100644 --- a/runtime/criusupport/exports.cmake +++ b/runtime/criusupport/exports.cmake @@ -22,8 +22,6 @@ if(J9VM_OPT_CRIU_SUPPORT) omr_add_exports(j9criu - Java_openj9_internal_criu_InternalCRIUSupport_isCheckpointAllowedImpl - Java_openj9_internal_criu_InternalCRIUSupport_isCRIUSupportEnabledImpl Java_org_eclipse_openj9_criu_CRIUSupport_checkpointJVMImpl ) endif() diff --git a/runtime/criusupport/uma/criusupport_exports.xml b/runtime/criusupport/uma/criusupport_exports.xml index 4b63ebaad7f..e297d8fcb7c 100644 --- a/runtime/criusupport/uma/criusupport_exports.xml +++ b/runtime/criusupport/uma/criusupport_exports.xml @@ -20,7 +20,5 @@ OpenJDK Assembly Exception [2]. SPDX-License-Identifier: EPL-2.0 OR Apache-2.0 OR GPL-2.0 WITH Classpath-exception-2.0 OR LicenseRef-GPL-2.0 WITH Assembly-exception --> - - diff --git a/runtime/jcl/common/criu.cpp b/runtime/jcl/common/criu.cpp index 665659496d9..2461483047f 100644 --- a/runtime/jcl/common/criu.cpp +++ b/runtime/jcl/common/criu.cpp @@ -30,6 +30,14 @@ extern "C" { #if defined(J9VM_OPT_CRIU_SUPPORT) +jlong JNICALL +Java_openj9_internal_criu_InternalCRIUSupport_getCheckpointRestoreNanoTimeDeltaImpl(JNIEnv *env, jclass unused) +{ + PORT_ACCESS_FROM_ENV(env); + + return PORTLIB->checkpointRestoreTimeDelta; +} + jboolean JNICALL Java_openj9_internal_criu_InternalCRIUSupport_isCheckpointAllowedImpl(JNIEnv *env, jclass unused) { diff --git a/runtime/jcl/exports.cmake b/runtime/jcl/exports.cmake index 550445d4d80..34cdfafaf8e 100644 --- a/runtime/jcl/exports.cmake +++ b/runtime/jcl/exports.cmake @@ -660,6 +660,7 @@ endif() # J9VM_OPT_CRIU_SUPPORT if(J9VM_OPT_CRIU_SUPPORT) omr_add_exports(jclse + Java_openj9_internal_criu_InternalCRIUSupport_getCheckpointRestoreNanoTimeDeltaImpl Java_openj9_internal_criu_InternalCRIUSupport_isCheckpointAllowedImpl Java_openj9_internal_criu_InternalCRIUSupport_isCRIUSupportEnabledImpl ) diff --git a/runtime/jcl/uma/criu_exports.xml b/runtime/jcl/uma/criu_exports.xml index 95f4a9468c6..40334830509 100644 --- a/runtime/jcl/uma/criu_exports.xml +++ b/runtime/jcl/uma/criu_exports.xml @@ -20,6 +20,7 @@ OpenJDK Assembly Exception [2]. SPDX-License-Identifier: EPL-2.0 OR Apache-2.0 OR GPL-2.0 WITH Classpath-exception-2.0 OR LicenseRef-GPL-2.0 WITH Assembly-exception --> + diff --git a/test/functional/cmdLineTests/criu/criu_nonPortable.xml b/test/functional/cmdLineTests/criu/criu_nonPortable.xml index 5b96027b702..93585a9be27 100644 --- a/test/functional/cmdLineTests/criu/criu_nonPortable.xml +++ b/test/functional/cmdLineTests/criu/criu_nonPortable.xml @@ -50,8 +50,8 @@ Error - - bash $SCRIPPATH$ $TEST_RESROOT$ $JAVA_COMMAND$ "$JVM_OPTIONS$" $MAINCLASS_TIMECHANGE$ ThreeCheckpoints + + bash $SCRIPPATH$ $TEST_RESROOT$ $JAVA_COMMAND$ "$JVM_OPTIONS$" "$MAINCLASS_TIMECHANGE$ testSystemNanoTime" ThreeCheckpoints Killed System.nanoTime() before CRIU checkpoint: PASSED: System.nanoTime() after CRIU restore: @@ -61,4 +61,47 @@ Error + + bash $SCRIPPATH$ $TEST_RESROOT$ $JAVA_COMMAND$ "$JVM_OPTIONS$" "$MAINCLASS_TIMECHANGE$ testMillisDelayBeforeCheckpointDone" ThreeCheckpoints + Killed + Start test name: testMillisDelay + PASSED: expected MILLIS_DELAY + CRIU is not enabled + Operation not permitted + FAILED: expected MILLIS_DELAY + Error + + + + bash $SCRIPPATH$ $TEST_RESROOT$ $JAVA_COMMAND$ "$JVM_OPTIONS$" "$MAINCLASS_TIMECHANGE$ testMillisDelayAfterCheckpointDone" ThreeCheckpoints + Killed + Start test name: testMillisDelay + PASSED: expected MILLIS_DELAY + CRIU is not enabled + Operation not permitted + FAILED: expected MILLIS_DELAY + Error + + + + bash $SCRIPPATH$ $TEST_RESROOT$ $JAVA_COMMAND$ "$JVM_OPTIONS$" "$MAINCLASS_TIMECHANGE$ testDateScheduledBeforeCheckpointDone" ThreeCheckpoints + Killed + Start test name: testDateScheduledBeforeCheckpointDone + PASSED: expected to run after timeMillisScheduledBeforeCheckpointDone + CRIU is not enabled + Operation not permitted + FAILED: expected to run after timeMillisScheduledBeforeCheckpointDone + Error + + + + bash $SCRIPPATH$ $TEST_RESROOT$ $JAVA_COMMAND$ "$JVM_OPTIONS$" "$MAINCLASS_TIMECHANGE$ testDateScheduledAfterCheckpointDone" ThreeCheckpoints + Killed + Start test name: testDateScheduledAfterCheckpointDone + PASSED: expected to run after timeMillisScheduledAfterCheckpointDone + CRIU is not enabled + Operation not permitted + FAILED: expected to run after timeMillisScheduledAfterCheckpointDone + Error + diff --git a/test/functional/cmdLineTests/criu/src/org/openj9/criu/TimeChangeTest.java b/test/functional/cmdLineTests/criu/src/org/openj9/criu/TimeChangeTest.java index b3811145f34..a13696e1e37 100644 --- a/test/functional/cmdLineTests/criu/src/org/openj9/criu/TimeChangeTest.java +++ b/test/functional/cmdLineTests/criu/src/org/openj9/criu/TimeChangeTest.java @@ -21,29 +21,196 @@ *******************************************************************************/ package org.openj9.criu; -import java.nio.file.Paths; import java.nio.file.Path; +import java.nio.file.Paths; +import java.util.Date; +import java.util.Timer; +import java.util.TimerTask; public class TimeChangeTest { - // The elapsed time is expected less than 2 second. - private static long MAX_ELAPSED_TIME = 2000 * 1000 * 1000; - private static Path imagePath = Paths.get("cpData"); + // maximum tardiness - 4 second + private final static long MAX_TARDINESS_MS = 4000; + private final static long MAX_TARDINESS_NS = MAX_TARDINESS_MS * 1000 * 1000; + // delay 100 millisecond + private final static long MILLIS_DELAY_BEFORECHECKPOINTDONE = 100; + // delay 5000 millisecond + private final static long MILLIS_DELAY_AFTERCHECKPOINTDONE = 5000; + private final long startNanoTime = System.nanoTime(); + private final long currentTimeMillis = System.currentTimeMillis(); + private final static Path imagePath = Paths.get("cpData"); - public static void main(String args[]) { - new TimeChangeTest().testSystemNanoTime(); + public static void main(String args[]) throws InterruptedException { + if (args.length == 0) { + throw new RuntimeException("Test name required"); + } else { + String testName = args[0]; + TimeChangeTest tct = new TimeChangeTest(); + if ("testSystemNanoTime".equalsIgnoreCase(testName)) { + tct.testSystemNanoTime(); + } else { + tct.test(testName); + } + } + } + + private void test(String testName) throws InterruptedException { + System.out.println("Start test name: " + testName); + showThreadCurrentTime("Before starting " + testName); + Timer timer = new Timer(); + switch (testName) { + case "testMillisDelayBeforeCheckpointDone": + testMillisDelayBeforeCheckpointDone(timer); + break; + case "testMillisDelayAfterCheckpointDone": + testMillisDelayAfterCheckpointDone(timer); + break; + case "testDateScheduledBeforeCheckpointDone": + testDateScheduledBeforeCheckpointDone(timer); + break; + case "testDateScheduledAfterCheckpointDone": + testDateScheduledAfterCheckpointDone(timer); + break; + default: + throw new RuntimeException("Unrecognized test name: " + testName); + } + CRIUTestUtils.checkPointJVM(imagePath, false); + // maximum test running time is 12s + Thread.sleep(12000); + showThreadCurrentTime("End " + testName); + timer.cancel(); } public void testSystemNanoTime() { final long beforeCheckpoint = System.nanoTime(); System.out.println("System.nanoTime() before CRIU checkpoint: " + beforeCheckpoint); - CRIUTestUtils.checkPointJVM(imagePath); + CRIUTestUtils.checkPointJVM(imagePath, false); final long afterRestore = System.nanoTime(); final long elapsedTime = afterRestore - beforeCheckpoint; - if (elapsedTime < MAX_ELAPSED_TIME) { - System.out.println("PASSED: System.nanoTime() after CRIU restore: " + afterRestore + ", the elapse time is: " + elapsedTime); + if (elapsedTime < MAX_TARDINESS_NS) { + System.out.println("PASSED: System.nanoTime() after CRIU restore: " + afterRestore + + ", the elapse time is: " + elapsedTime + " ns"); } else { - System.out.println("FAILED: System.nanoTime() after CRIU restore: " + afterRestore + ", the elapse time is: " + elapsedTime); + System.out.println("FAILED: System.nanoTime() after CRIU restore: " + afterRestore + + ", the elapse time is: " + elapsedTime + " ns, w/ MAX_TARDINESS_NS : " + MAX_TARDINESS_NS); } } + + private final TimerTask taskMillisDelayBeforeCheckpointDone = new TimerTask() { + public void run() { + final long endNanoTime = System.nanoTime(); + final long elapsedTime = (endNanoTime - startNanoTime) / 1000000; + boolean pass = false; + if ((elapsedTime >= MILLIS_DELAY_BEFORECHECKPOINTDONE) + && (elapsedTime < (MILLIS_DELAY_BEFORECHECKPOINTDONE + MAX_TARDINESS_MS))) { + pass = true; + } + showThreadCurrentTime("taskMillisDelayBeforeCheckpointDone"); + if (pass) { + System.out.println( + "PASSED: expected MILLIS_DELAY_BEFORECHECKPOINTDONE " + MILLIS_DELAY_BEFORECHECKPOINTDONE + + " ms, the actual elapsed time is: " + elapsedTime + " ms"); + } else { + System.out.println( + "FAILED: expected MILLIS_DELAY_BEFORECHECKPOINTDONE " + MILLIS_DELAY_BEFORECHECKPOINTDONE + + " ms, but the actual elapsed time is: " + elapsedTime + " ms"); + } + } + }; + + // Timer.schedule(TimerTask task, long delay) + private void testMillisDelayBeforeCheckpointDone(Timer timerMillisDelay) throws InterruptedException { + timerMillisDelay.schedule(taskMillisDelayBeforeCheckpointDone, MILLIS_DELAY_BEFORECHECKPOINTDONE); + } + + private final TimerTask taskMillisDelayAfterCheckpointDone = new TimerTask() { + public void run() { + final long endNanoTime = System.nanoTime(); + final long elapsedTime = (endNanoTime - startNanoTime) / 1000000; + boolean pass = false; + if ((elapsedTime >= MILLIS_DELAY_AFTERCHECKPOINTDONE) + && (elapsedTime < (MILLIS_DELAY_AFTERCHECKPOINTDONE + MAX_TARDINESS_MS))) { + pass = true; + } + showThreadCurrentTime("taskMillisDelayAfterCheckpointDone"); + if (pass) { + System.out.println("PASSED: expected MILLIS_DELAY_AFTERCHECKPOINTDONE " + + MILLIS_DELAY_AFTERCHECKPOINTDONE + " ms, the actual elapsed time is: " + elapsedTime + " ms"); + } else { + System.out + .println("FAILED: expected MILLIS_DELAY_AFTERCHECKPOINTDONE " + MILLIS_DELAY_AFTERCHECKPOINTDONE + + " ms, but the actual elapsed time is: " + elapsedTime + " ms"); + } + } + }; + + // Timer.schedule(TimerTask task, long delay) + private void testMillisDelayAfterCheckpointDone(Timer timerMillisDelay) throws InterruptedException { + timerMillisDelay.schedule(taskMillisDelayAfterCheckpointDone, MILLIS_DELAY_AFTERCHECKPOINTDONE); + } + + // expect the checkpoint takes longer than 10ms + private final long timeMillisScheduledBeforeCheckpointDone = currentTimeMillis + 10; + private final TimerTask taskDateScheduledBeforeCheckpointDone = new TimerTask() { + public void run() { + final long taskRunTimeMillis = System.currentTimeMillis(); + boolean pass = false; + if ((taskRunTimeMillis >= timeMillisScheduledBeforeCheckpointDone) + && (taskRunTimeMillis < (timeMillisScheduledBeforeCheckpointDone + MAX_TARDINESS_MS))) { + pass = true; + } + showThreadCurrentTime("taskDateScheduledBeforeCheckpointDone"); + if (pass) { + System.out.println("PASSED: expected to run after timeMillisScheduledBeforeCheckpointDone " + + timeMillisScheduledBeforeCheckpointDone + " ms, the actual taskRunTimeMillis is: " + + taskRunTimeMillis + " ms"); + } else { + System.out.println("FAILED: expected to run after timeMillisScheduledBeforeCheckpointDone " + + timeMillisScheduledBeforeCheckpointDone + " ms, but the actual taskRunTimeMillis is: " + + taskRunTimeMillis + " ms"); + } + } + }; + + // Timer.schedule(TimerTask task, Date time) + private void testDateScheduledBeforeCheckpointDone(Timer timerDateScheduledBeforeCheckpointDone) + throws InterruptedException { + Date dateScheduled = new Date(timeMillisScheduledBeforeCheckpointDone); + timerDateScheduledBeforeCheckpointDone.schedule(taskDateScheduledBeforeCheckpointDone, dateScheduled); + } + + // expect the Checkpoint takes less than 2000ms + private final long timeMillisScheduledAfterCheckpointDone = currentTimeMillis + 2000; + private final TimerTask taskDateScheduledAfterCheckpoint = new TimerTask() { + public void run() { + final long taskRunTimeMillis = System.currentTimeMillis(); + boolean pass = false; + if ((taskRunTimeMillis >= timeMillisScheduledAfterCheckpointDone) + && (taskRunTimeMillis < (timeMillisScheduledAfterCheckpointDone + MAX_TARDINESS_MS))) { + pass = true; + } + showThreadCurrentTime("taskDateScheduledAfterCheckpoint"); + if (pass) { + System.out.println("PASSED: expected to run after timeMillisScheduledAfterCheckpointDone " + + timeMillisScheduledAfterCheckpointDone + " ms, the actual taskRunTimeMillis is: " + + taskRunTimeMillis + " ms"); + } else { + System.out.println("FAILED: expected to run after timeMillisScheduledAfterCheckpointDone " + + timeMillisScheduledAfterCheckpointDone + " ms, but the actual taskRunTimeMillis is: " + + taskRunTimeMillis + " ms"); + } + } + }; + + // Timer.schedule(TimerTask task, Date time) + private void testDateScheduledAfterCheckpointDone(Timer timerDateScheduledAfterCheckpointDone) + throws InterruptedException { + Date dateScheduled = new Date(timeMillisScheduledAfterCheckpointDone); + timerDateScheduledAfterCheckpointDone.schedule(taskDateScheduledAfterCheckpoint, dateScheduled); + } + + private void showThreadCurrentTime(String logStr) { + System.out.println(logStr + ": System.currentTimeMillis: " + System.currentTimeMillis() + ", " + new Date() + + ", Thread's name: " + Thread.currentThread().getName()); + } }