Hi,
I am working on CloudStack infrastructure service to build our organization
framework.For this purpose, RHEL 6.4, Cloudstack 4.2.1 and KVM are being used.
I have been working around for long to figure out the below mentioned Issue but
unfortunately could not.
Issue: Snapshot gets stuck in the state "Creating" forever(Screenshot attached).
Impact: Couldn't get the snapshot consequently and thus, the instance from the
CloudStack's UI could not be started/Stopped.
Please see below trace from Management Server log which I think is the reason
behind (full log attached).
Unexpected exception while executing
org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmdcom.cloud.utils.exception.CloudRuntimeException:
com.cloud.agent.api.UnsupportedAnswer cannot be cast to
com.cloud.agent.api.CreateVMSnapshotAnswer
Please see below trace from agent log which was written at the moment I clicked
on Snapshot button in the Cloudstack's UI:
2014-02-25 17:27:09,129 WARN [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Unsupported command
In order to restart the instance again, I manually delete the row from the
table vm_snapshots in mysql database corresponding to this stuck snapshot.
Please suggest me the fix with proper explanation for this issue.
Thanks in advance.
Regards,Rohit
me":"ROOT-13","path":"ec5692cb-7758-4618-b589-09cb71e45dba","size":21474836480,"type":"ROOT","storagePoolType":"NetworkFilesystem","storagePoolUuid":"d41d4103-a11d-3160-8a3b-6469c574a93f","deviceId":0},{"id":19,"name":"DATA-13","path":"8017ac65-b52b-450b-937f-d92178de2f34","size":21474836480,"type":"DATADISK","storagePoolType":"NetworkFilesystem","storagePoolUuid":"d41d4103-a11d-3160-8a3b-6469c574a93f","deviceId":1}],"target":{"id":13,"snapshotName":"i-2-13-VM_VS_20140225120244","type":"Disk","current":false,"description":"new"},"vmName":"i-2-13-VM","guestOSType":"Red
Hat Enterprise Linux 6.4 (64-bit)","wait":1800}}] }
2014-02-25 17:32:45,254 DEBUG [agent.transport.Request]
(AgentManager-Handler-11:null) Seq 1-2016739514: Processing: { Ans: , MgmtId:
181122461670954, via: 1, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.UnsupportedAnswer":{"result":false,"details":"Unsupported
command issued:com.cloud.agent.api.CreateVMSnapshotCommand. Are you sure you
got the right type of server?","wait":0}}] }
2014-02-25 17:32:45,254 DEBUG [agent.transport.Request] (Job-Executor-2:job-143
= [ 8ebc7ede-829d-473b-b909-a397f4c83490 ]) Seq 1-2016739514: Received: { Ans:
, MgmtId: 181122461670954, via: 1, Ver: v1, Flags: 10, { UnsupportedAnswer } }
2014-02-25 17:32:45,254 WARN [agent.manager.AgentManagerImpl]
(Job-Executor-2:job-143 = [ 8ebc7ede-829d-473b-b909-a397f4c83490 ]) Unsupported
Command: Unsupported command
issued:com.cloud.agent.api.CreateVMSnapshotCommand. Are you sure you got the
right type of server?
2014-02-25 17:32:45,254 ERROR [vm.snapshot.VMSnapshotManagerImpl]
(Job-Executor-2:job-143 = [ 8ebc7ede-829d-473b-b909-a397f4c83490 ]) Create vm
snapshot i-2-13-VM_VS_20140225120244 failed for vm: i-2-13-VM due to
com.cloud.agent.api.UnsupportedAnswer cannot be cast to
com.cloud.agent.api.CreateVMSnapshotAnswer
2014-02-25 17:32:45,265 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null)
===START=== 192.168.125.241 -- GET
command=listOsTypes&response=json&sessionkey=bP1MluiO7KMYb3krOwtD1IpG0b0%3D&_=1393329472271
2014-02-25 17:32:45,324 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null)
===START=== 192.168.125.241 -- GET
command=listTags&response=json&sessionkey=bP1MluiO7KMYb3krOwtD1IpG0b0%3D&resourceId=340c69ae-f3a0-4966-aa0b-c799e944404f&resourceType=UserVm&listAll=true&_=1393329472305
2014-02-25 17:32:45,330 DEBUG [cloud.api.ApiServlet] (catalina-exec-13:null)
===END=== 192.168.125.241 -- GET
command=listTags&response=json&sessionkey=bP1MluiO7KMYb3krOwtD1IpG0b0%3D&resourceId=340c69ae-f3a0-4966-aa0b-c799e944404f&resourceType=UserVm&listAll=true&_=1393329472305
2014-02-25 17:32:45,373 DEBUG [cloud.api.ApiServlet] (catalina-exec-11:null)
===END=== 192.168.125.241 -- GET
command=listOsTypes&response=json&sessionkey=bP1MluiO7KMYb3krOwtD1IpG0b0%3D&_=1393329472271
2014-02-25 17:32:45,419 ERROR [cloud.async.AsyncJobManagerImpl]
(Job-Executor-2:job-143 = [ 8ebc7ede-829d-473b-b909-a397f4c83490 ]) Unexpected
exception while executing
org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd
com.cloud.utils.exception.CloudRuntimeException:
com.cloud.agent.api.UnsupportedAnswer cannot be cast to
com.cloud.agent.api.CreateVMSnapshotAnswer
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.createVmSnapshotInternal(VMSnapshotManagerImpl.java:406)
at
com.cloud.vm.snapshot.VMSnapshotManagerImpl.creatVMSnapshot(VMSnapshotManagerImpl.java:356)
at
com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
at
org.apache.cloudstack.api.command.user.vmsnapshot.CreateVMSnapshotCmd.execute(CreateVMSnapshotCmd.java:100)
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:722)
2014-02-25 17:32:45,420 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-2:job-143 = [ 8ebc7ede-829d-473b-b909-a397f4c83490 ]) Complete
async job-143 = [ 8ebc7ede-829d-473b-b909-a397f4c83490 ], jobStatus: 2,
resultCode: 530, result: Error Code: 530 Error text:
com.cloud.agent.api.UnsupportedAnswer cannot be cast to
com.cloud.agent.api.CreateVMSnapshotAnswer
2014-02-25 17:32:50,526 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
(secstorage-1:null) Zone 1 is ready to launch secondary storage VM
2014-02-25 17:32:50,626 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is ready to launch console proxy
2014-02-25 17:32:50,760 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-14:null) SeqA 3-1596: Processing Seq 3-1596: { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2014-02-25 17:32:50,835 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-14:null) SeqA 3-1596: Sending Seq 3-1596: { Ans: ,
MgmtId: 181122461670954, via: 3, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-02-25 17:32:51,461 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers to update status.
2014-02-25 17:32:51,462 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2014-02-25 17:32:54,001 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-13:null) Ping from 3
2014-02-25 17:32:54,082 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-12:null) Ping from 2
2014-02-25 17:32:54,340 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-15:null) Ping from 1
2014-02-25 17:32:55,800 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-2:null) SeqA 3-1598: Processing Seq 3-1598: { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2014-02-25 17:32:55,945 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-2:null) SeqA 3-1598: Sending Seq 3-1598: { Ans: ,
MgmtId: 181122461670954, via: 3, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-02-25 17:33:05,762 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-1:null) SeqA 3-1599: Processing Seq 3-1599: { Cmd ,
MgmtId: -1, via: 3, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.ConsoleProxyLoadReportCommand":{"_proxyVmId":2,"_loadInfo":"{\n
\"connections\": []\n}","wait":0}}] }
2014-02-25 17:33:05,847 DEBUG [agent.manager.AgentManagerImpl]
(AgentManager-Handler-1:null) SeqA 3-1599: Sending Seq 3-1599: { Ans: ,
MgmtId: 181122461670954, via: 3, Ver: v1, Flags: 100010,
[{"com.cloud.agent.api.AgentControlAnswer":{"result":true,"wait":0}}] }
2014-02-25 17:33:12,091 DEBUG [cloud.server.StatsCollector]
(StatsCollector-1:null) VmStatsCollector is running...
2014-02-25 17:33:12,185 DEBUG [agent.transport.Request] (StatsCollector-1:null)
Seq 1-2016739515: Received: { Ans: , MgmtId: 181122461670954, via: 1, Ver: v1,
Flags: 10, { GetVmStatsAnswer } }
2014-02-25 17:33:13,400 DEBUG [cloud.server.StatsCollector]
(StatsCollector-2:null) StorageCollector is running...
2014-02-25 17:33:13,460 DEBUG [agent.transport.Request] (StatsCollector-2:null)
Seq 2-1323958339: Received: { Ans: , MgmtId: 181122461670954, via: 2, Ver: v1,
Flags: 10, { GetStorageStatsAnswer } }
2014-02-25 17:33:13,500 DEBUG [agent.transport.Request] (StatsCollector-2:null)
Seq 1-2016739516: Received: { Ans: , MgmtId: 181122461670954, via: 1, Ver: v1,
Flags: 10, { GetStorageStatsAnswer } }
