diff --git a/server/src/main/java/com/cloud/vm/UserVmManagerImpl.java b/server/src/main/java/com/cloud/vm/UserVmManagerImpl.java index 8fe862316350..244832e69051 100644 --- a/server/src/main/java/com/cloud/vm/UserVmManagerImpl.java +++ b/server/src/main/java/com/cloud/vm/UserVmManagerImpl.java @@ -10141,7 +10141,10 @@ public UserVm restoreVMFromBackup(CreateVMFromBackupCmd cmd) throws ResourceUnav expunge(vmVO); logger.debug("Successfully cleaned up Instance {} after create Instance from backup failed", vmId); } catch (Exception cleanupException) { - logger.debug("Failed to cleanup Instance {} after create Instance from backup failed", vmId, cleanupException); + // Not debug: the Instance is left with whatever its disks held before the restore, and it looks like + // the result of a restore to anyone who finds it. + logger.warn("Failed to cleanup Instance {} after create Instance from backup failed; it remains, " + + "and its volumes may hold none of the backup's data", vmId, cleanupException); } throw e; } diff --git a/server/src/main/java/org/apache/cloudstack/backup/BackupManagerImpl.java b/server/src/main/java/org/apache/cloudstack/backup/BackupManagerImpl.java index 58e435b6406d..8a98f61b1ffd 100644 --- a/server/src/main/java/org/apache/cloudstack/backup/BackupManagerImpl.java +++ b/server/src/main/java/org/apache/cloudstack/backup/BackupManagerImpl.java @@ -2136,7 +2136,7 @@ public void poll(final Date timestamp) { } @DB - private Date scheduleNextBackupJob(final BackupScheduleVO backupSchedule) { + protected Date scheduleNextBackupJob(final BackupScheduleVO backupSchedule) { final Date nextTimestamp = DateUtil.getNextRunTime(backupSchedule.getScheduleType(), backupSchedule.getSchedule(), backupSchedule.getTimezone(), currentTimestamp); return Transaction.execute(new TransactionCallback() { @@ -2150,30 +2150,49 @@ public Date doInTransaction(TransactionStatus status) { }); } - private void checkStatusOfCurrentlyExecutingBackups() { + protected void checkStatusOfCurrentlyExecutingBackups() { final SearchCriteria sc = backupScheduleDao.createSearchCriteria(); sc.addAnd("asyncJobId", SearchCriteria.Op.NNULL); final List backupSchedules = backupScheduleDao.search(sc, null); for (final BackupScheduleVO backupSchedule : backupSchedules) { - final Long asyncJobId = backupSchedule.getAsyncJobId(); - final AsyncJobVO asyncJob = asyncJobManager.getAsyncJob(asyncJobId); - switch (asyncJob.getStatus()) { - case SUCCEEDED: - case FAILED: - final Date nextDateTime = scheduleNextBackupJob(backupSchedule); - final String nextScheduledTime = DateUtil.displayDateInTimezone(DateUtil.GMT_TIMEZONE, nextDateTime); - logger.debug("Next backup scheduled time for Instance ID " + backupSchedule.getVmId() + " is " + nextScheduledTime); - break; - default: - logger.debug("Found async backup job [id: {}, uuid: {}, vmId: {}] with " + - "status [{}] and cmd information: [cmd: {}, cmdInfo: {}].", - asyncJob.getId(), asyncJob.getUuid(), backupSchedule.getVmId(), - asyncJob.getStatus(), asyncJob.getCmd(), asyncJob.getCmdInfo()); - break; + // One schedule's problem must not stop the others: an exception escaping here ends the whole poll + // before scheduleBackups() runs, so every schedule it would have handled silently stops firing. + try { + checkStatusOfCurrentlyExecutingBackup(backupSchedule); + } catch (RuntimeException e) { + logger.warn("Could not check the running backup job of schedule {} for Instance ID {}; the other " + + "schedules are checked regardless", backupSchedule.getId(), backupSchedule.getVmId(), e); } } } + private void checkStatusOfCurrentlyExecutingBackup(final BackupScheduleVO backupSchedule) { + final Long asyncJobId = backupSchedule.getAsyncJobId(); + final AsyncJobVO asyncJob = asyncJobManager.getAsyncJob(asyncJobId); + if (asyncJob == null) { + // Async-job cleanup expunges expired jobs, unfinished ones included, without clearing the schedules + // that point at them. Nothing will ever report on this job again; move the schedule on so it fires. + logger.warn("Backup schedule {} for Instance ID {} refers to async job {}, which no longer exists; " + + "scheduling its next run", backupSchedule.getId(), backupSchedule.getVmId(), asyncJobId); + scheduleNextBackupJob(backupSchedule); + return; + } + switch (asyncJob.getStatus()) { + case SUCCEEDED: + case FAILED: + final Date nextDateTime = scheduleNextBackupJob(backupSchedule); + final String nextScheduledTime = DateUtil.displayDateInTimezone(DateUtil.GMT_TIMEZONE, nextDateTime); + logger.debug("Next backup scheduled time for Instance ID " + backupSchedule.getVmId() + " is " + nextScheduledTime); + break; + default: + logger.debug("Found async backup job [id: {}, uuid: {}, vmId: {}] with " + + "status [{}] and cmd information: [cmd: {}, cmdInfo: {}].", + asyncJob.getId(), asyncJob.getUuid(), backupSchedule.getVmId(), + asyncJob.getStatus(), asyncJob.getCmd(), asyncJob.getCmdInfo()); + break; + } + } + @DB public void scheduleBackups() { String displayTime = DateUtil.displayDateInTimezone(DateUtil.GMT_TIMEZONE, currentTimestamp); diff --git a/server/src/test/java/org/apache/cloudstack/backup/BackupManagerTest.java b/server/src/test/java/org/apache/cloudstack/backup/BackupManagerTest.java index 04bd03670079..d157ec0d02d5 100644 --- a/server/src/test/java/org/apache/cloudstack/backup/BackupManagerTest.java +++ b/server/src/test/java/org/apache/cloudstack/backup/BackupManagerTest.java @@ -63,6 +63,8 @@ import org.apache.cloudstack.framework.config.ConfigKey; import org.apache.cloudstack.framework.config.impl.ConfigDepotImpl; import org.apache.cloudstack.framework.jobs.AsyncJobManager; +import java.util.Date; +import org.apache.cloudstack.jobs.JobInfo; import org.apache.cloudstack.framework.jobs.impl.AsyncJobVO; import org.apache.cloudstack.reservation.ReservationVO; import org.apache.cloudstack.reservation.dao.ReservationDao; @@ -2874,4 +2876,34 @@ public void createBackupOfferingTestAddsNoDetails() { verify(backupOfferingDao).persist(any()); verify(backupOfferingDetailsDao, never()).saveDetails(any()); } + + /** + * A schedule whose async job was expunged must not stop the others. Async-job cleanup removes expired jobs, + * unfinished ones included, and leaves schedules pointing at them; getAsyncJob() then returns null, and the + * null dereference used to end the whole poll before scheduleBackups ran - every schedule handled by that poll + * stopped firing until a management server restart cleared the job ids. + */ + @Test + public void checkStatusOfCurrentlyExecutingBackupsRepairsAScheduleWhoseJobIsGone() { + BackupScheduleVO orphaned = mock(BackupScheduleVO.class); + BackupScheduleVO failing = mock(BackupScheduleVO.class); + BackupScheduleVO healthy = mock(BackupScheduleVO.class); + when(orphaned.getAsyncJobId()).thenReturn(7L); + when(failing.getAsyncJobId()).thenReturn(8L); + when(healthy.getAsyncJobId()).thenReturn(9L); + when(backupScheduleDao.createSearchCriteria()).thenReturn(mock(SearchCriteria.class)); + when(backupScheduleDao.search(any(), any())).thenReturn(List.of(orphaned, failing, healthy)); + when(asyncJobManager.getAsyncJob(7L)).thenReturn(null); + when(asyncJobManager.getAsyncJob(8L)).thenThrow(new RuntimeException("the job table is unreadable")); + AsyncJobVO done = mock(AsyncJobVO.class); + when(done.getStatus()).thenReturn(JobInfo.Status.SUCCEEDED); + when(asyncJobManager.getAsyncJob(9L)).thenReturn(done); + doReturn(new Date()).when(backupManager).scheduleNextBackupJob(any()); + + backupManager.checkStatusOfCurrentlyExecutingBackups(); + + verify(backupManager).scheduleNextBackupJob(orphaned); + verify(backupManager, never()).scheduleNextBackupJob(failing); + verify(backupManager).scheduleNextBackupJob(healthy); + } }