[
https://issues.apache.org/jira/browse/CLOUDSTACK-5016?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sailaja Mada reopened CLOUDSTACK-5016:
--------------------------------------
I tried duplicating the bug today.
1) I have a setup with Cluster and Zone wide primary storages .
2) My VM used to run on a Cluster wide Storage . This vm has VM snapshots
and reverted VM operations done on this
3) I have moved all the cluster storages into Maintanence mode . With This
this VM got into down state
4) I have released all the storages into UP state.
5) Now when I tried to start the VM , I got into this reported failure.
>From SSVM log, it says it is failing to locate the snapshot.
Details :
2013-11-12 03:43:10,832 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Processing command: com.cloud.agent.api.GetStorageStatsCommand
2013-11-12 03:43:11,063 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Request:Seq 14-2021721154: { Cmd , MgmtId: 94838926819810, via: 14, Ver: v1,
Flags: 100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cc6e4cfd-7210-492a-bafa-c3d3f548e513","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"60089df3-f0b9-3f8e-9f2a-dc095c46d477","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/dixonps1","port":2049}},"name":"ROOT-21","size":2147483648,"path":"ROOT-21-000005","volumeId":32,"vmName":"i-3-21-VM","accountId":3,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21-000005.vmdk\",\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21.vmdk\"]}","format":"OVA","id":32,"hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cc6e4cfd-7210-492a-bafa-c3d3f548e513","volumeType":"ROOT","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.102.192.100/cpg_vol/sailaja/dixonss1","_role":"Image"}},"name":"ROOT-21","size":2147483648,"path":"volumes/3/32","volumeId":32,"vmName":"i-3-21-VM","accountId":3,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21-000005.vmdk\",\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21.vmdk\"]}","format":"OVA","id":32,"hypervisorType":"VMware"}},"executeInSequence":true,"wait":10800}}]
}
2013-11-12 03:43:11,067 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Processing command: org.apache.cloudstack.storage.command.CopyCommand
2013-11-12 03:43:11,067 INFO
[storage.resource.VmwareSecondaryStorageResourceHandler]
(agentRequest-Handler-5:null) Open new VmwareContext. vCenter: 10.102.192.248,
user: administrator, password: v********
2013-11-12 03:43:11,244 INFO
[storage.resource.VmwareSecondaryStorageResourceHandler]
(agentRequest-Handler-5:null) Setup firewall rule for host: 10.102.192.18
2013-11-12 03:43:11,291 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null)
find VM i-3-21-VM on host
2013-11-12 03:43:11,294 INFO [vmware.mo.HostMO] (agentRequest-Handler-5:null)
VM i-3-21-VM not found in host cache
2013-11-12 03:43:11,294 DEBUG [vmware.mo.HostMO] (agentRequest-Handler-5:null)
load VM cache on host
2013-11-12 03:43:12,600 WARN [vmware.mo.VirtualMachineMO]
(agentRequest-Handler-5:null) Unable to find snapshot:
a4dae82b808343a9b8643b4a3e75bbd4
2013-11-12 03:43:12,601 ERROR [storage.resource.VmwareStorageProcessor]
(agentRequest-Handler-5:null) Unable to execute CopyVolumeCommand due to
exception
java.lang.RuntimeException: File [60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/i-3-21-VM.vmx was not found
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:411)
at
com.cloud.hypervisor.vmware.mo.VirtualMachineMO.createSnapshot(VirtualMachineMO.java:394)
at
com.cloud.storage.resource.VmwareStorageProcessor.copyVolumeToSecStorage(VmwareStorageProcessor.java:543)
at
com.cloud.storage.resource.VmwareStorageProcessor.copyVolumeFromPrimaryToSecondary(VmwareStorageProcessor.java:573)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:79)
at
com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:155)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49)
at
com.cloud.storage.resource.VmwareSecondaryStorageResourceHandler.executeRequest(VmwareSecondaryStorageResourceHandler.java:99)
at
com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(PremiumSecondaryStorageResource.java:56)
at com.cloud.agent.Agent.processRequest(Agent.java:525)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
at com.cloud.utils.nio.Task.run(Task.java:83)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-11-12 03:43:12,608 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Seq 14-2021721154: { Ans: , MgmtId: 94838926819810, via: 14, Ver: v1, Flags:
110,
[{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"copy
volume from primary to secondary failed due to exception: Exception:
java.lang.RuntimeException\nMessage: File [60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/i-3-21-VM.vmx was not found\n","wait":0}}] }
2013-11-12 03:43:12,704 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Request:Seq 14-2021721155: { Cmd , MgmtId: 94838926819810, via: 14, Ver: v1,
Flags: 100011,
[{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cc6e4cfd-7210-492a-bafa-c3d3f548e513","volumeType":"ROOT","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.102.192.100/cpg_vol/sailaja/dixonss1","_role":"Image"}},"name":"ROOT-21","size":2147483648,"volumeId":32,"vmName":"i-3-21-VM","accountId":3,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21-000005.vmdk\",\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21.vmdk\"]}","format":"OVA","id":32,"hypervisorType":"VMware"}},"wait":0}}]
}
2013-11-12 03:43:12,704 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Processing command: org.apache.cloudstack.storage.command.DeleteCommand
2013-11-12 03:43:12,716 WARN [cloud.agent.Agent] (agentRequest-Handler-2:null)
Caught:
java.lang.NullPointerException
at
org.apache.cloudstack.storage.resource.NfsSecondaryStorageResource.deleteVolume(NfsSecondaryStorageResource.java:1793)
at
org.apache.cloudstack.storage.resource.NfsSecondaryStorageResource.execute(NfsSecondaryStorageResource.java:1678)
at
org.apache.cloudstack.storage.resource.NfsSecondaryStorageResource.executeRequest(NfsSecondaryStorageResource.java:203)
at
com.cloud.storage.resource.PremiumSecondaryStorageResource.defaultAction(PremiumSecondaryStorageResource.java:63)
at
com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(PremiumSecondaryStorageResource.java:59)
at com.cloud.agent.Agent.processRequest(Agent.java:525)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
at com.cloud.utils.nio.Task.run(Task.java:83)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
2013-11-12 03:43:12,717 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Seq 14-2021721155: { Ans: , MgmtId: 94838926819810, via: 14, Ver: v1, Flags:
10,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
org.apache.cloudstack.storage.resource.NfsSecondaryStorageResource.deleteVolume(NfsSecondaryStorageResource.java:1793)\n\tat
org.apache.cloudstack.storage.resource.NfsSecondaryStorageResource.execute(NfsSecondaryStorageResource.java:1678)\n\tat
org.apache.cloudstack.storage.resource.NfsSecondaryStorageResource.executeRequest(NfsSecondaryStorageResource.java:203)\n\tat
com.cloud.storage.resource.PremiumSecondaryStorageResource.defaultAction(PremiumSecondaryStorageResource.java:63)\n\tat
com.cloud.storage.resource.PremiumSecondaryStorageResource.executeRequest(PremiumSecondaryStorageResource.java:59)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-11-12 03:44:09,607 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 14-1090: { Cmd , MgmtId: -1, via: 14, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.PingStorageCommand":{"changes":{},"hostType":"Storage","hostId":14,"wait":0}}]
}
2013-11-12 03:44:09,650 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null)
Received response: Seq 14-1090: { Ans: , MgmtId: 94838926819810, via: 14, Ver:
v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Storage","hostId":14,"wait":0},"result":true,"wait":0}}]
}
2013-11-12 03:44:11,540 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Processing command: com.cloud.agent.api.GetStorageStatsCommand
MS log:
2013-11-12 09:54:24,736 WARN [vmware.resource.VmwareResource]
(DirectAgent-72:10.102.192.18) StartCommand failed due to Exception:
java.lang.RuntimeException
Message: File [] /bd281808180e4b339bca6d078e277f77-000005.vmdk was not found
java.lang.RuntimeException: File []
/bd281808180e4b339bca6d078e277f77-000005.vmdk was not found
at
com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:411)
at
com.cloud.hypervisor.vmware.mo.VirtualMachineMO.powerOn(VirtualMachineMO.java:188)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.execute(VmwareResource.java:2981)
at
com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:513)
at
com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-11-12 09:54:24,764 DEBUG [agent.manager.DirectAgentAttache]
(DirectAgent-72:null) Seq 10-102188132: Response Received:
2013-11-12 09:54:24,765 DEBUG [agent.transport.Request] (DirectAgent-72:null)
Seq 10-102188132: Processing: { Ans: , MgmtId: 94838926819810, via: 10, Ver:
v1, Flags: 110,
[{"com.cloud.agent.api.StartAnswer":{"vm":{"id":21,"name":"i-3-21-VM","bootloader":"HVM","type":"User","cpus":1,"minSpeed":500,"maxSpeed":500,"minRam":536870912,"maxRam":536870912,"hostName":"zone51in1","arch":"x86_64","os":"CentOS
5.3
(64-bit)","bootArgs":"","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"enableDynamicallyScaleVm":false,"vncPassword":"99314110a23f70e4","params":{"nicAdapter":"E1000","vmware.reserve.cpu":"false","nestedVirtualizationFlag":"false","Message.ReservedCapacityFreed.Flag":"true","rootDiskController":"ide","vmware.reserve.mem":"false"},"uuid":"b727c61a-2b4f-40ae-a507-57470af93b0c","disks":[{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"cc6e4cfd-7210-492a-bafa-c3d3f548e513","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"60089df3-f0b9-3f8e-9f2a-dc095c46d477","id":2,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/dixonps1","port":2049}},"name":"ROOT-21","size":2147483648,"path":"ROOT-21-000005","volumeId":32,"vmName":"i-3-21-VM","accountId":3,"chainInfo":"{\"diskDeviceBusName\":\"ide0:1\",\"diskChain\":[\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21-000005.vmdk\",\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/ROOT-21.vmdk\"]}","format":"OVA","id":32,"hypervisorType":"VMware"}},"diskSeq":0,"type":"ROOT"},{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"e2672196-dd84-497b-863a-a59e93bad1d6","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"a8324a75-7a36-35f9-abb3-7c497ebc443d","id":3,"poolType":"NetworkFilesystem","host":"10.102.192.100","path":"/cpg_vol/sailaja/dixonnewps2","port":2049}},"name":"DATA-21","size":5368709120,"path":"bd281808180e4b339bca6d078e277f77-000005","volumeId":35,"vmName":"i-3-21-VM","accountId":3,"chainInfo":"{\"diskDeviceBusName\":\"scsi0:0\",\"diskChain\":[\"[60089df3f0b93f8e9f2adc095c46d477]
i-3-21-VM/bd281808180e4b339bca6d078e277f77-000005.vmdk\"]}","format":"OVA","id":35,"hypervisorType":"VMware"}},"diskSeq":1,"type":"DATADISK"},{"data":{"org.apache.cloudstack.storage.to.TemplateObjectTO":{"id":0,"format":"ISO","accountId":0,"hvm":false}},"diskSeq":3,"type":"ISO"}],"nics":[{"deviceId":0,"networkRateMbps":200,"defaultNic":true,"uuid":"baf982f8-1b25-4c70-879a-177049bcb497","ip":"10.1.1.101","netmask":"255.255.255.0","gateway":"10.1.1.1","mac":"02:00:6e:d2:00:01","dns1":"10.103.128.15","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://797","isolationUri":"vlan://797","isSecurityGroupEnabled":false}]},"result":false,"details":"StartCommand
failed due to Exception: java.lang.RuntimeException\nMessage: File []
/bd281808180e4b339bca6d078e277f77-000005.vmdk was not found\n","wait":0}}] }
2013-11-12 09:54:24,765 DEBUG [agent.transport.Request]
(Job-Executor-90:job-171 = [ 9df4dd8c-b136-4029-a9d7-95bac09b004c ]) Seq
10-102188132: Received: { Ans: , MgmtId: 94838926819810, via: 10, Ver: v1,
Flags: 110, { StartAnswer } }
2013-11-12 09:54:33,199 INFO [storage.volume.VolumeServiceImpl]
(Job-Executor-90:job-171 = [ 9df4dd8c-b136-4029-a9d7-95bac09b004c ]) Volume 62
is not referred anywhere, remove it from volumes table
2013-11-12 09:54:33,218 ERROR [cloud.storage.VolumeManagerImpl]
(Job-Executor-90:job-171 = [ 9df4dd8c-b136-4029-a9d7-95bac09b004c ]) migrate
volume failed:copy volume from primary to secondary failed due to exception:
Exception: java.lang.RuntimeException
Message: File [60089df3f0b93f8e9f2adc095c46d477] i-3-21-VM/i-3-21-VM.vmx was
not found
2013-11-12 09:54:33,223 INFO [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-90:job-171 = [ 9df4dd8c-b136-4029-a9d7-95bac09b004c ]) Unable to
contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:6] is
unreachable: migrate volume failed: copy volume from primary to secondary
failed due to exception: Exception: java.lang.RuntimeException
Message: File [60089df3f0b93f8e9f2adc095c46d477] i-3-21-VM/i-3-21-VM.vmx was
not found
at
com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2278)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2629)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
at
org.apache.cloudstack.engine.cloud.entity.api.VMEntityManagerImpl.deployVirtualMachine(VMEntityManagerImpl.java:237)
at
org.apache.cloudstack.engine.cloud.entity.api.VirtualMachineEntityImpl.deploy(VirtualMachineEntityImpl.java:209)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:3440)
at
com.cloud.vm.UserVmManagerImpl.startVirtualMachine(UserVmManagerImpl.java:1959)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vm.StartVMCmd.execute(StartVMCmd.java:120)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
at
com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
2013-11-12 09:54:33,267 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(Job-Executor-90:job-171 = [ 9df4dd8c-b136-4029-a9d7-95bac09b004c ]) Cleaning
up resources for the vm VM[User|zone51in1] in Starting state
> Failed to reboot the VM which has VM Snapshots and Migrated Volumes
> -------------------------------------------------------------------
>
> Key: CLOUDSTACK-5016
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-5016
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Storage Controller, VMware
> Affects Versions: 4.2.1
> Reporter: Sailaja Mada
> Assignee: Likitha Shetty
> Priority: Critical
> Fix For: 4.2.1
>
> Attachments: logsall.rar, startvm.png
>
>
> Steps:
> 1. Configure Adv Zone with 2 zone wide primary storages using VMWARE 5.0
> update2 Hypervisor
> 2. Deploy VM using user account
> 3. Create 2 VMsnapshots wo memory and 1 VM snapshot with Memory
> 4. Revert to VM Snap2 then to VM Snap1
> 5. Stop the VM and Migrate the Volume to second Primary Storage
> 7. Start the VM - It got started.
> 8. Tried to reboot the VM.
> Observation:
> It failed to start the VM .
> 2013-10-31 20:17:28,495 WARN [storage.resource.VmwareStorageLayoutHelper]
> (DirectAgent-289:10.102.192.18) Unable to locate VMDK file:
> a933eb3fa28a473ab5e28b99f5f2607e-delta.vmdk
> 2013-10-31 20:17:28,496 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-289:null) Seq 9-894174187: Response Received:
> 2013-10-31 20:17:28,497 DEBUG [agent.transport.Request]
> (DirectAgent-289:null) Seq 9-894174187: Processing: { Ans: , MgmtId:
> 94838926819810, via: 9, Ver: v1, Flags: 10,
> [{"com.cloud.agent.api.Answer":{"result":true,"details":"Success","wait":0}}]
> }
> 2013-10-31 20:17:28,497 DEBUG [agent.transport.Request]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Seq
> 9-894174187: Received: { Ans: , MgmtId: 94838926819810, via: 9, Ver: v1,
> Flags: 10, { Answer } }
> 2013-10-31 20:17:28,507 INFO [storage.volume.VolumeServiceImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Volume 39
> is not referred anywhere, remove it from volumes table
> 2013-10-31 20:17:28,513 ERROR [cloud.storage.VolumeManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) migrate
> volume failed:copy volume from primary to secondary failed due to exception:
> Exception: java.lang.RuntimeException
> Message: File [7f18caf5397a340a934ed37c558aee2b] i-5-24-VM/i-5-24-VM.vmx was
> not found
> 2013-10-31 20:17:28,519 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Unable to
> contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:5] is
> unreachable: migrate volume failed: copy volume from primary to secondary
> failed due to exception: Exception: java.lang.RuntimeException
> Message: File [7f18caf5397a340a934ed37c558aee2b] i-5-24-VM/i-5-24-VM.vmx was
> not found
> 2013-10-31 20:17:28,519 INFO [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Unable to
> contact resource.
> com.cloud.exception.StorageUnavailableException: Resource [StoragePool:5] is
> unreachable: migrate volume failed: copy volume from primary to secondary
> failed due to exception: Exception: java.lang.RuntimeException
> Message: File [7f18caf5397a340a934ed37c558aee2b] i-5-24-VM/i-5-24-VM.vmx was
> not found
> at
> com.cloud.storage.VolumeManagerImpl.migrateVolume(VolumeManagerImpl.java:2278)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2629)
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:888)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:570)
> at
> com.cloud.vm.UserVmManagerImpl.restoreVMInternal(UserVmManagerImpl.java:4930)
> at
> com.cloud.vm.UserVmManagerImpl.rebootVirtualMachine(UserVmManagerImpl.java:1971)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.RebootVMCmd.execute(RebootVMCmd.java:99)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2013-10-31 20:17:28,547 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Cleaning
> up resources for the vm VM[User|sailajaVM1] in Starting state
> 2013-10-31 20:17:28,549 DEBUG [agent.transport.Request]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Seq
> 9-894174188: Sending { Cmd , MgmtId: 94838926819810, via: 9, Ver: v1, Flags:
> 100111,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-5-24-VM","wait":0}}]
> }
> 2013-10-31 20:17:28,549 DEBUG [agent.transport.Request]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Seq
> 9-894174188: Executing: { Cmd , MgmtId: 94838926819810, via: 9, Ver: v1,
> Flags: 100111,
> [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":true,"vmName":"i-5-24-VM","wait":0}}]
> }
> 2013-10-31 20:17:28,853 DEBUG [cloud.capacity.CapacityManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) release
> mem from host: 9, old used: 2013265920,reserved: 0, total: 17166258176; new
> used: 1476395008,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-10-31 20:17:28,881 DEBUG [cloud.vm.UserVmManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Unable to
> start VM 1ec83c40-e0dc-48ad-90d8-f4000c0dfe91
> com.cloud.exception.InsufficientServerCapacityException: Unable to create a
> deployment for VM[User|sailajaVM1]Scope=interface com.cloud.dc.DataCenter;
> id=4
> at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:841)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:577)
> at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:570)
> at
> com.cloud.vm.UserVmManagerImpl.restoreVMInternal(UserVmManagerImpl.java:4930)
> at
> com.cloud.vm.UserVmManagerImpl.rebootVirtualMachine(UserVmManagerImpl.java:1971)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.RebootVMCmd.execute(RebootVMCmd.java:99)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2013-10-31 20:17:28,889 ERROR [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ])
> Unexpected exception while executing
> org.apache.cloudstack.api.command.user.vm.RebootVMCmd
> com.cloud.utils.exception.CloudRuntimeException: Unable to start VM with
> specified idUnable to create a deployment for VM[User|sailajaVM1]
> at
> com.cloud.vm.UserVmManagerImpl.restoreVMInternal(UserVmManagerImpl.java:4933)
> at
> com.cloud.vm.UserVmManagerImpl.rebootVirtualMachine(UserVmManagerImpl.java:1971)
> at
> com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at
> org.apache.cloudstack.api.command.user.vm.RebootVMCmd.execute(RebootVMCmd.java:99)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at
> com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:531)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> at java.lang.Thread.run(Thread.java:679)
> 2013-10-31 20:17:28,891 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-5:job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ]) Complete
> async job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038 ], jobStatus: 2,
> resultCode: 530, result: Error Code: 530 Error text: Unable to start VM with
> specified idUnable to create a deployment for VM[User|sailajaVM1]
> 2013-10-31 20:17:30,404 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null)
> ===START=== 10.104.255.45 -- GET
> command=queryAsyncJobResult&jobId=57e484cb-c0aa-47c8-b991-1aa7aed9b038&response=json&sessionkey=CHP8%2Bg6QICbqOnSaFI0Tkhq5ngs%3D&_=1383231183604
> 2013-10-31 20:17:30,417 DEBUG [cloud.async.AsyncJobManagerImpl]
> (catalina-exec-2:null) Async job-143 = [ 57e484cb-c0aa-47c8-b991-1aa7aed9b038
> ] completed
> 2013-10-31 20:17:28,549 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-228:null) Seq 9-894174188: Executing request
> 2013-10-31 20:17:28,549 INFO [vmware.resource.VmwareResource]
> (DirectAgent-228:10.102.192.18) Executing resource StopCommand:
> {"isProxy":false,"executeInSequence":true,"vmName":"i-5-24-VM","wait":0}
--
This message was sent by Atlassian JIRA
(v6.1#6144)
