http://git-wip-us.apache.org/repos/asf/cloudstack/blob/8bc02940/engine/orchestration/src/com/cloud/vm/VirtualMachineManagerImpl.java ---------------------------------------------------------------------- diff --git a/engine/orchestration/src/com/cloud/vm/VirtualMachineManagerImpl.java b/engine/orchestration/src/com/cloud/vm/VirtualMachineManagerImpl.java index 7d373a2..9dea90a 100644 --- a/engine/orchestration/src/com/cloud/vm/VirtualMachineManagerImpl.java +++ b/engine/orchestration/src/com/cloud/vm/VirtualMachineManagerImpl.java @@ -67,6 +67,7 @@ import org.apache.cloudstack.storage.datastore.db.PrimaryDataStoreDao; import org.apache.cloudstack.storage.datastore.db.StoragePoolVO; import org.apache.cloudstack.storage.to.VolumeObjectTO; import org.apache.cloudstack.utils.identity.ManagementServerNode; +import org.apache.log4j.Logger; import com.cloud.agent.AgentManager; import com.cloud.agent.Listener; @@ -205,6 +206,7 @@ import com.cloud.vm.snapshot.dao.VMSnapshotDao; @Local(value = VirtualMachineManager.class) public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMachineManager, VmWorkJobHandler, Listener, Configurable { + private static final Logger s_logger = Logger.getLogger(VirtualMachineManagerImpl.class); public static final String VM_WORK_JOB_HANDLER = VirtualMachineManagerImpl.class.getSimpleName(); @@ -380,8 +382,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final VMInstanceVO vm = _vmDao.findVMByInstanceName(vmInstanceName); final Account owner = _entityMgr.findById(Account.class, vm.getAccountId()); - if (logger.isDebugEnabled()) { - logger.debug("Allocating entries for VM: " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Allocating entries for VM: " + vm); } vm.setDataCenterId(plan.getDataCenterId()); @@ -396,8 +398,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac Transaction.execute(new TransactionCallbackWithExceptionNoReturn<InsufficientCapacityException>() { @Override public void doInTransactionWithoutResult(final TransactionStatus status) throws InsufficientCapacityException { - if (logger.isDebugEnabled()) { - logger.debug("Allocating nics for " + vmFinal); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Allocating nics for " + vmFinal); } try { @@ -406,8 +408,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac throw new CloudRuntimeException("Concurrent operation while trying to allocate resources for the VM", e); } - if (logger.isDebugEnabled()) { - logger.debug("Allocating disks for " + vmFinal); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Allocating disks for " + vmFinal); } if (template.getFormat() == ImageFormat.ISO) { @@ -429,8 +431,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } }); - if (logger.isDebugEnabled()) { - logger.debug("Allocation completed for VM: " + vmFinal); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Allocation completed for VM: " + vmFinal); } } @@ -466,8 +468,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac protected void advanceExpunge(VMInstanceVO vm) throws ResourceUnavailableException, OperationTimedoutException, ConcurrentOperationException { if (vm == null || vm.getRemoved() != null) { - if (logger.isDebugEnabled()) { - logger.debug("Unable to find vm or vm is destroyed: " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to find vm or vm is destroyed: " + vm); } return; } @@ -477,28 +479,28 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { if (!stateTransitTo(vm, VirtualMachine.Event.ExpungeOperation, vm.getHostId())) { - logger.debug("Unable to destroy the vm because it is not in the correct state: " + vm); + s_logger.debug("Unable to destroy the vm because it is not in the correct state: " + vm); throw new CloudRuntimeException("Unable to destroy " + vm); } } catch (final NoTransitionException e) { - logger.debug("Unable to destroy the vm because it is not in the correct state: " + vm); + s_logger.debug("Unable to destroy the vm because it is not in the correct state: " + vm); throw new CloudRuntimeException("Unable to destroy " + vm, e); } - if (logger.isDebugEnabled()) { - logger.debug("Destroying vm " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Destroying vm " + vm); } final VirtualMachineProfile profile = new VirtualMachineProfileImpl(vm); final HypervisorGuru hvGuru = _hvGuruMgr.getGuru(vm.getHypervisorType()); - logger.debug("Cleaning up NICS"); + s_logger.debug("Cleaning up NICS"); final List<Command> nicExpungeCommands = hvGuru.finalizeExpungeNics(vm, profile.getNics()); _networkMgr.cleanupNics(profile); - logger.debug("Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage"); + s_logger.debug("Cleaning up hypervisor data structures (ex. SRs in XenServer) for managed storage"); final List<Command> volumeExpungeCommands = hvGuru.finalizeExpungeVolumes(vm); @@ -516,7 +518,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac if (!cmds.isSuccessful()) { for (final Answer answer : cmds.getAnswers()) { if (!answer.getResult()) { - logger.warn("Failed to expunge vm due to: " + answer.getDetails()); + s_logger.warn("Failed to expunge vm due to: " + answer.getDetails()); throw new CloudRuntimeException("Unable to expunge " + vm + " due to " + answer.getDetails()); } @@ -553,7 +555,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac if (!cmds.isSuccessful()) { for (final Answer answer : cmds.getAnswers()) { if (!answer.getResult()) { - logger.warn("Failed to expunge vm due to: " + answer.getDetails()); + s_logger.warn("Failed to expunge vm due to: " + answer.getDetails()); throw new CloudRuntimeException("Unable to expunge " + vm + " due to " + answer.getDetails()); } } @@ -561,8 +563,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } } - if (logger.isDebugEnabled()) { - logger.debug("Expunged " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Expunged " + vm); } } @@ -631,15 +633,15 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac while (true) { final ItWorkVO vo = _workDao.findByOutstandingWork(vm.getId(), state); if (vo == null) { - if (logger.isDebugEnabled()) { - logger.debug("Unable to find work for VM: " + vm + " and state: " + state); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to find work for VM: " + vm + " and state: " + state); } return true; } if (vo.getStep() == Step.Done) { - if (logger.isDebugEnabled()) { - logger.debug("Work for " + vm + " is " + vo.getStep()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Work for " + vm + " is " + vo.getStep()); } return true; } @@ -647,24 +649,24 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac // also check DB to get latest VM state to detect vm update from concurrent process before idle waiting to get an early exit final VMInstanceVO instance = _vmDao.findById(vm.getId()); if (instance != null && instance.getState() == State.Running) { - if (logger.isDebugEnabled()) { - logger.debug("VM is already started in DB: " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("VM is already started in DB: " + vm); } return true; } if (vo.getSecondsTaskIsInactive() > VmOpCancelInterval.value()) { - logger.warn("The task item for vm " + vm + " has been inactive for " + vo.getSecondsTaskIsInactive()); + s_logger.warn("The task item for vm " + vm + " has been inactive for " + vo.getSecondsTaskIsInactive()); return false; } try { Thread.sleep(VmOpWaitInterval.value()*1000); } catch (final InterruptedException e) { - logger.info("Waiting for " + vm + " but is interrupted"); + s_logger.info("Waiting for " + vm + " but is interrupted"); throw new ConcurrentOperationException("Waiting for " + vm + " but is interrupted"); } - logger.debug("Waiting some more to make sure there's no activity on " + vm); + s_logger.debug("Waiting some more to make sure there's no activity on " + vm); } } @@ -683,13 +685,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac Transaction.execute(new TransactionCallbackWithException<Ternary<VMInstanceVO, ReservationContext, ItWorkVO>, NoTransitionException>() { @Override public Ternary<VMInstanceVO, ReservationContext, ItWorkVO> doInTransaction(final TransactionStatus status) throws NoTransitionException { - final Journal journal = new Journal.LogJournal("Creating " + vm, logger); + final Journal journal = new Journal.LogJournal("Creating " + vm, s_logger); final ItWorkVO work = _workDao.persist(workFinal); final ReservationContextImpl context = new ReservationContextImpl(work.getId(), journal, caller, account); if (stateTransitTo(vm, Event.StartRequested, null, work.getId())) { - if (logger.isDebugEnabled()) { - logger.debug("Successfully transitioned to start state for " + vm + " reservation id = " + work.getId()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Successfully transitioned to start state for " + vm + " reservation id = " + work.getId()); } return new Ternary<VMInstanceVO, ReservationContext, ItWorkVO>(vm, context, work); } @@ -703,8 +705,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac return result; } } catch (final NoTransitionException e) { - if (logger.isDebugEnabled()) { - logger.debug("Unable to transition into Starting state due to " + e.getMessage()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to transition into Starting state due to " + e.getMessage()); } } @@ -713,14 +715,14 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac throw new ConcurrentOperationException("Unable to acquire lock on " + vm); } - if (logger.isDebugEnabled()) { - logger.debug("Determining why we're unable to update the state to Starting for " + instance + ". Retry=" + retry); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Determining why we're unable to update the state to Starting for " + instance + ". Retry=" + retry); } final State state = instance.getState(); if (state == State.Running) { - if (logger.isDebugEnabled()) { - logger.debug("VM is already started: " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("VM is already started: " + vm); } return null; } @@ -734,7 +736,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } if (state != State.Stopped) { - logger.debug("VM " + vm + " is not in a state to be started: " + state); + s_logger.debug("VM " + vm + " is not in a state to be started: " + state); return null; } } @@ -844,13 +846,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final ServiceOfferingVO offering = _offeringDao.findById(vm.getId(), vm.getServiceOfferingId()); final VirtualMachineTemplate template = _entityMgr.findByIdIncludingRemoved(VirtualMachineTemplate.class, vm.getTemplateId()); - if (logger.isDebugEnabled()) { - logger.debug("Trying to deploy VM, vm has dcId: " + vm.getDataCenterId() + " and podId: " + vm.getPodIdToDeployIn()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Trying to deploy VM, vm has dcId: " + vm.getDataCenterId() + " and podId: " + vm.getPodIdToDeployIn()); } DataCenterDeployment plan = new DataCenterDeployment(vm.getDataCenterId(), vm.getPodIdToDeployIn(), null, null, null, null, ctx); if (planToDeploy != null && planToDeploy.getDataCenterId() != 0) { - if (logger.isDebugEnabled()) { - logger.debug("advanceStart: DeploymentPlan is provided, using dcId:" + planToDeploy.getDataCenterId() + ", podId: " + planToDeploy.getPodId() + + if (s_logger.isDebugEnabled()) { + s_logger.debug("advanceStart: DeploymentPlan is provided, using dcId:" + planToDeploy.getDataCenterId() + ", podId: " + planToDeploy.getPodId() + ", clusterId: " + planToDeploy.getClusterId() + ", hostId: " + planToDeploy.getHostId() + ", poolId: " + planToDeploy.getPoolId()); } plan = @@ -871,8 +873,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac if (avoids == null) { avoids = new ExcludeList(); } - if (logger.isDebugEnabled()) { - logger.debug("Deploy avoids pods: " + avoids.getPodsToAvoid() + ", clusters: " + avoids.getClustersToAvoid() + ", hosts: " + avoids.getHostsToAvoid()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Deploy avoids pods: " + avoids.getPodsToAvoid() + ", clusters: " + avoids.getClustersToAvoid() + ", hosts: " + avoids.getHostsToAvoid()); } boolean planChangedByVolume = false; @@ -891,16 +893,16 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac // reassign pool for the volume even if it ready. final Long volTemplateId = vol.getTemplateId(); if (volTemplateId != null && volTemplateId.longValue() != template.getId()) { - if (logger.isDebugEnabled()) { - logger.debug(vol + " of " + vm + " is READY, but template ids don't match, let the planner reassign a new pool"); + if (s_logger.isDebugEnabled()) { + s_logger.debug(vol + " of " + vm + " is READY, but template ids don't match, let the planner reassign a new pool"); } continue; } final StoragePool pool = (StoragePool)dataStoreMgr.getPrimaryDataStore(vol.getPoolId()); if (!pool.isInMaintenance()) { - if (logger.isDebugEnabled()) { - logger.debug("Root volume is ready, need to place VM in volume's cluster"); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Root volume is ready, need to place VM in volume's cluster"); } final long rootVolDcId = pool.getDataCenterId(); final Long rootVolPodId = pool.getPodId(); @@ -911,8 +913,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac if (rootVolClusterId.longValue() != clusterIdSpecified.longValue()) { // cannot satisfy the plan passed in to the // planner - if (logger.isDebugEnabled()) { - logger.debug("Cannot satisfy the deployment plan passed in since the ready Root volume is in different cluster. volume's cluster: " + + if (s_logger.isDebugEnabled()) { + s_logger.debug("Cannot satisfy the deployment plan passed in since the ready Root volume is in different cluster. volume's cluster: " + rootVolClusterId + ", cluster specified: " + clusterIdSpecified); } throw new ResourceUnavailableException( @@ -925,8 +927,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac planToDeploy.getHostId(), vol.getPoolId(), null, ctx); } else { plan = new DataCenterDeployment(rootVolDcId, rootVolPodId, rootVolClusterId, null, vol.getPoolId(), null, ctx); - if (logger.isDebugEnabled()) { - logger.debug(vol + " is READY, changing deployment plan to use this pool's dcId: " + rootVolDcId + " , podId: " + rootVolPodId + + if (s_logger.isDebugEnabled()) { + s_logger.debug(vol + " is READY, changing deployment plan to use this pool's dcId: " + rootVolDcId + " , podId: " + rootVolPodId + " , and clusterId: " + rootVolClusterId); } planChangedByVolume = true; @@ -941,7 +943,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { dest = _dpMgr.planDeployment(vmProfile, plan, avoids, planner); } catch (final AffinityConflictException e2) { - logger.warn("Unable to create deployment, affinity rules associted to the VM conflict", e2); + s_logger.warn("Unable to create deployment, affinity rules associted to the VM conflict", e2); throw new CloudRuntimeException("Unable to create deployment, affinity rules associted to the VM conflict"); } @@ -990,8 +992,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } try { - if (logger.isDebugEnabled()) { - logger.debug("VM is being created in podId: " + vm.getPodIdToDeployIn()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("VM is being created in podId: " + vm.getPodIdToDeployIn()); } _networkMgr.prepare(vmProfile, dest, ctx); if (vm.getHypervisorType() != HypervisorType.BareMetal) { @@ -1052,13 +1054,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } startedVm = vm; - if (logger.isDebugEnabled()) { - logger.debug("Start completed for VM " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Start completed for VM " + vm); } return; } else { - if (logger.isDebugEnabled()) { - logger.info("The guru did not like the answers so stopping " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.info("The guru did not like the answers so stopping " + vm); } final StopCommand cmd = new StopCommand(vm, getExecuteInSequence(vm.getHypervisorType()), false); @@ -1076,49 +1078,49 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } if (answer == null || !answer.getResult()) { - logger.warn("Unable to stop " + vm + " due to " + (answer != null ? answer.getDetails() : "no answers")); + s_logger.warn("Unable to stop " + vm + " due to " + (answer != null ? answer.getDetails() : "no answers")); _haMgr.scheduleStop(vm, destHostId, WorkType.ForceStop); throw new ExecutionException("Unable to stop " + vm + " so we are unable to retry the start operation"); } throw new ExecutionException("Unable to start " + vm + " due to error in finalizeStart, not retrying"); } } - logger.info("Unable to start VM on " + dest.getHost() + " due to " + (startAnswer == null ? " no start answer" : startAnswer.getDetails())); + s_logger.info("Unable to start VM on " + dest.getHost() + " due to " + (startAnswer == null ? " no start answer" : startAnswer.getDetails())); if (startAnswer != null && startAnswer.getContextParam("stopRetry") != null) { break; } } catch (final OperationTimedoutException e) { - logger.debug("Unable to send the start command to host " + dest.getHost()); + s_logger.debug("Unable to send the start command to host " + dest.getHost()); if (e.isActive()) { _haMgr.scheduleStop(vm, destHostId, WorkType.CheckStop); } canRetry = false; throw new AgentUnavailableException("Unable to start " + vm.getHostName(), destHostId, e); } catch (final ResourceUnavailableException e) { - logger.info("Unable to contact resource.", e); + s_logger.info("Unable to contact resource.", e); if (!avoids.add(e)) { if (e.getScope() == Volume.class || e.getScope() == Nic.class) { throw e; } else { - logger.warn("unexpected ResourceUnavailableException : " + e.getScope().getName(), e); + s_logger.warn("unexpected ResourceUnavailableException : " + e.getScope().getName(), e); throw e; } } } catch (final InsufficientCapacityException e) { - logger.info("Insufficient capacity ", e); + s_logger.info("Insufficient capacity ", e); if (!avoids.add(e)) { if (e.getScope() == Volume.class || e.getScope() == Nic.class) { throw e; } else { - logger.warn("unexpected InsufficientCapacityException : " + e.getScope().getName(), e); + s_logger.warn("unexpected InsufficientCapacityException : " + e.getScope().getName(), e); } } } catch (final ExecutionException e) { - logger.error("Failed to start instance " + vm, e); + s_logger.error("Failed to start instance " + vm, e); throw new AgentUnavailableException("Unable to start instance due to " + e.getMessage(), destHostId, e); } catch (final NoTransitionException e) { - logger.error("Failed to start instance " + vm, e); + s_logger.error("Failed to start instance " + vm, e); throw new AgentUnavailableException("Unable to start instance due to " + e.getMessage(), destHostId, e); } finally { if (startedVm == null && canRetry) { @@ -1275,13 +1277,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } if (!answer.getResult()) { final String details = answer.getDetails(); - logger.debug("Unable to stop VM due to " + details); + s_logger.debug("Unable to stop VM due to " + details); return false; } guru.finalizeStop(profile, answer); } else { - logger.error("Invalid answer received in response to a StopCommand for " + vm.getInstanceName()); + s_logger.error("Invalid answer received in response to a StopCommand for " + vm.getInstanceName()); return false; } @@ -1301,33 +1303,33 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac protected boolean cleanup(final VirtualMachineGuru guru, final VirtualMachineProfile profile, final ItWorkVO work, final Event event, final boolean cleanUpEvenIfUnableToStop) { final VirtualMachine vm = profile.getVirtualMachine(); final State state = vm.getState(); - logger.debug("Cleaning up resources for the vm " + vm + " in " + state + " state"); + s_logger.debug("Cleaning up resources for the vm " + vm + " in " + state + " state"); try { if (state == State.Starting) { if (work != null) { final Step step = work.getStep(); if (step == Step.Starting && !cleanUpEvenIfUnableToStop) { - logger.warn("Unable to cleanup vm " + vm + "; work state is incorrect: " + step); + s_logger.warn("Unable to cleanup vm " + vm + "; work state is incorrect: " + step); return false; } if (step == Step.Started || step == Step.Starting || step == Step.Release) { if (vm.getHostId() != null) { if (!sendStop(guru, profile, cleanUpEvenIfUnableToStop, false)) { - logger.warn("Failed to stop vm " + vm + " in " + State.Starting + " state as a part of cleanup process"); + s_logger.warn("Failed to stop vm " + vm + " in " + State.Starting + " state as a part of cleanup process"); return false; } } } if (step != Step.Release && step != Step.Prepare && step != Step.Started && step != Step.Starting) { - logger.debug("Cleanup is not needed for vm " + vm + "; work state is incorrect: " + step); + s_logger.debug("Cleanup is not needed for vm " + vm + "; work state is incorrect: " + step); return true; } } else { if (vm.getHostId() != null) { if (!sendStop(guru, profile, cleanUpEvenIfUnableToStop, false)) { - logger.warn("Failed to stop vm " + vm + " in " + State.Starting + " state as a part of cleanup process"); + s_logger.warn("Failed to stop vm " + vm + " in " + State.Starting + " state as a part of cleanup process"); return false; } } @@ -1336,39 +1338,39 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } else if (state == State.Stopping) { if (vm.getHostId() != null) { if (!sendStop(guru, profile, cleanUpEvenIfUnableToStop, false)) { - logger.warn("Failed to stop vm " + vm + " in " + State.Stopping + " state as a part of cleanup process"); + s_logger.warn("Failed to stop vm " + vm + " in " + State.Stopping + " state as a part of cleanup process"); return false; } } } else if (state == State.Migrating) { if (vm.getHostId() != null) { if (!sendStop(guru, profile, cleanUpEvenIfUnableToStop, false)) { - logger.warn("Failed to stop vm " + vm + " in " + State.Migrating + " state as a part of cleanup process"); + s_logger.warn("Failed to stop vm " + vm + " in " + State.Migrating + " state as a part of cleanup process"); return false; } } if (vm.getLastHostId() != null) { if (!sendStop(guru, profile, cleanUpEvenIfUnableToStop, false)) { - logger.warn("Failed to stop vm " + vm + " in " + State.Migrating + " state as a part of cleanup process"); + s_logger.warn("Failed to stop vm " + vm + " in " + State.Migrating + " state as a part of cleanup process"); return false; } } } else if (state == State.Running) { if (!sendStop(guru, profile, cleanUpEvenIfUnableToStop, false)) { - logger.warn("Failed to stop vm " + vm + " in " + State.Running + " state as a part of cleanup process"); + s_logger.warn("Failed to stop vm " + vm + " in " + State.Running + " state as a part of cleanup process"); return false; } } } finally { try { _networkMgr.release(profile, cleanUpEvenIfUnableToStop); - logger.debug("Successfully released network resources for the vm " + vm); + s_logger.debug("Successfully released network resources for the vm " + vm); } catch (final Exception e) { - logger.warn("Unable to release some network resources.", e); + s_logger.warn("Unable to release some network resources.", e); } volumeMgr.release(profile); - logger.debug("Successfully cleanued up resources for the vm " + vm + " in " + state + " state"); + s_logger.debug("Successfully cleanued up resources for the vm " + vm + " in " + state + " state"); } return true; @@ -1431,42 +1433,42 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac ConcurrentOperationException { final State state = vm.getState(); if (state == State.Stopped) { - if (logger.isDebugEnabled()) { - logger.debug("VM is already stopped: " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("VM is already stopped: " + vm); } return; } if (state == State.Destroyed || state == State.Expunging || state == State.Error) { - if (logger.isDebugEnabled()) { - logger.debug("Stopped called on " + vm + " but the state is " + state); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Stopped called on " + vm + " but the state is " + state); } return; } // grab outstanding work item if any final ItWorkVO work = _workDao.findByOutstandingWork(vm.getId(), vm.getState()); if (work != null) { - if (logger.isDebugEnabled()) { - logger.debug("Found an outstanding work item for this vm " + vm + " with state:" + vm.getState() + ", work id:" + work.getId()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Found an outstanding work item for this vm " + vm + " with state:" + vm.getState() + ", work id:" + work.getId()); } } final Long hostId = vm.getHostId(); if (hostId == null) { if (!cleanUpEvenIfUnableToStop) { - if (logger.isDebugEnabled()) { - logger.debug("HostId is null but this is not a forced stop, cannot stop vm " + vm + " with state:" + vm.getState()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("HostId is null but this is not a forced stop, cannot stop vm " + vm + " with state:" + vm.getState()); } throw new CloudRuntimeException("Unable to stop " + vm); } try { stateTransitTo(vm, Event.AgentReportStopped, null, null); } catch (final NoTransitionException e) { - logger.warn(e.getMessage()); + s_logger.warn(e.getMessage()); } // mark outstanding work item if any as done if (work != null) { - if (logger.isDebugEnabled()) { - logger.debug("Updating work item to Done, id:" + work.getId()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Updating work item to Done, id:" + work.getId()); } work.setStep(Step.Done); _workDao.update(work.getId(), work); @@ -1486,26 +1488,26 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac throw new CloudRuntimeException("We cannot stop " + vm + " when it is in state " + vm.getState()); } final boolean doCleanup = true; - if (logger.isDebugEnabled()) { - logger.debug("Unable to transition the state but we're moving on because it's forced stop"); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to transition the state but we're moving on because it's forced stop"); } if (doCleanup) { if (cleanup(vmGuru, new VirtualMachineProfileImpl(vm), work, Event.StopRequested, cleanUpEvenIfUnableToStop)) { try { - if (logger.isDebugEnabled()) { - logger.debug("Updating work item to Done, id:" + work.getId()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Updating work item to Done, id:" + work.getId()); } if (!changeState(vm, Event.AgentReportStopped, null, work, Step.Done)) { throw new CloudRuntimeException("Unable to stop " + vm); } } catch (final NoTransitionException e) { - logger.warn("Unable to cleanup " + vm); + s_logger.warn("Unable to cleanup " + vm); throw new CloudRuntimeException("Unable to stop " + vm, e); } } else { - if (logger.isDebugEnabled()) { - logger.debug("Failed to cleanup VM: " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Failed to cleanup VM: " + vm); } throw new CloudRuntimeException("Failed to cleanup " + vm + " , current state " + vm.getState()); } @@ -1551,50 +1553,50 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } } catch (final AgentUnavailableException e) { - logger.warn("Unable to stop vm, agent unavailable: " + e.toString()); + s_logger.warn("Unable to stop vm, agent unavailable: " + e.toString()); } catch (final OperationTimedoutException e) { - logger.warn("Unable to stop vm, operation timed out: " + e.toString()); + s_logger.warn("Unable to stop vm, operation timed out: " + e.toString()); } finally { if (!stopped) { if (!cleanUpEvenIfUnableToStop) { - logger.warn("Unable to stop vm " + vm); + s_logger.warn("Unable to stop vm " + vm); try { stateTransitTo(vm, Event.OperationFailed, vm.getHostId()); } catch (final NoTransitionException e) { - logger.warn("Unable to transition the state " + vm); + s_logger.warn("Unable to transition the state " + vm); } throw new CloudRuntimeException("Unable to stop " + vm); } else { - logger.warn("Unable to actually stop " + vm + " but continue with release because it's a force stop"); + s_logger.warn("Unable to actually stop " + vm + " but continue with release because it's a force stop"); vmGuru.finalizeStop(profile, answer); } } } - if (logger.isDebugEnabled()) { - logger.debug(vm + " is stopped on the host. Proceeding to release resource held."); + if (s_logger.isDebugEnabled()) { + s_logger.debug(vm + " is stopped on the host. Proceeding to release resource held."); } try { _networkMgr.release(profile, cleanUpEvenIfUnableToStop); - logger.debug("Successfully released network resources for the vm " + vm); + s_logger.debug("Successfully released network resources for the vm " + vm); } catch (final Exception e) { - logger.warn("Unable to release some network resources.", e); + s_logger.warn("Unable to release some network resources.", e); } try { if (vm.getHypervisorType() != HypervisorType.BareMetal) { volumeMgr.release(profile); - logger.debug("Successfully released storage resources for the vm " + vm); + s_logger.debug("Successfully released storage resources for the vm " + vm); } } catch (final Exception e) { - logger.warn("Unable to release storage resources.", e); + s_logger.warn("Unable to release storage resources.", e); } try { if (work != null) { - if (logger.isDebugEnabled()) { - logger.debug("Updating the outstanding work item to Done, id:" + work.getId()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Updating the outstanding work item to Done, id:" + work.getId()); } work.setStep(Step.Done); _workDao.update(work.getId(), work); @@ -1604,7 +1606,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac throw new CloudRuntimeException("unable to stop " + vm); } } catch (final NoTransitionException e) { - logger.warn(e.getMessage()); + s_logger.warn(e.getMessage()); throw new CloudRuntimeException("Unable to stop " + vm); } } @@ -1620,7 +1622,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac // hacking it here at general VM manager /* if (_vmSnapshotMgr.hasActiveVMSnapshotTasks(vm.getId())) { - logger.error("State transit with event: " + e + " failed due to: " + vm.getInstanceName() + " has active VM snapshots tasks"); + s_logger.error("State transit with event: " + e + " failed due to: " + vm.getInstanceName() + " has active VM snapshots tasks"); return false; } */ @@ -1636,7 +1638,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac * Remove the hacking logic here. // if there are active vm snapshots task, state change is not allowed if (_vmSnapshotMgr.hasActiveVMSnapshotTasks(vm.getId())) { - logger.error("State transit with event: " + e + " failed due to: " + vm.getInstanceName() + " has active VM snapshots tasks"); + s_logger.error("State transit with event: " + e + " failed due to: " + vm.getInstanceName() + " has active VM snapshots tasks"); return false; } */ @@ -1658,20 +1660,20 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac public void destroy(final String vmUuid) throws AgentUnavailableException, OperationTimedoutException, ConcurrentOperationException { VMInstanceVO vm = _vmDao.findByUuid(vmUuid); if (vm == null || vm.getState() == State.Destroyed || vm.getState() == State.Expunging || vm.getRemoved() != null) { - if (logger.isDebugEnabled()) { - logger.debug("Unable to find vm or vm is destroyed: " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to find vm or vm is destroyed: " + vm); } return; } - if (logger.isDebugEnabled()) { - logger.debug("Destroying vm " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Destroying vm " + vm); } advanceStop(vmUuid, VmDestroyForcestop.value()); if (!_vmSnapshotMgr.deleteAllVMSnapshots(vm.getId(), null)) { - logger.debug("Unable to delete all snapshots for " + vm); + s_logger.debug("Unable to delete all snapshots for " + vm); throw new CloudRuntimeException("Unable to delete vm snapshots for " + vm); } @@ -1679,11 +1681,11 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac vm = _vmDao.findByUuid(vmUuid); try { if (!stateTransitTo(vm, VirtualMachine.Event.DestroyRequested, vm.getHostId())) { - logger.debug("Unable to destroy the vm because it is not in the correct state: " + vm); + s_logger.debug("Unable to destroy the vm because it is not in the correct state: " + vm); throw new CloudRuntimeException("Unable to destroy " + vm); } } catch (final NoTransitionException e) { - logger.debug(e.getMessage()); + s_logger.debug(e.getMessage()); throw new CloudRuntimeException("Unable to destroy " + vm, e); } } @@ -1749,7 +1751,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { stateTransitTo(vm, VirtualMachine.Event.StorageMigrationRequested, null); } catch (final NoTransitionException e) { - logger.debug("Unable to migrate vm: " + e.toString()); + s_logger.debug("Unable to migrate vm: " + e.toString()); throw new CloudRuntimeException("Unable to migrate vm: " + e.toString()); } @@ -1779,7 +1781,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final String srcDcName = _clusterDetailsDao.getVmwareDcName(srcClusterId); final String destDcName = _clusterDetailsDao.getVmwareDcName(destClusterId); if (srcDcName != null && destDcName != null && !srcDcName.equals(destDcName)) { - logger.debug("Since VM's storage was successfully migrated across VMware Datacenters, unregistering VM: " + vm.getInstanceName() + + s_logger.debug("Since VM's storage was successfully migrated across VMware Datacenters, unregistering VM: " + vm.getInstanceName() + " from source host: " + srcHost.getId()); final UnregisterVMCommand uvc = new UnregisterVMCommand(vm.getInstanceName()); uvc.setCleanupVmFiles(true); @@ -1794,28 +1796,28 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } } else { - logger.debug("Storage migration failed"); + s_logger.debug("Storage migration failed"); } } catch (final ConcurrentOperationException e) { - logger.debug("Failed to migration: " + e.toString()); + s_logger.debug("Failed to migration: " + e.toString()); throw new CloudRuntimeException("Failed to migration: " + e.toString()); } catch (final InsufficientVirtualNetworkCapacityException e) { - logger.debug("Failed to migration: " + e.toString()); + s_logger.debug("Failed to migration: " + e.toString()); throw new CloudRuntimeException("Failed to migration: " + e.toString()); } catch (final InsufficientAddressCapacityException e) { - logger.debug("Failed to migration: " + e.toString()); + s_logger.debug("Failed to migration: " + e.toString()); throw new CloudRuntimeException("Failed to migration: " + e.toString()); } catch (final InsufficientCapacityException e) { - logger.debug("Failed to migration: " + e.toString()); + s_logger.debug("Failed to migration: " + e.toString()); throw new CloudRuntimeException("Failed to migration: " + e.toString()); } catch (final StorageUnavailableException e) { - logger.debug("Failed to migration: " + e.toString()); + s_logger.debug("Failed to migration: " + e.toString()); throw new CloudRuntimeException("Failed to migration: " + e.toString()); } finally { try { stateTransitTo(vm, VirtualMachine.Event.AgentReportStopped, null); } catch (final NoTransitionException e) { - logger.debug("Failed to change vm state: " + e.toString()); + s_logger.debug("Failed to change vm state: " + e.toString()); throw new CloudRuntimeException("Failed to change vm state: " + e.toString()); } } @@ -1868,8 +1870,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac private void orchestrateMigrate(final String vmUuid, final long srcHostId, final DeployDestination dest) throws ResourceUnavailableException, ConcurrentOperationException { final VMInstanceVO vm = _vmDao.findByUuid(vmUuid); if (vm == null) { - if (logger.isDebugEnabled()) { - logger.debug("Unable to find the vm " + vmUuid); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to find the vm " + vmUuid); } throw new CloudRuntimeException("Unable to find a virtual machine with id " + vmUuid); } @@ -1877,12 +1879,12 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } protected void migrate(final VMInstanceVO vm, final long srcHostId, final DeployDestination dest) throws ResourceUnavailableException, ConcurrentOperationException { - logger.info("Migrating " + vm + " to " + dest); + s_logger.info("Migrating " + vm + " to " + dest); final long dstHostId = dest.getHost().getId(); final Host fromHost = _hostDao.findById(srcHostId); if (fromHost == null) { - logger.info("Unable to find the host to migrate from: " + srcHostId); + s_logger.info("Unable to find the host to migrate from: " + srcHostId); throw new CloudRuntimeException("Unable to find the host to migrate from: " + srcHostId); } @@ -1890,7 +1892,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final List<VolumeVO> volumes = _volsDao.findCreatedByInstance(vm.getId()); for (final VolumeVO volume : volumes) { if (!_storagePoolDao.findById(volume.getPoolId()).getScope().equals(ScopeType.ZONE)) { - logger.info("Source and destination host are not in same cluster and all volumes are not on zone wide primary store, unable to migrate to host: " + s_logger.info("Source and destination host are not in same cluster and all volumes are not on zone wide primary store, unable to migrate to host: " + dest.getHost().getId()); throw new CloudRuntimeException( "Source and destination host are not in same cluster and all volumes are not on zone wide primary store, unable to migrate to host: " @@ -1902,8 +1904,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final VirtualMachineGuru vmGuru = getVmGuru(vm); if (vm.getState() != State.Running) { - if (logger.isDebugEnabled()) { - logger.debug("VM is not Running, unable to migrate the vm " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("VM is not Running, unable to migrate the vm " + vm); } throw new CloudRuntimeException("VM is not Running, unable to migrate the vm currently " + vm + " , current state: " + vm.getState().toString()); } @@ -1957,12 +1959,12 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { if (vm == null || vm.getHostId() == null || vm.getHostId() != srcHostId || !changeState(vm, Event.MigrationRequested, dstHostId, work, Step.Migrating)) { _networkMgr.rollbackNicForMigration(vmSrc, profile); - logger.info("Migration cancelled because state has changed: " + vm); + s_logger.info("Migration cancelled because state has changed: " + vm); throw new ConcurrentOperationException("Migration cancelled because state has changed: " + vm); } } catch (final NoTransitionException e1) { _networkMgr.rollbackNicForMigration(vmSrc, profile); - logger.info("Migration cancelled because " + e1.getMessage()); + s_logger.info("Migration cancelled because " + e1.getMessage()); throw new ConcurrentOperationException("Migration cancelled because " + e1.getMessage()); } @@ -1980,7 +1982,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } } catch (final OperationTimedoutException e) { if (e.isActive()) { - logger.warn("Active migration command so scheduling a restart for " + vm); + s_logger.warn("Active migration command so scheduling a restart for " + vm); _haMgr.scheduleRestart(vm, true); } throw new AgentUnavailableException("Operation timed out on migrating " + vm, dstHostId); @@ -1996,23 +1998,23 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { if (!checkVmOnHost(vm, dstHostId)) { - logger.error("Unable to complete migration for " + vm); + s_logger.error("Unable to complete migration for " + vm); try { _agentMgr.send(srcHostId, new Commands(cleanup(vm)), null); } catch (final AgentUnavailableException e) { - logger.error("AgentUnavailableException while cleanup on source host: " + srcHostId); + s_logger.error("AgentUnavailableException while cleanup on source host: " + srcHostId); } cleanup(vmGuru, new VirtualMachineProfileImpl(vm), work, Event.AgentReportStopped, true); throw new CloudRuntimeException("Unable to complete migration for " + vm); } } catch (final OperationTimedoutException e) { - logger.debug("Error while checking the vm " + vm + " on host " + dstHostId, e); + s_logger.debug("Error while checking the vm " + vm + " on host " + dstHostId, e); } migrated = true; } finally { if (!migrated) { - logger.info("Migration was unsuccessful. Cleaning up: " + vm); + s_logger.info("Migration was unsuccessful. Cleaning up: " + vm); _networkMgr.rollbackNicForMigration(vmSrc, profile); _alertMgr.sendAlert(alertType, fromHost.getDataCenterId(), fromHost.getPodId(), @@ -2021,13 +2023,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { _agentMgr.send(dstHostId, new Commands(cleanup(vm)), null); } catch (final AgentUnavailableException ae) { - logger.info("Looks like the destination Host is unavailable for cleanup"); + s_logger.info("Looks like the destination Host is unavailable for cleanup"); } try { stateTransitTo(vm, Event.OperationFailed, srcHostId); } catch (final NoTransitionException e) { - logger.warn(e.getMessage()); + s_logger.warn(e.getMessage()); } } else { _networkMgr.commitNicForMigration(vmSrc, profile); @@ -2107,11 +2109,11 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac // Put the vm in migrating state. try { if (!changeState(vm, Event.MigrationRequested, hostId, work, Step.Migrating)) { - logger.info("Migration cancelled because state has changed: " + vm); + s_logger.info("Migration cancelled because state has changed: " + vm); throw new ConcurrentOperationException("Migration cancelled because state has changed: " + vm); } } catch (final NoTransitionException e) { - logger.info("Migration cancelled because " + e.getMessage()); + s_logger.info("Migration cancelled because " + e.getMessage()); throw new ConcurrentOperationException("Migration cancelled because " + e.getMessage()); } } @@ -2120,11 +2122,11 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac // Put the vm in running state. try { if (!changeState(vm, Event.OperationSucceeded, hostId, work, Step.Started)) { - logger.error("Unable to change the state for " + vm); + s_logger.error("Unable to change the state for " + vm); throw new ConcurrentOperationException("Unable to change the state for " + vm); } } catch (final NoTransitionException e) { - logger.error("Unable to change state due to " + e.getMessage()); + s_logger.error("Unable to change state due to " + e.getMessage()); throw new ConcurrentOperationException("Unable to change state due to " + e.getMessage()); } } @@ -2256,9 +2258,9 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac AttachOrDettachConfigDriveCommand dettachCommand = new AttachOrDettachConfigDriveCommand(vm.getInstanceName(), vmData, VmConfigDriveLabel.value(), false); try { _agentMgr.send(srcHost.getId(), dettachCommand); - logger.debug("Deleted config drive ISO for vm " + vm.getInstanceName() + " In host " + srcHost); + s_logger.debug("Deleted config drive ISO for vm " + vm.getInstanceName() + " In host " + srcHost); } catch (OperationTimedoutException e) { - logger.debug("TIme out occured while exeuting command AttachOrDettachConfigDrive " + e.getMessage()); + s_logger.debug("TIme out occured while exeuting command AttachOrDettachConfigDrive " + e.getMessage()); } @@ -2273,23 +2275,23 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { if (!checkVmOnHost(vm, destHostId)) { - logger.error("Vm not found on destination host. Unable to complete migration for " + vm); + s_logger.error("Vm not found on destination host. Unable to complete migration for " + vm); try { _agentMgr.send(srcHostId, new Commands(cleanup(vm.getInstanceName())), null); } catch (final AgentUnavailableException e) { - logger.error("AgentUnavailableException while cleanup on source host: " + srcHostId); + s_logger.error("AgentUnavailableException while cleanup on source host: " + srcHostId); } cleanup(vmGuru, new VirtualMachineProfileImpl(vm), work, Event.AgentReportStopped, true); throw new CloudRuntimeException("VM not found on desintation host. Unable to complete migration for " + vm); } } catch (final OperationTimedoutException e) { - logger.warn("Error while checking the vm " + vm + " is on host " + destHost, e); + s_logger.warn("Error while checking the vm " + vm + " is on host " + destHost, e); } migrated = true; } finally { if (!migrated) { - logger.info("Migration was unsuccessful. Cleaning up: " + vm); + s_logger.info("Migration was unsuccessful. Cleaning up: " + vm); _alertMgr.sendAlert(alertType, srcHost.getDataCenterId(), srcHost.getPodId(), "Unable to migrate vm " + vm.getInstanceName() + " from host " + srcHost.getName() + " in zone " + dc.getName() + " and pod " + dc.getName(), "Migrate Command failed. Please check logs."); @@ -2297,9 +2299,9 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac _agentMgr.send(destHostId, new Commands(cleanup(vm.getInstanceName())), null); stateTransitTo(vm, Event.OperationFailed, srcHostId); } catch (final AgentUnavailableException e) { - logger.warn("Looks like the destination Host is unavailable for cleanup.", e); + s_logger.warn("Looks like the destination Host is unavailable for cleanup.", e); } catch (final NoTransitionException e) { - logger.error("Error while transitioning vm from migrating to running state.", e); + s_logger.error("Error while transitioning vm from migrating to running state.", e); } } @@ -2323,7 +2325,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { final List<ItWorkVO> works = _workDao.listWorkInProgressFor(nodeId); for (final ItWorkVO work : works) { - logger.info("Handling unfinished work item: " + work); + s_logger.info("Handling unfinished work item: " + work); try { final VMInstanceVO vm = _vmDao.findById(work.getInstanceId()); if (vm != null) { @@ -2344,7 +2346,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } } } catch (final Exception e) { - logger.error("Error while handling " + work, e); + s_logger.error("Error while handling " + work, e); } } } finally { @@ -2369,7 +2371,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { orchestrateMigrateAway(vmUuid, srcHostId, null); } catch (final InsufficientServerCapacityException e) { - logger.warn("Failed to deploy vm " + vmUuid + " with original planner, sending HAPlanner"); + s_logger.warn("Failed to deploy vm " + vmUuid + " with original planner, sending HAPlanner"); orchestrateMigrateAway(vmUuid, srcHostId, _haMgr.getHAPlanner()); } } finally { @@ -2404,7 +2406,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac private void orchestrateMigrateAway(final String vmUuid, final long srcHostId, final DeploymentPlanner planner) throws InsufficientServerCapacityException { final VMInstanceVO vm = _vmDao.findByUuid(vmUuid); if (vm == null) { - logger.debug("Unable to find a VM for " + vmUuid); + s_logger.debug("Unable to find a VM for " + vmUuid); throw new CloudRuntimeException("Unable to find " + vmUuid); } @@ -2413,7 +2415,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final Long hostId = vm.getHostId(); if (hostId == null) { - logger.debug("Unable to migrate because the VM doesn't have a host id: " + vm); + s_logger.debug("Unable to migrate because the VM doesn't have a host id: " + vm); throw new CloudRuntimeException("Unable to migrate " + vmUuid); } @@ -2437,17 +2439,17 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { dest = _dpMgr.planDeployment(profile, plan, excludes, planner); } catch (final AffinityConflictException e2) { - logger.warn("Unable to create deployment, affinity rules associted to the VM conflict", e2); + s_logger.warn("Unable to create deployment, affinity rules associted to the VM conflict", e2); throw new CloudRuntimeException("Unable to create deployment, affinity rules associted to the VM conflict"); } if (dest != null) { - if (logger.isDebugEnabled()) { - logger.debug("Found destination " + dest + " for migrating to."); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Found destination " + dest + " for migrating to."); } } else { - if (logger.isDebugEnabled()) { - logger.debug("Unable to find destination for migrating the vm " + profile); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to find destination for migrating the vm " + profile); } throw new InsufficientServerCapacityException("Unable to find a server to migrate to.", host.getClusterId()); } @@ -2457,22 +2459,22 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac migrate(vm, srcHostId, dest); return; } catch (final ResourceUnavailableException e) { - logger.debug("Unable to migrate to unavailable " + dest); + s_logger.debug("Unable to migrate to unavailable " + dest); } catch (final ConcurrentOperationException e) { - logger.debug("Unable to migrate VM due to: " + e.getMessage()); + s_logger.debug("Unable to migrate VM due to: " + e.getMessage()); } try { advanceStop(vmUuid, true); throw new CloudRuntimeException("Unable to migrate " + vm); } catch (final ResourceUnavailableException e) { - logger.debug("Unable to stop VM due to " + e.getMessage()); + s_logger.debug("Unable to stop VM due to " + e.getMessage()); throw new CloudRuntimeException("Unable to migrate " + vm); } catch (final ConcurrentOperationException e) { - logger.debug("Unable to stop VM due to " + e.getMessage()); + s_logger.debug("Unable to stop VM due to " + e.getMessage()); throw new CloudRuntimeException("Unable to migrate " + vm); } catch (final OperationTimedoutException e) { - logger.debug("Unable to stop VM due to " + e.getMessage()); + s_logger.debug("Unable to stop VM due to " + e.getMessage()); throw new CloudRuntimeException("Unable to migrate " + vm); } } @@ -2481,7 +2483,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac protected class CleanupTask extends ManagedContextRunnable { @Override protected void runInContext() { - logger.trace("VM Operation Thread Running"); + s_logger.trace("VM Operation Thread Running"); try { _workDao.cleanup(VmOpCleanupWait.value()); @@ -2489,7 +2491,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final Date cutDate = new Date(new Date().getTime() - 3600000); _workJobDao.expungeCompletedWorkJobs(cutDate); } catch (final Exception e) { - logger.error("VM Operations failed due to ", e); + s_logger.error("VM Operations failed due to ", e); } } } @@ -2587,9 +2589,9 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac if (rebootAnswer != null && rebootAnswer.getResult()) { return; } - logger.info("Unable to reboot VM " + vm + " on " + dest.getHost() + " due to " + (rebootAnswer == null ? " no reboot answer" : rebootAnswer.getDetails())); + s_logger.info("Unable to reboot VM " + vm + " on " + dest.getHost() + " due to " + (rebootAnswer == null ? " no reboot answer" : rebootAnswer.getDetails())); } catch (final OperationTimedoutException e) { - logger.warn("Unable to send the reboot command to host " + dest.getHost() + " for the vm " + vm + " due to operation timeout", e); + s_logger.warn("Unable to send the reboot command to host " + dest.getHost() + " for the vm " + vm + " due to operation timeout", e); throw new CloudRuntimeException("Failed to reboot the vm on host " + dest.getHost()); } } @@ -2666,24 +2668,24 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac NoTransitionException, InsufficientAddressCapacityException { final VirtualMachineGuru vmGuru = getVmGuru(vm); - logger.debug("VM state is starting on full sync so updating it to running"); + s_logger.debug("VM state is starting on full sync so updating it to running"); vm = _vmDao.findById(vm.getId()); // grab outstanding work item if any final ItWorkVO work = _workDao.findByOutstandingWork(vm.getId(), vm.getState()); if (work != null) { - if (logger.isDebugEnabled()) { - logger.debug("Found an outstanding work item for this vm " + vm + " in state:" + vm.getState() + ", work id:" + work.getId()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Found an outstanding work item for this vm " + vm + " in state:" + vm.getState() + ", work id:" + work.getId()); } } try { stateTransitTo(vm, cause, hostId); } catch (final NoTransitionException e1) { - logger.warn(e1.getMessage()); + s_logger.warn(e1.getMessage()); } - logger.debug("VM's " + vm + " state is starting on full sync so updating it to Running"); + s_logger.debug("VM's " + vm + " state is starting on full sync so updating it to Running"); vm = _vmDao.findById(vm.getId()); // this should ensure vm has the most // up to date info @@ -2698,7 +2700,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } final Commands cmds = new Commands(Command.OnError.Stop); - logger.debug("Finalizing commands that need to be send to complete Start process for the vm " + vm); + s_logger.debug("Finalizing commands that need to be send to complete Start process for the vm " + vm); if (vmGuru.finalizeCommandsOnStart(cmds, profile)) { if (cmds.size() != 0) { @@ -2708,15 +2710,15 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac if (vmGuru.finalizeStart(profile, vm.getHostId(), cmds, null)) { stateTransitTo(vm, cause, vm.getHostId()); } else { - logger.error("Unable to finish finialization for running vm: " + vm); + s_logger.error("Unable to finish finialization for running vm: " + vm); } } else { - logger.error("Unable to finalize commands on start for vm: " + vm); + s_logger.error("Unable to finalize commands on start for vm: " + vm); } if (work != null) { - if (logger.isDebugEnabled()) { - logger.debug("Updating outstanding work item to Done, id:" + work.getId()); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Updating outstanding work item to Done, id:" + work.getId()); } work.setStep(Step.Done); _workDao.update(work.getId(), work); @@ -2787,14 +2789,14 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac return; } - if(logger.isDebugEnabled()) { - logger.debug("Received startup command from hypervisor host. host id: " + agent.getId()); + if(s_logger.isDebugEnabled()) { + s_logger.debug("Received startup command from hypervisor host. host id: " + agent.getId()); } _syncMgr.resetHostSyncState(agent.getId()); if (forRebalance) { - logger.debug("Not processing listener " + this + " as connect happens on rebalance process"); + s_logger.debug("Not processing listener " + this + " as connect happens on rebalance process"); return; } final Long clusterId = agent.getClusterId(); @@ -2805,9 +2807,9 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final ClusterVMMetaDataSyncCommand syncVMMetaDataCmd = new ClusterVMMetaDataSyncCommand(ClusterVMMetaDataSyncInterval.value(), clusterId); try { final long seq_no = _agentMgr.send(agentId, new Commands(syncVMMetaDataCmd), this); - logger.debug("Cluster VM metadata sync started with jobid " + seq_no); + s_logger.debug("Cluster VM metadata sync started with jobid " + seq_no); } catch (final AgentUnavailableException e) { - logger.fatal("The Cluster VM metadata sync process failed for cluster id " + clusterId + " with ", e); + s_logger.fatal("The Cluster VM metadata sync process failed for cluster id " + clusterId + " with ", e); } } } @@ -2817,12 +2819,12 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac protected void runInContext() { final GlobalLock lock = GlobalLock.getInternLock("TransitionChecking"); if (lock == null) { - logger.debug("Couldn't get the global lock"); + s_logger.debug("Couldn't get the global lock"); return; } if (!lock.lock(30)) { - logger.debug("Couldn't lock the db"); + s_logger.debug("Couldn't lock the db"); return; } try { @@ -2838,7 +2840,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } } } catch (final Exception e) { - logger.warn("Caught the following exception on transition checking", e); + s_logger.warn("Caught the following exception on transition checking", e); } finally { lock.unlock(); } @@ -2858,15 +2860,15 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac // Check that the VM is stopped / running if (!(vmInstance.getState().equals(State.Stopped) || vmInstance.getState().equals(State.Running))) { - logger.warn("Unable to upgrade virtual machine " + vmInstance.toString() + " in state " + vmInstance.getState()); + s_logger.warn("Unable to upgrade virtual machine " + vmInstance.toString() + " in state " + vmInstance.getState()); throw new InvalidParameterValueException("Unable to upgrade virtual machine " + vmInstance.toString() + " " + " in state " + vmInstance.getState() + "; make sure the virtual machine is stopped/running"); } // Check if the service offering being upgraded to is what the VM is already running with if (!newServiceOffering.isDynamic() && vmInstance.getServiceOfferingId() == newServiceOffering.getId()) { - if (logger.isInfoEnabled()) { - logger.info("Not upgrading vm " + vmInstance.toString() + " since it already has the requested " + "service offering (" + newServiceOffering.getName() + + if (s_logger.isInfoEnabled()) { + s_logger.info("Not upgrading vm " + vmInstance.toString() + " since it already has the requested " + "service offering (" + newServiceOffering.getName() + ")"); } @@ -2976,7 +2978,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac InsufficientCapacityException { final CallContext cctx = CallContext.current(); - logger.debug("Adding vm " + vm + " to network " + network + "; requested nic profile " + requested); + s_logger.debug("Adding vm " + vm + " to network " + network + "; requested nic profile " + requested); final VMInstanceVO vmVO = _vmDao.findById(vm.getId()); final ReservationContext context = new ReservationContextImpl(null, null, cctx.getCallingUser(), cctx.getCallingAccount()); @@ -2999,13 +3001,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final NicTO nicTO = toNicTO(nic, vmProfile.getVirtualMachine().getHypervisorType()); //4) plug the nic to the vm - logger.debug("Plugging nic for vm " + vm + " in network " + network); + s_logger.debug("Plugging nic for vm " + vm + " in network " + network); boolean result = false; try { result = plugNic(network, nicTO, vmTO, context, dest); if (result) { - logger.debug("Nic is plugged successfully for vm " + vm + " in network " + network + ". Vm is a part of network now"); + s_logger.debug("Nic is plugged successfully for vm " + vm + " in network " + network + ". Vm is a part of network now"); final long isDefault = nic.isDefaultNic() ? 1 : 0; // insert nic's Id into DB as resource_name if(VirtualMachine.Type.User.equals(vmVO.getType())) { @@ -3015,12 +3017,12 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } return nic; } else { - logger.warn("Failed to plug nic to the vm " + vm + " in network " + network); + s_logger.warn("Failed to plug nic to the vm " + vm + " in network " + network); return null; } } finally { if (!result) { - logger.debug("Removing nic " + nic + " from vm " + vmProfile.getVirtualMachine() + " as nic plug failed on the backend"); + s_logger.debug("Removing nic " + nic + " from vm " + vmProfile.getVirtualMachine() + " as nic plug failed on the backend"); _networkMgr.removeNic(vmProfile, _nicsDao.findById(nic.getId())); } } @@ -3028,7 +3030,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac //1) allocate nic return _networkMgr.createNicForVm(network, requested, context, vmProfile, false); } else { - logger.warn("Unable to add vm " + vm + " to network " + network); + s_logger.warn("Unable to add vm " + vm + " to network " + network); throw new ResourceUnavailableException("Unable to add vm " + vm + " to network, is not in the right state", DataCenter.class, vm.getDataCenterId()); } } @@ -3109,25 +3111,25 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac //1) Unplug the nic if (vm.getState() == State.Running) { final NicTO nicTO = toNicTO(nicProfile, vmProfile.getVirtualMachine().getHypervisorType()); - logger.debug("Un-plugging nic " + nic + " for vm " + vm + " from network " + network); + s_logger.debug("Un-plugging nic " + nic + " for vm " + vm + " from network " + network); final boolean result = unplugNic(network, nicTO, vmTO, context, dest); if (result) { - logger.debug("Nic is unplugged successfully for vm " + vm + " in network " + network); + s_logger.debug("Nic is unplugged successfully for vm " + vm + " in network " + network); final long isDefault = nic.isDefaultNic() ? 1 : 0; UsageEventUtils.publishUsageEvent(EventTypes.EVENT_NETWORK_OFFERING_REMOVE, vm.getAccountId(), vm.getDataCenterId(), vm.getId(), Long.toString(nic.getId()), network.getNetworkOfferingId(), null, isDefault, VirtualMachine.class.getName(), vm.getUuid(), vm.isDisplay()); } else { - logger.warn("Failed to unplug nic for the vm " + vm + " from network " + network); + s_logger.warn("Failed to unplug nic for the vm " + vm + " from network " + network); return false; } } else if (vm.getState() != State.Stopped) { - logger.warn("Unable to remove vm " + vm + " from network " + network); + s_logger.warn("Unable to remove vm " + vm + " from network " + network); throw new ResourceUnavailableException("Unable to remove vm " + vm + " from network, is not in the right state", DataCenter.class, vm.getDataCenterId()); } //2) Release the nic _networkMgr.releaseNic(vmProfile, nic); - logger.debug("Successfully released nic " + nic + "for vm " + vm); + s_logger.debug("Successfully released nic " + nic + "for vm " + vm); //3) Remove the nic _networkMgr.removeNic(vmProfile, nic); @@ -3164,13 +3166,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } if (nic == null) { - logger.warn("Could not get a nic with " + network); + s_logger.warn("Could not get a nic with " + network); return false; } // don't delete default NIC on a user VM if (nic.isDefaultNic() && vm.getType() == VirtualMachine.Type.User) { - logger.warn("Failed to remove nic from " + vm + " in " + network + ", nic is default."); + s_logger.warn("Failed to remove nic from " + vm + " in " + network + ", nic is default."); throw new CloudRuntimeException("Failed to remove nic from " + vm + " in " + network + ", nic is default."); } @@ -3179,16 +3181,16 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac if (lock == null) { //check if nic is still there. Return if it was released already if (_nicsDao.findById(nic.getId()) == null) { - if (logger.isDebugEnabled()) { - logger.debug("Not need to remove the vm " + vm + " from network " + network + " as the vm doesn't have nic in this network"); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Not need to remove the vm " + vm + " from network " + network + " as the vm doesn't have nic in this network"); } return true; } throw new ConcurrentOperationException("Unable to lock nic " + nic.getId()); } - if (logger.isDebugEnabled()) { - logger.debug("Lock is acquired for nic id " + lock.getId() + " as a part of remove vm " + vm + " from network " + network); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Lock is acquired for nic id " + lock.getId() + " as a part of remove vm " + vm + " from network " + network); } try { @@ -3199,22 +3201,22 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac //1) Unplug the nic if (vm.getState() == State.Running) { final NicTO nicTO = toNicTO(nicProfile, vmProfile.getVirtualMachine().getHypervisorType()); - logger.debug("Un-plugging nic for vm " + vm + " from network " + network); + s_logger.debug("Un-plugging nic for vm " + vm + " from network " + network); final boolean result = unplugNic(network, nicTO, vmTO, context, dest); if (result) { - logger.debug("Nic is unplugged successfully for vm " + vm + " in network " + network); + s_logger.debug("Nic is unplugged successfully for vm " + vm + " in network " + network); } else { - logger.warn("Failed to unplug nic for the vm " + vm + " from network " + network); + s_logger.warn("Failed to unplug nic for the vm " + vm + " from network " + network); return false; } } else if (vm.getState() != State.Stopped) { - logger.warn("Unable to remove vm " + vm + " from network " + network); + s_logger.warn("Unable to remove vm " + vm + " from network " + network); throw new ResourceUnavailableException("Unable to remove vm " + vm + " from network, is not in the right state", DataCenter.class, vm.getDataCenterId()); } //2) Release the nic _networkMgr.releaseNic(vmProfile, nic); - logger.debug("Successfully released nic " + nic + "for vm " + vm); + s_logger.debug("Successfully released nic " + nic + "for vm " + vm); //3) Remove the nic _networkMgr.removeNic(vmProfile, nic); @@ -3222,8 +3224,8 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac } finally { if (lock != null) { _nicsDao.releaseFromLockTable(lock.getId()); - if (logger.isDebugEnabled()) { - logger.debug("Lock is released for nic id " + lock.getId() + " as a part of remove vm " + vm + " from network " + network); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Lock is released for nic id " + lock.getId() + " as a part of remove vm " + vm + " from network " + network); } } } @@ -3255,13 +3257,13 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { dest = _dpMgr.planDeployment(profile, plan, excludes, null); } catch (final AffinityConflictException e2) { - logger.warn("Unable to create deployment, affinity rules associted to the VM conflict", e2); + s_logger.warn("Unable to create deployment, affinity rules associted to the VM conflict", e2); throw new CloudRuntimeException("Unable to create deployment, affinity rules associted to the VM conflict"); } if (dest != null) { - if (logger.isDebugEnabled()) { - logger.debug(" Found " + dest + " for scaling the vm to."); + if (s_logger.isDebugEnabled()) { + s_logger.debug(" Found " + dest + " for scaling the vm to."); } } @@ -3273,10 +3275,10 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac try { migrateForScale(vm.getUuid(), srcHostId, dest, oldSvcOfferingId); } catch (final ResourceUnavailableException e) { - logger.debug("Unable to migrate to unavailable " + dest); + s_logger.debug("Unable to migrate to unavailable " + dest); throw e; } catch (final ConcurrentOperationException e) { - logger.debug("Unable to migrate VM due to: " + e.getMessage()); + s_logger.debug("Unable to migrate VM due to: " + e.getMessage()); throw e; } } @@ -3327,18 +3329,18 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac throws ResourceUnavailableException, ConcurrentOperationException { VMInstanceVO vm = _vmDao.findByUuid(vmUuid); - logger.info("Migrating " + vm + " to " + dest); + s_logger.info("Migrating " + vm + " to " + dest); vm.getServiceOfferingId(); final long dstHostId = dest.getHost().getId(); final Host fromHost = _hostDao.findById(srcHostId); if (fromHost == null) { - logger.info("Unable to find the host to migrate from: " + srcHostId); + s_logger.info("Unable to find the host to migrate from: " + srcHostId); throw new CloudRuntimeException("Unable to find the host to migrate from: " + srcHostId); } if (fromHost.getClusterId().longValue() != dest.getCluster().getId()) { - logger.info("Source and destination host are not in same cluster, unable to migrate to host: " + dest.getHost().getId()); + s_logger.info("Source and destination host are not in same cluster, unable to migrate to host: " + dest.getHost().getId()); throw new CloudRuntimeException("Source and destination host are not in same cluster, unable to migrate to host: " + dest.getHost().getId()); } @@ -3347,15 +3349,15 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac final long vmId = vm.getId(); vm = _vmDao.findByUuid(vmUuid); if (vm == null) { - if (logger.isDebugEnabled()) { - logger.debug("Unable to find the vm " + vm); + if (s_logger.isDebugEnabled()) { + s_logger.debug("Unable to find the vm " + vm); } throw new CloudRuntimeException("Unable to find a virtual machine with id " + vmId); } if (vm.getState() != State.Ru
<TRUNCATED>
