diff --git a/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachineManagerImpl.java b/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachineManagerImpl.java index c98391a654db..7da1bca4ed3e 100755 --- a/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachineManagerImpl.java +++ b/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachineManagerImpl.java @@ -696,6 +696,11 @@ protected void advanceExpunge(VMInstanceVO vm) throws ResourceUnavailableExcepti advanceStop(vm.getUuid(), VmDestroyForcestop.value()); vm = _vmDao.findByUuid(vm.getUuid()); + // advanceStop() returns without contacting the host when the database already has the instance as Stopped, + // Error, Destroyed or Expunging. The host may still be running it. Expunging is about to release its + // addresses and delete its volumes, so make sure no domain is left behind for it. + ensureInstanceIsStoppedOnLastKnownHost(vm); + try { if (!stateTransitTo(vm, VirtualMachine.Event.ExpungeOperation, vm.getHostId())) { logger.debug("Unable to expunge the vm because it is not in the correct state: " + vm); @@ -2209,8 +2214,13 @@ private List> getVolumesToDisconnect(VirtualMachine vm) { return volumesToDisconnect; } - protected Pair sendStop(final VirtualMachineGuru guru, final VirtualMachineProfile profile, final boolean force, final boolean checkBeforeCleanup) { - final VirtualMachine vm = profile.getVirtualMachine(); + /** + * Build a StopCommand carrying everything the host needs to tear an instance down: the external hypervisor + * details, the VLAN persistence map that decides whether a bridge may be deleted, the control NIC address used + * for system VMs, and the volumes to disconnect. Callers that build a StopCommand without these will make the + * host delete bridges belonging to persistent networks and leave volumes connected. + */ + protected StopCommand buildStopCommand(final VirtualMachine vm, final VirtualMachineProfile profile, final boolean checkBeforeCleanup) { Map vlanToPersistenceMap = getVlanToPersistenceMapForVM(vm.getId()); StopCommand stpCmd = new StopCommand(vm, getExecuteInSequence(vm.getHypervisorType()), checkBeforeCleanup); updateStopCommandForExternalHypervisorType(vm.getHypervisorType(), profile, stpCmd); @@ -2219,7 +2229,12 @@ protected Pair sendStop(final VirtualMachineGuru guru, final Vi } stpCmd.setControlIp(getControlNicIpForVM(vm)); stpCmd.setVolumesToDisconnect(getVolumesToDisconnect(vm)); - final StopCommand stop = stpCmd; + return stpCmd; + } + + protected Pair sendStop(final VirtualMachineGuru guru, final VirtualMachineProfile profile, final boolean force, final boolean checkBeforeCleanup) { + final VirtualMachine vm = profile.getVirtualMachine(); + final StopCommand stop = buildStopCommand(vm, profile, checkBeforeCleanup); try { Answer answer = null; if(vm.getHostId() != null) { @@ -5437,6 +5452,7 @@ private void handlePowerOnReportWithNoPendingJobsOnVM(final VMInstanceVO vm) { case Destroyed: case Expunging: logger.info("Receive power on report when Instance is in destroyed or expunging state. Instance: {}, state: {}.", vm, vm.getState()); + stopUnmanagedInstanceOnReportingHost(vm); break; case Migrating: @@ -5452,11 +5468,81 @@ private void handlePowerOnReportWithNoPendingJobsOnVM(final VMInstanceVO vm) { case Error: default: logger.info("Receive power on report when Instance is in error or unexpected state. Instance: {}, state: {}.", vm, vm.getState()); + _alertMgr.sendAlert(AlertManager.AlertType.ALERT_TYPE_SYNC, vm.getDataCenterId(), vm.getPodIdToDeployIn(), + VM_SYNC_ALERT_SUBJECT, String.format("Instance %s is reported running by host %s but is in %s state. " + + "It is not managed by CloudStack and may need to be stopped on the host.", + vm.getInstanceName(), vm.getPowerHostId(), vm.getState())); break; } } - private void handlePowerOffReportWithNoPendingJobsOnVM(final VMInstanceVO vm) { + /** + * Send a StopCommand for an instance to the last host it is known to have run on, whatever the database state + * says. Used before expunging, where the instance's addresses and volumes are about to be released and a domain + * left running on the host would keep using them. + * + * External instances are skipped: their teardown is done by their extension in finalizeExpunge, and a + * StopCommand issued from here would not carry the details that path needs. + */ + protected void ensureInstanceIsStoppedOnLastKnownHost(final VMInstanceVO vm) { + if (vm == null || HypervisorType.External.equals(vm.getHypervisorType())) { + return; + } + final Long hostId = vm.getHostId() != null ? vm.getHostId() : vm.getLastHostId(); + if (hostId == null) { + return; + } + try { + // checkBeforeCleanup is false on purpose: a running domain is what has to be removed here. + final StopCommand stop = buildStopCommand(vm, new VirtualMachineProfileImpl(vm), false); + final Answer answer = _agentMgr.send(hostId, stop); + if (answer != null && answer.getResult()) { + return; + } + logger.warn("Unable to confirm instance {} is stopped on host {} before expunging: {}", vm, hostId, + answer == null ? "no answer from host" : answer.getDetails()); + } catch (final AgentUnavailableException | OperationTimedoutException e) { + logger.warn("Unable to confirm instance {} is stopped on host {} before expunging.", vm, hostId, e); + } + } + + /** + * The host reports an instance as powered on that the database considers destroyed or expunged. It will never be + * managed again, and its addresses and storage have already been handed back, so stop it on the host that + * reported it instead of leaving it running unmanaged. + * + * External instances are skipped, as in ensureInstanceIsStoppedOnLastKnownHost(). + */ + protected void stopUnmanagedInstanceOnReportingHost(final VMInstanceVO vm) { + if (HypervisorType.External.equals(vm.getHypervisorType())) { + return; + } + final Long powerHostId = vm.getPowerHostId(); + if (powerHostId == null) { + logger.warn("Instance {} is reported powered on but no reporting host is recorded, cannot stop it.", vm); + return; + } + try { + // checkBeforeCleanup must be false: the instance is known to be running, and that is exactly what + // has to be stopped. With it set, the host would refuse and answer "vm is still running on host". + final StopCommand stop = buildStopCommand(vm, new VirtualMachineProfileImpl(vm), false); + final Answer answer = _agentMgr.send(powerHostId, stop); + if (answer != null && answer.getResult()) { + logger.info("Stopped unmanaged instance {} on host {}.", vm, powerHostId); + return; + } + logger.warn("Unable to stop unmanaged instance {} on host {}: {}", vm, powerHostId, + answer == null ? "no answer from host" : answer.getDetails()); + } catch (final AgentUnavailableException | OperationTimedoutException e) { + logger.warn("Unable to stop unmanaged instance {} on host {}.", vm, powerHostId, e); + } + _alertMgr.sendAlert(AlertManager.AlertType.ALERT_TYPE_SYNC, vm.getDataCenterId(), vm.getPodIdToDeployIn(), + VM_SYNC_ALERT_SUBJECT, String.format("Instance %s is reported running by host %s but is in %s state, " + + "and could not be stopped. It may need to be stopped on the host.", + vm.getInstanceName(), powerHostId, vm.getState())); + } + + protected void handlePowerOffReportWithNoPendingJobsOnVM(final VMInstanceVO vm) { switch (vm.getState()) { case Starting: case Stopping: @@ -5480,20 +5566,26 @@ private void handlePowerOffReportWithNoPendingJobsOnVM(final VMInstanceVO vm) { return; } - if (PowerState.PowerOff.equals(vm.getPowerState())) { + // A missing report is not proof that the instance is gone, only that the host did not list it. Stop it + // on the host before giving up its resources, otherwise a still-running instance keeps its NICs and IP + // addresses while the database says they are free and they get handed to another instance. + if (PowerState.PowerOff.equals(vm.getPowerState()) || PowerState.PowerReportMissing.equals(vm.getPowerState())) { + // force is false for a missing report. sendStop() swallows AgentUnavailableException and + // OperationTimedoutException and answers success when forced, and a host too busy to answer is + // exactly the condition that produced the stale report in the first place. Backing off and letting a + // later report decide is better than freeing an address on no evidence. A PowerOff report is the + // host stating the instance is down, so that path keeps its previous behaviour. + final boolean forceStop = PowerState.PowerOff.equals(vm.getPowerState()); final VirtualMachineGuru vmGuru = getVmGuru(vm); final VirtualMachineProfile profile = new VirtualMachineProfileImpl(vm); - Pair result = sendStop(vmGuru, profile, true, true); + Pair result = sendStop(vmGuru, profile, forceStop, true); if (!result.first()) { + logger.warn("Unable to stop VM {} on its host, not releasing its resources: {}", vm, result.second()); return; } else { // Release resources on StopCommand success releaseVmResources(profile, true); } - } else if (PowerState.PowerReportMissing.equals(vm.getPowerState())) { - final VirtualMachineProfile profile = new VirtualMachineProfileImpl(vm); - // VM will be sync-ed to Stopped state, release the resources - releaseVmResources(profile, true); } try { diff --git a/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachinePowerStateSyncImpl.java b/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachinePowerStateSyncImpl.java index 475ed0f37bd2..8a8fb7db6de5 100644 --- a/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachinePowerStateSyncImpl.java +++ b/engine/orchestration/src/main/java/com/cloud/vm/VirtualMachinePowerStateSyncImpl.java @@ -18,9 +18,11 @@ import java.util.Date; import java.util.HashMap; +import java.util.HashSet; import java.util.List; import java.util.Map; import java.util.Set; +import java.util.concurrent.ConcurrentHashMap; import java.util.stream.Collectors; import javax.inject.Inject; @@ -34,6 +36,7 @@ import org.apache.logging.log4j.Logger; import com.cloud.agent.api.HostVmStateReportEntry; +import com.cloud.alert.AlertManager; import com.cloud.configuration.ManagementServiceConfiguration; import com.cloud.host.Host; import com.cloud.host.HostVO; @@ -48,6 +51,11 @@ public class VirtualMachinePowerStateSyncImpl implements VirtualMachinePowerStat @Inject VMInstanceDao _instanceDao; @Inject HostDao hostDao; @Inject ManagementServiceConfiguration mgmtServiceConf; + @Inject AlertManager _alertMgr; + + protected static final String UNKNOWN_INSTANCES_ALERT_SUBJECT = "Instances running on a host that CloudStack has no record of"; + + private final Map> unknownInstancesByHost = new ConcurrentHashMap<>(); private LazyCache vmCache; private LazyCache hostCache; @@ -66,14 +74,14 @@ public void resetHostSyncState(Host host) { @Override public void processHostVmStateReport(long hostId, Map report) { logger.debug("Process host VM state report. host: {}", hostCache.get(hostId)); - Map translatedInfo = convertVmStateReport(report); + Map translatedInfo = convertVmStateReport(hostId, report); processReport(hostId, translatedInfo, false); } @Override public void processHostVmStatePingReport(long hostId, Map report, boolean force) { logger.debug("Process host VM state report from ping process. host: {}", hostCache.get(hostId)); - Map translatedInfo = convertVmStateReport(report); + Map translatedInfo = convertVmStateReport(hostId, report); processReport(hostId, translatedInfo, force); } @@ -114,6 +122,21 @@ private List filterOutdatedFromMissingVmReport(List .collect(Collectors.toList()); } + /** + * A host report only lists the instances that were running on the host when the report was collected. When the + * management server changes an instance's state around that moment, an in-flight report may have been collected + * before the change and therefore says nothing about it. Treating such an instance as missing would undo the + * change that just happened, so instances whose state changed within the graceful period are left alone and + * judged by a later report instead. + */ + protected boolean hasRecentStateChange(VMInstanceVO instance, Date currentTime, long milliSecondsGracefulPeriod) { + Date lastStateChange = instance.getUpdateTime(); + if (lastStateChange == null) { + return false; + } + return currentTime.getTime() - lastStateChange.getTime() < milliSecondsGracefulPeriod; + } + private void processMissingVmReport(long hostId, Set vmIds, boolean force) { // any state outdates should be checked against the time before this list was retrieved Date startTime = DateUtil.currentGMTTime(); @@ -143,6 +166,12 @@ private void processMissingVmReport(long hostId, Set vmIds, boolean force) vmStateUpdateTime = instance.getCreated(); } } + if (hasRecentStateChange(instance, currentTime, milliSecondsGracefulPeriod)) { + logger.debug("vm id: {} - state changed at {}, which is within the graceful period ({} ms); " + + "the report may have been collected before that change, skipping missing report", + instance.getId(), DateUtil.getOutputString(instance.getUpdateTime()), milliSecondsGracefulPeriod); + continue; + } logger.debug("Detected missing VM. host: {}, vm id: {}({}), power state: {}, last state update: {}", hostId, instance.getId(), @@ -151,8 +180,8 @@ private void processMissingVmReport(long hostId, Set vmIds, boolean force) DateUtil.getOutputString(vmStateUpdateTime)); long milliSecondsSinceLastStateUpdate = currentTime.getTime() - vmStateUpdateTime.getTime(); if (force || (milliSecondsSinceLastStateUpdate > milliSecondsGracefulPeriod)) { - logger.debug("vm id: {} - time since last state update({} ms) has passed graceful period", - instance.getId(), milliSecondsSinceLastStateUpdate); + logger.debug("vm id: {} - reporting missing (time since last state update: {} ms, graceful period: {} ms, forced: {})", + instance.getId(), milliSecondsSinceLastStateUpdate, milliSecondsGracefulPeriod, force); // this is where a race condition might have happened if we don't re-fetch the instance; // between the startime of this job and the currentTime of this missing-branch // an update might have occurred that we should not override in case of out of band migration @@ -178,23 +207,63 @@ private void processReport(long hostId, Map tra logger.debug("Done with process of VM state report. host: {}", () -> hostCache.get(hostId)); } - public Map convertVmStateReport(Map states) { + public Map convertVmStateReport(long hostId, Map states) { final HashMap map = new HashMap<>(); if (MapUtils.isEmpty(states)) { + reportUnknownInstances(hostId, new HashSet<>()); return map; } + Set unknownInstanceNames = new HashSet<>(); Map nameIdMap = _instanceDao.getNameIdMapForVmInstanceNames(states.keySet()); for (Map.Entry entry : states.entrySet()) { Long id = nameIdMap.get(entry.getKey()); if (id != null) { map.put(id, entry.getValue().getState()); } else { + unknownInstanceNames.add(entry.getKey()); logger.debug("Unable to find matched VM in CloudStack DB. name: {} powerstate: {}", entry.getKey(), entry.getValue()); } } + reportUnknownInstances(hostId, unknownInstanceNames); return map; } + /** + * A host reporting an instance that CloudStack has no record of means something is running there unmanaged, + * usually left behind by a deploy or an expunge that did not reach the host. Previously this produced one debug + * line per instance per report and nothing else, so it could go unnoticed indefinitely. + * + * Logged at warn level, and only when the set of unknown instances on a host changes, so a standing condition + * does not repeat on every report. + * + * @return true when the set changed and was reported, false when there was nothing new to say. + */ + protected boolean reportUnknownInstances(long hostId, Set unknownInstanceNames) { + Set previous = unknownInstancesByHost.get(hostId); + if (unknownInstanceNames.equals(previous) || (CollectionUtils.isEmpty(unknownInstanceNames) && previous == null)) { + return false; + } + if (unknownInstanceNames.isEmpty()) { + unknownInstancesByHost.remove(hostId); + logger.info("No unknown instances are reported anymore. host: {}", () -> hostCache.get(hostId)); + return true; + } + unknownInstancesByHost.put(hostId, unknownInstanceNames); + HostVO host = hostCache.get(hostId); + String names = String.join(", ", unknownInstanceNames); + logger.warn("Host reports {} instance(s) that do not exist in CloudStack DB, they are running unmanaged. " + + "host: {}, instances: [{}]", + unknownInstanceNames.size(), host, names); + if (host != null) { + _alertMgr.sendAlert(AlertManager.AlertType.ALERT_TYPE_SYNC, host.getDataCenterId(), host.getPodId(), + UNKNOWN_INSTANCES_ALERT_SUBJECT, + String.format("Host %s reports %d instance(s) that do not exist in CloudStack: %s. They are " + + "running unmanaged and may still be holding addresses and storage.", + host.getName(), unknownInstanceNames.size(), names)); + } + return true; + } + protected VMInstanceVO getVmFromId(long vmId) { return _instanceDao.findById(vmId); } diff --git a/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachineManagerImplTest.java b/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachineManagerImplTest.java index c9a404f9c89c..68abdcea18a8 100644 --- a/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachineManagerImplTest.java +++ b/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachineManagerImplTest.java @@ -24,6 +24,7 @@ import static org.junit.Assert.assertThrows; import static org.junit.Assert.assertTrue; import static org.mockito.ArgumentMatchers.any; +import static org.mockito.ArgumentMatchers.anyBoolean; import static org.mockito.ArgumentMatchers.anyList; import static org.mockito.ArgumentMatchers.anyLong; import static org.mockito.ArgumentMatchers.anyString; @@ -2049,4 +2050,85 @@ public void testUnmanageSuccessKvm() throws Exception { } } + @Test + public void testEnsureInstanceIsStoppedOnLastKnownHost_skipsExternal() throws Exception { + when(vmInstanceMock.getHypervisorType()).thenReturn(HypervisorType.External); + virtualMachineManagerImpl.ensureInstanceIsStoppedOnLastKnownHost(vmInstanceMock); + verify(agentManagerMock, never()).send(anyLong(), any(StopCommand.class)); + } + + @Test + public void testEnsureInstanceIsStoppedOnLastKnownHost_noHostIdDoesNothing() throws Exception { + when(vmInstanceMock.getHypervisorType()).thenReturn(HypervisorType.KVM); + when(vmInstanceMock.getHostId()).thenReturn(null); + when(vmInstanceMock.getLastHostId()).thenReturn(null); + virtualMachineManagerImpl.ensureInstanceIsStoppedOnLastKnownHost(vmInstanceMock); + verify(agentManagerMock, never()).send(anyLong(), any(StopCommand.class)); + } + + @Test + public void testEnsureInstanceIsStoppedOnLastKnownHost_fallsBackToLastHostId() throws Exception { + StopCommand stopCommand = mock(StopCommand.class); + when(vmInstanceMock.getHypervisorType()).thenReturn(HypervisorType.KVM); + when(vmInstanceMock.getHostId()).thenReturn(null); + when(vmInstanceMock.getLastHostId()).thenReturn(7L); + doReturn(stopCommand).when(virtualMachineManagerImpl).buildStopCommand(any(), any(), eq(false)); + com.cloud.agent.api.Answer answer = mock(com.cloud.agent.api.Answer.class); + when(answer.getResult()).thenReturn(true); + when(agentManagerMock.send(eq(7L), any(StopCommand.class))).thenReturn(answer); + + virtualMachineManagerImpl.ensureInstanceIsStoppedOnLastKnownHost(vmInstanceMock); + + verify(agentManagerMock, times(1)).send(eq(7L), any(StopCommand.class)); + } + + @Test + public void testEnsureInstanceIsStoppedOnLastKnownHost_agentUnavailableIsSwallowed() throws Exception { + StopCommand stopCommand = mock(StopCommand.class); + when(vmInstanceMock.getHypervisorType()).thenReturn(HypervisorType.KVM); + when(vmInstanceMock.getHostId()).thenReturn(7L); + doReturn(stopCommand).when(virtualMachineManagerImpl).buildStopCommand(any(), any(), eq(false)); + when(agentManagerMock.send(anyLong(), any(StopCommand.class))) + .thenThrow(new AgentUnavailableException("down", 7L)); + + // must not propagate, expunge continues + virtualMachineManagerImpl.ensureInstanceIsStoppedOnLastKnownHost(vmInstanceMock); + + verify(agentManagerMock, times(1)).send(anyLong(), any(StopCommand.class)); + } + + /** + * A missing report is weak evidence, so the stop must not be forced: sendStop() answers success for an + * unreachable host when forced, which would free the addresses of an instance that is still running. + */ + @Test + public void testHandlePowerOffReport_missingReportUsesUnforcedStopAndKeepsResources() { + when(vmInstanceMock.getState()).thenReturn(VirtualMachine.State.Migrating); + when(vmInstanceMock.getPowerState()).thenReturn(VirtualMachine.PowerState.PowerReportMissing); + doReturn(mock(VirtualMachineGuru.class)).when(virtualMachineManagerImpl).getVmGuru(any()); + doReturn(new Pair<>(false, "host did not answer")).when(virtualMachineManagerImpl) + .sendStop(any(), any(), eq(false), eq(true)); + + virtualMachineManagerImpl.handlePowerOffReportWithNoPendingJobsOnVM(vmInstanceMock); + + verify(virtualMachineManagerImpl, times(1)).sendStop(any(), any(), eq(false), eq(true)); + verify(virtualMachineManagerImpl, never()).releaseVmResources(any(), anyBoolean()); + } + + /** + * A PowerOff report is the host stating the instance is down, so that path keeps its forced stop. + */ + @Test + public void testHandlePowerOffReport_powerOffKeepsForcedStop() { + when(vmInstanceMock.getState()).thenReturn(VirtualMachine.State.Migrating); + when(vmInstanceMock.getPowerState()).thenReturn(VirtualMachine.PowerState.PowerOff); + doReturn(mock(VirtualMachineGuru.class)).when(virtualMachineManagerImpl).getVmGuru(any()); + doReturn(new Pair<>(false, "host did not answer")).when(virtualMachineManagerImpl) + .sendStop(any(), any(), eq(true), eq(true)); + + virtualMachineManagerImpl.handlePowerOffReportWithNoPendingJobsOnVM(vmInstanceMock); + + verify(virtualMachineManagerImpl, times(1)).sendStop(any(), any(), eq(true), eq(true)); + verify(virtualMachineManagerImpl, never()).releaseVmResources(any(), anyBoolean()); + } } diff --git a/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachinePowerStateSyncImplTest.java b/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachinePowerStateSyncImplTest.java index 4df14fe22f3b..31371ae50328 100644 --- a/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachinePowerStateSyncImplTest.java +++ b/engine/orchestration/src/test/java/com/cloud/vm/VirtualMachinePowerStateSyncImplTest.java @@ -16,12 +16,17 @@ // under the License. package com.cloud.vm; +import java.util.Arrays; +import java.util.Collections; import java.util.Date; import java.util.HashMap; +import java.util.HashSet; import java.util.Map; +import java.util.Set; import org.apache.cloudstack.framework.messagebus.MessageBus; import org.apache.cloudstack.framework.messagebus.PublishScope; +import org.junit.Assert; import org.junit.Before; import org.junit.Test; import org.junit.runner.RunWith; @@ -30,6 +35,9 @@ import org.mockito.Mockito; import org.mockito.junit.MockitoJUnitRunner; +import com.cloud.agent.api.HostVmStateReportEntry; +import com.cloud.alert.AlertManager; +import com.cloud.configuration.ManagementServiceConfiguration; import com.cloud.host.HostVO; import com.cloud.host.dao.HostDao; import com.cloud.vm.dao.VMInstanceDao; @@ -42,6 +50,10 @@ public class VirtualMachinePowerStateSyncImplTest { VMInstanceDao instanceDao; @Mock HostDao hostDao; + @Mock + ManagementServiceConfiguration mgmtServiceConf; + @Mock + AlertManager alertManager; @InjectMocks VirtualMachinePowerStateSyncImpl virtualMachinePowerStateSync = new VirtualMachinePowerStateSyncImpl(); @@ -104,4 +116,159 @@ public void test_updateAndPublishVmPowerStates_partialUpdated() { PublishScope.GLOBAL, 2L); } + + private VMInstanceVO instanceWithUpdateTime(Date updateTime) { + VMInstanceVO instance = Mockito.mock(VMInstanceVO.class); + Mockito.when(instance.getUpdateTime()).thenReturn(updateTime); + return instance; + } + + @Test + public void test_hasRecentStateChange_withinGracefulPeriod() { + Date now = new Date(); + VMInstanceVO instance = instanceWithUpdateTime(new Date(now.getTime() - 1000L)); + Assert.assertTrue(virtualMachinePowerStateSync.hasRecentStateChange(instance, now, 120000L)); + } + + @Test + public void test_hasRecentStateChange_outsideGracefulPeriod() { + Date now = new Date(); + VMInstanceVO instance = instanceWithUpdateTime(new Date(now.getTime() - 300000L)); + Assert.assertFalse(virtualMachinePowerStateSync.hasRecentStateChange(instance, now, 120000L)); + } + + @Test + public void test_hasRecentStateChange_nullUpdateTime() { + VMInstanceVO instance = instanceWithUpdateTime(null); + Assert.assertFalse(virtualMachinePowerStateSync.hasRecentStateChange(instance, new Date(), 120000L)); + } + + @Test + public void test_convertVmStateReport_mapsKnownAndSkipsUnknown() { + Map report = new HashMap<>(); + report.put("i-2-1-VM", new HostVmStateReportEntry(VirtualMachine.PowerState.PowerOn, "host")); + report.put("i-2-2-VM", new HostVmStateReportEntry(VirtualMachine.PowerState.PowerOn, "host")); + Map nameIdMap = new HashMap<>(); + nameIdMap.put("i-2-1-VM", 1L); + Mockito.when(instanceDao.getNameIdMapForVmInstanceNames(Mockito.anyCollection())).thenReturn(nameIdMap); + + Map result = virtualMachinePowerStateSync.convertVmStateReport(1L, report); + + Assert.assertEquals(1, result.size()); + Assert.assertEquals(VirtualMachine.PowerState.PowerOn, result.get(1L)); + } + + @Test + public void test_convertVmStateReport_emptyReport() { + Map result = + virtualMachinePowerStateSync.convertVmStateReport(1L, new HashMap<>()); + Assert.assertTrue(result.isEmpty()); + Mockito.verify(instanceDao, Mockito.never()).getNameIdMapForVmInstanceNames(Mockito.anyCollection()); + } + + @Test + public void test_reportUnknownInstances_onlyReportsChanges() { + Set unknown = new HashSet<>(); + unknown.add("i-2-3-VM"); + // first sighting is reported, an identical set afterwards is not + Assert.assertTrue(virtualMachinePowerStateSync.reportUnknownInstances(1L, unknown)); + Assert.assertFalse(virtualMachinePowerStateSync.reportUnknownInstances(1L, new HashSet<>(unknown))); + + // a new name in the set is a change and is reported again + Set grown = new HashSet<>(unknown); + grown.add("i-2-4-VM"); + Assert.assertTrue(virtualMachinePowerStateSync.reportUnknownInstances(1L, grown)); + + // clearing is reported once, then stays quiet + Assert.assertTrue(virtualMachinePowerStateSync.reportUnknownInstances(1L, new HashSet<>())); + Assert.assertFalse(virtualMachinePowerStateSync.reportUnknownInstances(1L, new HashSet<>())); + } + + @Test + public void test_reportUnknownInstances_noneEverSeen() { + Assert.assertFalse(virtualMachinePowerStateSync.reportUnknownInstances(2L, new HashSet<>())); + } + + private VMInstanceVO missingInstance(long id, Date updateTime) { + VMInstanceVO instance = Mockito.mock(VMInstanceVO.class); + Mockito.lenient().when(instance.getId()).thenReturn(id); + Mockito.lenient().when(instance.getUuid()).thenReturn("uuid-" + id); + Mockito.lenient().when(instance.getPowerStateUpdateTime()).thenReturn(null); + Mockito.lenient().when(instance.getUpdateTime()).thenReturn(updateTime); + return instance; + } + + /** + * The instance changed state a moment ago, so an in-flight report that does not mention it proves nothing. + * This must hold even for a forced report, which is the bug being fixed: it fails if the + * hasRecentStateChange() call in processMissingVmReport() is removed. + */ + @Test + public void test_processMissingVmReport_forcedReportDoesNotOverrideRecentStateChange() { + VMInstanceVO instance = missingInstance(1L, new Date(System.currentTimeMillis() - 5000L)); + Mockito.when(mgmtServiceConf.getPingInterval()).thenReturn(60); + Mockito.when(instanceDao.findByHostInStatesExcluding(Mockito.anyLong(), Mockito.anyCollection(), + Mockito.eq(VirtualMachine.State.Running), Mockito.eq(VirtualMachine.State.Stopping), + Mockito.eq(VirtualMachine.State.Starting))).thenReturn(Collections.singletonList(instance)); + + virtualMachinePowerStateSync.processHostVmStatePingReport(1L, new HashMap<>(), true); + + Mockito.verify(instanceDao, Mockito.never()).updatePowerState(Mockito.anyMap(), Mockito.anyLong(), + Mockito.any(Date.class)); + } + + /** + * Same forced report, but the instance has been in its current state for longer than the graceful period. + * It is genuinely missing and must still be reported, so out-of-band stop detection keeps working. + */ + @Test + public void test_processMissingVmReport_forcedReportStillReportsSettledInstance() { + VMInstanceVO instance = missingInstance(1L, new Date(System.currentTimeMillis() - 600000L)); + Mockito.when(mgmtServiceConf.getPingInterval()).thenReturn(60); + Mockito.when(instanceDao.findByHostInStatesExcluding(Mockito.anyLong(), Mockito.anyCollection(), + Mockito.eq(VirtualMachine.State.Running), Mockito.eq(VirtualMachine.State.Stopping), + Mockito.eq(VirtualMachine.State.Starting))).thenReturn(Collections.singletonList(instance)); + Mockito.when(instanceDao.updatePowerState(Mockito.anyMap(), Mockito.anyLong(), + Mockito.any(Date.class))).thenReturn(new HashMap<>()); + + virtualMachinePowerStateSync.processHostVmStatePingReport(1L, new HashMap<>(), true); + + Mockito.verify(instanceDao, Mockito.times(1)).updatePowerState( + Mockito.argThat(states -> VirtualMachine.PowerState.PowerReportMissing.equals(states.get(1L))), + Mockito.eq(1L), Mockito.any(Date.class)); + } + + /** + * An unforced report must keep honouring the graceful period for a settled instance that is only briefly absent. + */ + @Test + public void test_processMissingVmReport_unforcedReportHonoursGracefulPeriod() { + Mockito.when(mgmtServiceConf.getPingInterval()).thenReturn(60); + VMInstanceVO instance = missingInstance(1L, new Date(System.currentTimeMillis() - 5000L)); + Mockito.when(instanceDao.findByHostInStatesExcluding(Mockito.anyLong(), Mockito.anyCollection(), + Mockito.eq(VirtualMachine.State.Running), Mockito.eq(VirtualMachine.State.Stopping), + Mockito.eq(VirtualMachine.State.Starting))).thenReturn(Collections.singletonList(instance)); + Mockito.lenient().when(instanceDao.isPowerStateUpToDate(instance)).thenReturn(true); + + virtualMachinePowerStateSync.processHostVmStatePingReport(1L, new HashMap<>(), false); + + Mockito.verify(instanceDao, Mockito.never()).updatePowerState(Mockito.anyMap(), Mockito.anyLong(), + Mockito.any(Date.class)); + } + + /** + * An unknown name in a report must be recorded, so a second sighting of the same set says nothing new. + */ + @Test + public void test_convertVmStateReport_recordsUnknownInstances() { + Map report = new HashMap<>(); + report.put("i-2-2-VM", new HostVmStateReportEntry(VirtualMachine.PowerState.PowerOn, "host")); + Mockito.when(instanceDao.getNameIdMapForVmInstanceNames(Mockito.anyCollection())) + .thenReturn(new HashMap<>()); + + virtualMachinePowerStateSync.convertVmStateReport(1L, report); + + Assert.assertFalse(virtualMachinePowerStateSync.reportUnknownInstances(1L, + new HashSet<>(Arrays.asList("i-2-2-VM")))); + } }