You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Rohit Kumar (JIRA)" <ji...@apache.org> on 2014/02/26 07:09:19 UTC

[jira] [Created] (CLOUDSTACK-6171) Cloudstack:KVM:: Snapshot stuck in Creating Status forever.‏

Rohit Kumar created CLOUDSTACK-6171:
---------------------------------------

             Summary: Cloudstack:KVM:: Snapshot stuck in Creating Status forever.‏
                 Key: CLOUDSTACK-6171
                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-6171
             Project: CloudStack
          Issue Type: Task
      Security Level: Public (Anyone can view this level - this is the default.)
          Components: Infra, Install and Setup, KVM, Management Server
    Affects Versions: 4.2.0, 4.2.1
         Environment: RHEL 6.4
            Reporter: Rohit Kumar
            Priority: Blocker


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.

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 this.

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 } }


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 



--
This message was sent by Atlassian JIRA
(v6.1.5#6160)