cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sanjeev N (JIRA)" <j...@apache.org>
Subject [jira] [Created] (CLOUDSTACK-3855) [Object_Store_Refactor][VMWare] Failed to delete volume created from snapshot
Date Fri, 26 Jul 2013 12:39:49 GMT
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

Mime
View raw message