You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "edison su (JIRA)" <ji...@apache.org> on 2013/07/26 22:41:49 UTC
[jira] [Assigned] (CLOUDSTACK-3855) [Object_Store_Refactor][VMWare]
Failed to delete volume created from snapshot
[ https://issues.apache.org/jira/browse/CLOUDSTACK-3855?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
edison su reassigned CLOUDSTACK-3855:
-------------------------------------
Assignee: edison su
> [Object_Store_Refactor][VMWare] Failed to delete volume created from snapshot
> -----------------------------------------------------------------------------
>
> Key: CLOUDSTACK-3855
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3855
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Storage Controller, VMware, Volumes
> Affects Versions: 4.2.0
> Environment: Latest build from ACS 4.2 branch
> Storage: NFS for both primary and secondary
> Reporter: Sanjeev N
> Assignee: edison su
> Priority: Critical
> Fix For: 4.2.0
>
> Attachments: cloud.dmp, management-server.rar
>
>
> [Object_Store_Refactor][VMWare] Failed to delete volume created from snapshot
> Steps to Reproduce:
> ================
> 1.Bring up CS with vmware cluster
> 2.Create primary and secondary storage using NFS
> 3.Deploy guest vm using default cent of template
> 4.Create snapshot on the root disk of the vm
> 5.Create volume from the snapshot created above
> 6.Delete volume
> Expected Result:
> =============
> Volume deletion should be successful
> Actual Result:
> ==========
> Volume deletion failed
> Observations:
> ===========
> Volume is deleted from the primary storage, but it remained in Expunging state in volumes table.
> Following is the log snippet from management server log:
> 2013-07-26 08:21:55,509 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===START=== 10.146.0.20 -- GET command=deleteVolume&id=b8510782-a81d-4030-92fa-0caa8ad4fd43&response=json&sessionkey=q1TR1VxFu6eJ5wz9Ir014iaS6Ng%3D&_=1374841314322
> 2013-07-26 08:21:55,633 INFO [cloud.storage.VolumeManagerImpl] (catalina-exec-19:null) Expunging volume 14 from primary data store
> 2013-07-26 08:21:55,683 DEBUG [agent.transport.Request] (catalina-exec-19:null) Seq 2-1034028063: Sending { Cmd , MgmtId: 6615759585382, via: 2, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b8510782-a81d-4030-92fa-0caa8ad4fd43","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"468ecd4b-14a6-3b7d-8991-c9dd7427b94a","id":2,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_esx_os","port":2049}},"name":"vm1-esx","size":6500,"path":"6fd7d69e7f6647869a74f60566c88d3a","volumeId":14,"accountId":2,"format":"OVA","id":14,"hypervisorType":"VMware"}},"wait":0}}] }
> 2013-07-26 08:21:55,684 DEBUG [agent.transport.Request] (catalina-exec-19:null) Seq 2-1034028063: Executing: { Cmd , MgmtId: 6615759585382, via: 2, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b8510782-a81d-4030-92fa-0caa8ad4fd43","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"468ecd4b-14a6-3b7d-8991-c9dd7427b94a","id":2,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_esx_os","port":2049}},"name":"vm1-esx","size":6500,"path":"6fd7d69e7f6647869a74f60566c88d3a","volumeId":14,"accountId":2,"format":"OVA","id":14,"hypervisorType":"VMware"}},"wait":0}}] }
> 2013-07-26 08:21:55,684 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-435:null) Seq 2-1034028063: Executing request
> 2013-07-26 08:21:55,691 INFO [storage.resource.VmwareStorageProcessor] (DirectAgent-435:10.147.40.13) Executing resource DestroyCommand: {"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"b8510782-a81d-4030-92fa-0caa8ad4fd43","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"468ecd4b-14a6-3b7d-8991-c9dd7427b94a","id":2,"poolType":"NetworkFilesystem","host":"10.147.28.7","path":"/export/home/sanjeev/pri_esx_os","port":2049}},"name":"vm1-esx","size":6500,"path":"6fd7d69e7f6647869a74f60566c88d3a","volumeId":14,"accountId":2,"format":"OVA","id":14,"hypervisorType":"VMware"}},"wait":0}
> 2013-07-26 08:21:55,726 INFO [storage.resource.VmwareStorageProcessor] (DirectAgent-435:10.147.40.13) Destroy volume by original name: 6fd7d69e7f6647869a74f60566c88d3a.vmdk
> 2013-07-26 08:21:55,733 INFO [vmware.mo.DatastoreMO] (DirectAgent-435:10.147.40.13) Search file 6fd7d69e7f6647869a74f60566c88d3a.vmdk on [468ecd4b14a63b7d8991c9dd7427b94a]
> 2013-07-26 08:21:55,815 INFO [vmware.mo.DatastoreMO] (DirectAgent-435:10.147.40.13) File [468ecd4b14a63b7d8991c9dd7427b94a] 6fd7d69e7f6647869a74f60566c88d3a.vmdk exists on datastore
> 2013-07-26 08:21:56,134 INFO [storage.resource.VmwareStorageProcessor] (DirectAgent-435:10.147.40.13) Destroy volume by derived name: 6fd7d69e7f6647869a74f60566c88d3a-flat.vmdk
> 2013-07-26 08:21:56,138 INFO [vmware.mo.DatastoreMO] (DirectAgent-435:10.147.40.13) Search file 6fd7d69e7f6647869a74f60566c88d3a-flat.vmdk on [468ecd4b14a63b7d8991c9dd7427b94a]
> 2013-07-26 08:21:56,159 INFO [vmware.mo.DatastoreMO] (DirectAgent-435:10.147.40.13) File [468ecd4b14a63b7d8991c9dd7427b94a] 6fd7d69e7f6647869a74f60566c88d3a-flat.vmdk exists on datastore
> 2013-07-26 08:22:07,622 ERROR [storage.resource.VmwareStorageProcessor] (DirectAgent-435:10.147.40.13) DestroyCommand failed due to Exception: java.lang.RuntimeException
> Message: Cannot delete file [468ecd4b14a63b7d8991c9dd7427b94a] 6fd7d69e7f6647869a74f60566c88d3a-flat.vmdk
> java.lang.RuntimeException: Cannot delete file [468ecd4b14a63b7d8991c9dd7427b94a] 6fd7d69e7f6647869a74f60566c88d3a-flat.vmdk
> at com.cloud.hypervisor.vmware.util.VmwareClient.waitForTask(VmwareClient.java:290)
> at com.cloud.hypervisor.vmware.mo.DatastoreMO.deleteFile(DatastoreMO.java:158)
> at com.cloud.storage.resource.VmwareStorageProcessor.deleteVolume(VmwareStorageProcessor.java:1524)
> at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:114)
> at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:53)
> at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:566)
> 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-07-26 08:22:07,630 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-435:null) Seq 2-1034028063: Response Received:
> 2013-07-26 08:22:07,631 DEBUG [agent.transport.Request] (DirectAgent-435:null) Seq 2-1034028063: Processing: { Ans: , MgmtId: 6615759585382, via: 2, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false,"details":"DestroyCommand failed due to Exception: java.lang.RuntimeException\nMessage: Cannot delete file [468ecd4b14a63b7d8991c9dd7427b94a] 6fd7d69e7f6647869a74f60566c88d3a-flat.vmdk\n","wait":0}}] }
> 2013-07-26 08:22:07,631 DEBUG [agent.transport.Request] (catalina-exec-19:null) Seq 2-1034028063: Received: { Ans: , MgmtId: 6615759585382, via: 2, Ver: v1, Flags: 10, { Answer } }
> 2013-07-26 08:22:07,641 WARN [storage.datastore.ObjectInDataStoreManagerImpl] (catalina-exec-19:null) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@4039ea94)
> 2013-07-26 08:22:07,650 INFO [cloud.storage.VolumeManagerImpl] (catalina-exec-19:null) Expunging volume 14 from secondary data store
> 2013-07-26 08:22:07,664 DEBUG [storage.volume.VolumeObject] (catalina-exec-19:null) Failed to transit volume: 14, due to: com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new state from Expunging via DestroyRequested
> 2013-07-26 08:22:07,664 DEBUG [storage.volume.VolumeObject] (catalina-exec-19:null) Failed to update state
> com.cloud.utils.exception.CloudRuntimeException: Failed to transit volume: 14, due to: com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new state from Expunging via DestroyRequested
> at org.apache.cloudstack.storage.volume.VolumeObject.stateTransit(VolumeObject.java:158)
> at org.apache.cloudstack.storage.volume.VolumeObject.processEvent(VolumeObject.java:288)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:272)
> at com.cloud.storage.VolumeManagerImpl.deleteVolume(VolumeManagerImpl.java:1376)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.volume.DeleteVolumeCmd.execute(DeleteVolumeCmd.java:83)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.api.ApiServer.queueCommand(ApiServer.java:514)
> at com.cloud.api.ApiServer.handleRequest(ApiServer.java:372)
> at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:305)
> at com.cloud.api.ApiServlet.doGet(ApiServlet.java:66)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
> at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
> at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:721)
> at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2268)
> 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-07-26 08:22:07,665 WARN [cloud.storage.VolumeManagerImpl] (catalina-exec-19:null) Failed to expunge volume:
> com.cloud.utils.exception.CloudRuntimeException: Failed to update state:com.cloud.utils.exception.CloudRuntimeException: Failed to transit volume: 14, due to: com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new state from Expunging via DestroyRequested
> at org.apache.cloudstack.storage.volume.VolumeObject.processEvent(VolumeObject.java:291)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.expungeVolumeAsync(VolumeServiceImpl.java:272)
> at com.cloud.storage.VolumeManagerImpl.deleteVolume(VolumeManagerImpl.java:1376)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.volume.DeleteVolumeCmd.execute(DeleteVolumeCmd.java:83)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:158)
> at com.cloud.api.ApiServer.queueCommand(ApiServer.java:514)
> at com.cloud.api.ApiServer.handleRequest(ApiServer.java:372)
> at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:305)
> at com.cloud.api.ApiServlet.doGet(ApiServlet.java:66)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
> at org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
> at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:721)
> at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2268)
> 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-07-26 08:22:07,676 INFO [cloud.api.ApiServer] (catalina-exec-19:null) Failed to delete volume
> 2013-07-26 08:22:07,677 DEBUG [cloud.api.ApiServlet] (catalina-exec-19:null) ===END=== 10.146.0.20 -- GET command=deleteVolume&id=b8510782-a81d-4030-92fa-0caa8ad4fd43&response=json&sessionkey=q1TR1VxFu6eJ5wz9Ir014iaS6Ng%3D&_=1374841314322
> Volume state in DB:
> ================
> mysql> select * from volumes where id=14\G;
> *************************** 1. row ***************************
> id: 14
> account_id: 2
> domain_id: 1
> pool_id: 2
> last_pool_id: NULL
> instance_id: NULL
> device_id: NULL
> name: vm1-esx
> uuid: b8510782-a81d-4030-92fa-0caa8ad4fd43
> size: 6500
> folder: NULL
> path: 6fd7d69e7f6647869a74f60566c88d3a
> pod_id: NULL
> data_center_id: 2
> iscsi_name: NULL
> host_ip: NULL
> volume_type: DATADISK
> pool_type: NULL
> disk_offering_id: 1
> template_id: 7
> first_snapshot_backup_uuid: NULL
> recreatable: 0
> created: 2013-07-26 09:25:35
> attached: NULL
> updated: 2013-07-26 12:22:07
> removed: NULL
> state: Expunging
> chain_info: NULL
> update_count: 8
> disk_type: NULL
> display_volume: 1
> format: OVA
> min_iops: NULL
> max_iops: NULL
> 1 row in set (0.00 sec)
> ERROR:
> No query specified
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira