You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Sanjeev N (JIRA)" <ji...@apache.org> on 2013/07/26 14:39:49 UTC
[jira] [Created] (CLOUDSTACK-3855) [Object_Store_Refactor][VMWare]
Failed to delete volume created from snapshot
Sanjeev N created CLOUDSTACK-3855:
-------------------------------------
Summary: [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
Priority: Critical
Fix For: 4.2.0
[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