diff --git a/openidm-shell/src/main/java/org/forgerock/openidm/shell/impl/UpdateCommand.java b/openidm-shell/src/main/java/org/forgerock/openidm/shell/impl/UpdateCommand.java index dfdb1267d5..14511b687c 100644 --- a/openidm-shell/src/main/java/org/forgerock/openidm/shell/impl/UpdateCommand.java +++ b/openidm-shell/src/main/java/org/forgerock/openidm/shell/impl/UpdateCommand.java @@ -12,6 +12,7 @@ * information: "Portions copyright [year] [name of copyright owner]". * * Copyright 2015-2016 ForgeRock AS. + * Portions Copyright 2026 3A Systems, LLC. */ package org.forgerock.openidm.shell.impl; @@ -35,6 +36,7 @@ import java.util.List; import java.util.Map; import java.util.Scanner; +import java.util.concurrent.TimeUnit; import org.apache.felix.service.command.CommandSession; import org.forgerock.json.JsonValue; @@ -78,11 +80,46 @@ public class UpdateCommand { private final CommandSession session; private final HttpRemoteJsonResource resource; private final UpdateCommandConfig config; + private final WaitClock clock; private final Map executorRegistry = new HashMap<>(); private PrintWriter logger; private UpdateStep[] executeSequence; private UpdateStep[] recoverySequence; + /** + * Source of elapsed time and of sleeping for the wait loops. Injectable from tests so that the loops can be + * driven deterministically instead of depending on the wall clock. + */ + interface WaitClock { + /** + * Returns a monotonic time in nanoseconds, as {@link System#nanoTime()}. + * + * @return the current monotonic time in nanoseconds. + */ + long nanoTime(); + + /** + * Blocks for the given number of milliseconds, as {@link Thread#sleep(long)}. + * + * @param millis the time to sleep in milliseconds. + * @throws InterruptedException if interrupted while sleeping. + */ + void sleep(long millis) throws InterruptedException; + + /** The clock backed by {@link System#nanoTime()} and {@link Thread#sleep(long)}. */ + WaitClock SYSTEM = new WaitClock() { + @Override + public long nanoTime() { + return System.nanoTime(); + } + + @Override + public void sleep(long millis) throws InterruptedException { + Thread.sleep(millis); + } + }; + } + /** * All steps associated with the update installation process. */ @@ -152,9 +189,24 @@ enum ExecutorStatus { * @param config the configuration provided by the command line parameters. */ public UpdateCommand(CommandSession session, HttpRemoteJsonResource resource, UpdateCommandConfig config) { + this(session, resource, config, WaitClock.SYSTEM); + } + + /** + * Constructor that also takes the clock the wait loops measure elapsed time and sleep with, so that tests can + * drive the loops without depending on the wall clock. + * + * @param session the command line session to possibly log output to, or to get keyboard input. + * @param resource the resource provider to execute REST calls to OpenIDM. + * @param config the configuration provided by the command line parameters. + * @param clock the clock to measure elapsed time and sleep with. + */ + UpdateCommand(CommandSession session, HttpRemoteJsonResource resource, UpdateCommandConfig config, + WaitClock clock) { this.session = session; this.resource = resource; this.config = config; + this.clock = clock; // Register the update steps. registerStepExecutor(new GetArchiveDataStepExecutor()); @@ -547,42 +599,37 @@ public UpdateStep getStep() { */ @Override public ExecutorStatus execute(Context context, UpdateExecutionState state) { - long start = System.currentTimeMillis(); + long start = clock.nanoTime(); long maxWaitTime = config.getMaxJobsFinishWaitTimeMs(); - boolean jobRunning; - boolean timeout = false; log("Waiting for running jobs to finish."); - do { - try { - jobRunning = isJobRunning(context); - if (jobRunning) { - if (maxWaitTime < 0) { - log("Jobs are still running, exiting update process."); - return ExecutorStatus.FAIL; - } - try { - log("Waiting for jobs to finish..."); - Thread.sleep(config.getCheckJobsRunningFrequency()); - } catch (InterruptedException e) { - log("WARNING: Got interrupted while waiting for jobs to finish, exiting update process."); - return ExecutorStatus.FAIL; - } - timeout = (System.currentTimeMillis() - start > maxWaitTime); + try { + // The timeout is checked before sleeping, never after, so the verdict is always based on the + // latest poll: jobs that finish during the last sleep are seen rather than reported as still + // running. + while (isJobRunning(context)) { + if (maxWaitTime < 0) { + log("Jobs are still running, exiting update process."); + return ExecutorStatus.FAIL; + } + if (TimeUnit.NANOSECONDS.toMillis(clock.nanoTime() - start) > maxWaitTime) { + log("Running jobs did not finish within the allotted wait time of " + maxWaitTime + "ms."); + return ExecutorStatus.FAIL; + } + try { + log("Waiting for jobs to finish..."); + clock.sleep(config.getCheckJobsRunningFrequency()); + } catch (InterruptedException e) { + log("WARNING: Got interrupted while waiting for jobs to finish, exiting update process."); + return ExecutorStatus.FAIL; } - } catch (ResourceException e) { - log("Error encountered while waiting for jobs to finish", e); - return ExecutorStatus.FAIL; } - } while (jobRunning && !timeout); - - if (jobRunning) { - log("Running jobs did not finish within the allotted wait time of " + maxWaitTime + "ms."); + } catch (ResourceException e) { + log("Error encountered while waiting for jobs to finish", e); return ExecutorStatus.FAIL; - } else { - log("All running jobs have finished."); - return ExecutorStatus.SUCCESS; } + log("All running jobs have finished."); + return ExecutorStatus.SUCCESS; } /** diff --git a/openidm-shell/src/test/java/org/forgerock/openidm/shell/impl/UpdateCommandTest.java b/openidm-shell/src/test/java/org/forgerock/openidm/shell/impl/UpdateCommandTest.java index 8875e699fd..e666b3c932 100644 --- a/openidm-shell/src/test/java/org/forgerock/openidm/shell/impl/UpdateCommandTest.java +++ b/openidm-shell/src/test/java/org/forgerock/openidm/shell/impl/UpdateCommandTest.java @@ -12,6 +12,7 @@ * information: "Portions copyright [year] [name of copyright owner]". * * Copyright 2015-2016 ForgeRock AS. + * Portions Copyright 2026 3A Systems, LLC. */ package org.forgerock.openidm.shell.impl; @@ -21,6 +22,8 @@ import static org.forgerock.openidm.shell.impl.UpdateCommand.UpdateStep.*; import static org.mockito.Mockito.*; +import java.util.concurrent.TimeUnit; + import org.apache.felix.service.command.CommandSession; import org.forgerock.json.JsonValue; import org.forgerock.json.resource.ActionRequest; @@ -260,7 +263,8 @@ public void testEnterMaintenanceMode() throws Exception { .setMaxJobsFinishWaitTimeMs(100L) .setCheckJobsRunningFrequency(10L) .setMaxUpdateWaitTimeMs(5000L); - UpdateCommand updateCommand = new UpdateCommand(session, resource, config); + // a fake clock keeps the 100ms jobs budget from being crossed by a stalled CI runner (issue #219). + UpdateCommand updateCommand = new UpdateCommand(session, resource, config, new FakeWaitClock(0L)); UpdateExecutionState executionState = updateCommand.execute(new RootContext()); assertThat(executionState.getLastAttemptedStep()).isEqualTo(INSTALL_ARCHIVE); @@ -268,6 +272,47 @@ public void testEnterMaintenanceMode() throws Exception { assertThat(executionState.getLastRecoveryStep()).isEqualTo(ENABLE_SCHEDULER); } + /** + * Regression test for issue #219: the jobs budget expires during a sleep, but the next poll finds no running + * jobs. The wait step must report what the last poll saw, not fail on the stale state from before the sleep. + */ + @Test + public void testWaitForJobsPollsAgainWhenTimeoutExpiresDuringSleep() throws Exception { + HttpRemoteJsonResource resource = mockResource( + mc(UPDATE_ROUTE, UPDATE_ACTION_AVAIL, + json(object( + field("updates", array(object(field("archive", "test.zip")))), + field("rejects", array()) + ))), + mc(UPDATE_ROUTE, UPDATE_ACTION_GET_LICENSE, json(object(field("license", "This is the license")))), + mc(SCHEDULER_JOB_ROUTE, SCHEDULER_ACTION_PAUSE, json(object(field("success", true)))), + // one job running at the first poll, none at the second. + mc(SCHEDULER_JOB_ROUTE, SCHEDULER_ACTION_LIST_JOBS, json(array(object())), json(array())), + // mock the next step to fail. + mc(MAINTENANCE_ROUTE, MAINTENANCE_ACTION_ENABLE, json(object(field("maintenanceEnabled", false)))), + // mock the calls on recovery. + mc(SCHEDULER_JOB_ROUTE, SCHEDULER_ACTION_RESUME_JOBS, json(object(field("success", true)))), + mc(MAINTENANCE_ROUTE, MAINTENANCE_ACTION_DISABLE, json(object(field("maintenanceEnabled", false)))) + ); + + UpdateCommandConfig config = new UpdateCommandConfig() + .setUpdateArchive("test.zip") + .setLogFilePath(null) + .setQuietMode(false) + .setAcceptedLicense(true) + .setSkipRepoUpdatePreview(true) + .setMaxJobsFinishWaitTimeMs(100L) + .setCheckJobsRunningFrequency(10L) + .setMaxUpdateWaitTimeMs(1000L); + // every 10ms sleep stalls for another 190ms, so the 100ms budget is crossed during the first sleep. + UpdateCommand updateCommand = new UpdateCommand(session, resource, config, new FakeWaitClock(190L)); + UpdateExecutionState executionState = updateCommand.execute(new RootContext()); + + assertThat(executionState.getLastAttemptedStep()).isEqualTo(ENTER_MAINTENANCE_MODE); + assertThat(executionState.getCompletedInstallStatus()).isNull(); + assertThat(executionState.getLastRecoveryStep()).isEqualTo(ENABLE_SCHEDULER); + } + //@Test public void testTimeoutInstallUpdateArchive() throws Exception { HttpRemoteJsonResource resource = mockResource( @@ -500,6 +545,29 @@ public void testSuccessfulInstallWithRestart() throws Exception { assertThat(executionState.getLastRecoveryStep()).isEqualTo(FORCE_RESTART); } + /** + * A {@link UpdateCommand.WaitClock} whose time only advances when the command sleeps: each sleep advances it by + * the requested duration plus a fixed stall, simulating a runner that is descheduled while sleeping. + */ + private static class FakeWaitClock implements UpdateCommand.WaitClock { + private final long stallMs; + private long nowMs; + + FakeWaitClock(long stallMs) { + this.stallMs = stallMs; + } + + @Override + public long nanoTime() { + return TimeUnit.MILLISECONDS.toNanos(nowMs); + } + + @Override + public void sleep(long millis) { + nowMs += millis + stallMs; + } + } + private HttpRemoteJsonResource mockResource(MockCriteria... mockCriterion) throws ResourceException { HttpRemoteJsonResource resource = mock(HttpRemoteJsonResource.class); for (MockCriteria mockCriteria : mockCriterion) {