You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@cloudstack.apache.org by "Min Chen (JIRA)" <ji...@apache.org> on 2013/07/30 01:19:49 UTC
[jira] [Assigned] (CLOUDSTACK-3416) [Object_Store_Refactor] Extract
Volume multiple times on the same volume results in failure
[ https://issues.apache.org/jira/browse/CLOUDSTACK-3416?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Min Chen reassigned CLOUDSTACK-3416:
------------------------------------
Assignee: Min Chen
> [Object_Store_Refactor] Extract Volume multiple times on the same volume results in failure
> -------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-3416
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3416
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the default.)
> Components: Management Server
> Affects Versions: 4.2.0
> Environment: latest build from master branch
> Reporter: Sanjeev N
> Assignee: Min Chen
> Fix For: 4.2.0
>
> Attachments: management-server.rar
>
>
> [Object_Store_Refactor] Extract Volume multiple times on the same volume results in failure
> Steps to Reproduce:
> ================
> 1.Bring up CS in advanced zone with s3 as the storage provider
> 2.create a guest vm using the default cent OS template
> 3.Create a small disk, attach to a vm and detach it
> 4.Extract volume
> This is copy the volume from primary to secondary cache storage and then to s3 and will provide presinged URL to download the volume.
> 5.Repeat step 4 couple of times
> Extract volume fails with following exceptions:
> 2013-07-09 11:27:46,950 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===START=== 10.146.0.20 -- GET command=extractVolume&id=9972a317-8f8f-49d3-b91a-7eac8c193b20&zoneid=2c82a035-11cf-4303-9724-e35129dbb07e&mode=HTTP_DOWNLOAD&response=json&sessionkey=kRXjQ8Ib6WEGFB8nHLPghtXoVxs%3D&_=1373363953955
> 2013-07-09 11:27:46,991 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-25:null) submit async job-17, details: AsyncJobVO {id:17, userId: 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 6, cmd: org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd, cmdOriginator: null, cmdInfo: {"response":"json","id":"9972a317-8f8f-49d3-b91a-7eac8c193b20","sessionkey":"kRXjQ8Ib6WEGFB8nHLPghtXoVxs\u003d","cmdEventType":"VOLUME.EXTRACT","ctxUserId":"2","zoneid":"2c82a035-11cf-4303-9724-e35129dbb07e","httpmethod":"GET","_":"1373363953955","ctxAccountId":"2","ctxStartEventId":"68","mode":"HTTP_DOWNLOAD"}, cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 6615759585382, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
> 2013-07-09 11:27:46,995 DEBUG [cloud.api.ApiServlet] (catalina-exec-25:null) ===END=== 10.146.0.20 -- GET command=extractVolume&id=9972a317-8f8f-49d3-b91a-7eac8c193b20&zoneid=2c82a035-11cf-4303-9724-e35129dbb07e&mode=HTTP_DOWNLOAD&response=json&sessionkey=kRXjQ8Ib6WEGFB8nHLPghtXoVxs%3D&_=1373363953955
> 2013-07-09 11:27:46,998 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-17) Executing org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd for job-17
> 2013-07-09 11:27:47,066 DEBUG [storage.volume.VolumeObject] (Job-Executor-17:job-17) Failed to update state
> com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new state from Creating via CreateOnlyRequested
> at com.cloud.utils.fsm.StateMachine2.getNextState(StateMachine2.java:83)
> at com.cloud.utils.fsm.StateMachine2.transitTo(StateMachine2.java:100)
> at org.apache.cloudstack.storage.datastore.ObjectInDataStoreManagerImpl.update(ObjectInDataStoreManagerImpl.java:242)
> at org.apache.cloudstack.storage.volume.VolumeObject.processEventOnly(VolumeObject.java:306)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolumeFromPrimaryToImage(VolumeServiceImpl.java:659)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolume(VolumeServiceImpl.java:715)
> at com.cloud.storage.VolumeManagerImpl.extractVolume(VolumeManagerImpl.java:2776)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd.execute(ExtractVolumeCmd.java:130)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:514)
> 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:679)
> 2013-07-09 11:27:47,074 ERROR [storage.volume.VolumeServiceImpl] (Job-Executor-17:job-17) failed to copy volume to image store
> com.cloud.utils.exception.CloudRuntimeException: Failed to update state:com.cloud.utils.fsm.NoTransitionException: Unable to transition to a new state from Creating via CreateOnlyRequested
> at org.apache.cloudstack.storage.volume.VolumeObject.processEventOnly(VolumeObject.java:309)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolumeFromPrimaryToImage(VolumeServiceImpl.java:659)
> at org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolume(VolumeServiceImpl.java:715)
> at com.cloud.storage.VolumeManagerImpl.extractVolume(VolumeManagerImpl.java:2776)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd.execute(ExtractVolumeCmd.java:130)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:514)
> 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:679)
> 2013-07-09 11:27:47,094 DEBUG [agent.transport.Request] (Job-Executor-17:job-17) Seq 3-847708178: Sending { Cmd , MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9972a317-8f8f-49d3-b91a-7eac8c193b20","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.S3TO":{"id":2,"uuid":"0e7a46b0-c9fd-4d7f-9f68-3e346a2bcd35","accessKey":"9M7I6JPYZHDNLG43TWCD","secretKey":"KL7IAVYcYO8URicgniNjeCmL7k3tYKMpJRXNHw==","endPoint":"10.147.29.57:8080","bucketName":"imagestore","httpsFlag":false,"created":"Jul 9, 2013 7:59:12 AM","enableRRS":false}},"name":"test","size":5368709120,"path":"volumes/2/6/727c5651-56b4-466c-993b-9384c29b9c41.vhd","volumeId":6,"accountId":2,"format":"VHD","id":6}},"wait":0}}] }
> 2013-07-09 11:27:47,201 DEBUG [agent.transport.Request] (AgentManager-Handler-1:null) Seq 3-847708178: Processing: { Ans: , MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"details":"Deleted volume %s from bucket imagestore.","wait":0}}] }
> 2013-07-09 11:27:47,202 DEBUG [agent.transport.Request] (Job-Executor-17:job-17) Seq 3-847708178: Received: { Ans: , MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10, { Answer } }
> 2013-07-09 11:27:47,261 WARN [storage.datastore.ObjectInDataStoreManagerImpl] (Job-Executor-17:job-17) Unsupported data object (VOLUME, org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@6f941e86)
> 2013-07-09 11:27:47,271 ERROR [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-17) Unexpected exception while executing org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd
> com.cloud.utils.exception.CloudRuntimeException: Failed to copy the volume from the source primary storage pool to secondary storage.
> at com.cloud.storage.VolumeManagerImpl.extractVolume(VolumeManagerImpl.java:2790)
> at com.cloud.utils.component.ComponentInstantiationPostProcessor$InterceptorDispatcher.intercept(ComponentInstantiationPostProcessor.java:125)
> at org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd.execute(ExtractVolumeCmd.java:130)
> at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:155)
> at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:514)
> 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:679)
> 2013-07-09 11:27:47,272 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-17) Complete async job-17, jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to copy the volume from the source primary storage pool to secondary storage.
> Since there was a failure in extractVolumecmd, it executed DeleteCommand and deleted the volume which got copied to S3 after step4:
> 2013-07-09 11:27:47,094 DEBUG [agent.transport.Request] (Job-Executor-17:job-17) Seq 3-847708178: Sending { Cmd , MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 100011, [{"org.apache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"9972a317-8f8f-49d3-b91a-7eac8c193b20","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.S3TO":{"id":2,"uuid":"0e7a46b0-c9fd-4d7f-9f68-3e346a2bcd35","accessKey":"9M7I6JPYZHDNLG43TWCD","secretKey":"KL7IAVYcYO8URicgniNjeCmL7k3tYKMpJRXNHw==","endPoint":"10.147.29.57:8080","bucketName":"imagestore","httpsFlag":false,"created":"Jul 9, 2013 7:59:12 AM","enableRRS":false}},"name":"test","size":5368709120,"path":"volumes/2/6/727c5651-56b4-466c-993b-9384c29b9c41.vhd","volumeId":6,"accountId":2,"format":"VHD","id":6}},"wait":0}}] }
> 2013-07-09 11:27:47,201 DEBUG [agent.transport.Request] (AgentManager-Handler-1:null) Seq 3-847708178: Processing: { Ans: , MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":true,"details":"Deleted volume %s from bucket imagestore.","wait":0}}] }
> At this stage volume was deleted only from s3 but not from NFS cache storage.
> Following are the cloud DB entries:
> mysql> select * from volumes where id=6;
> +----+------------+-----------+---------+--------------+-------------+-----------+------+--------------------------------------+------------+--------+--------------------------------------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+----------------------------+-------------+---------------------+----------+---------------------+---------+-------+------------+--------------+-----------+----------------+--------+----------+----------+
> | id | account_id | domain_id | pool_id | last_pool_id | instance_id | device_id | name | uuid | size | folder | path | pod_id | data_center_id | iscsi_name | host_ip | volume_type | pool_type | disk_offering_id | template_id | first_snapshot_backup_uuid | recreatable | created | attached | updated | removed | state | chain_info | update_count | disk_type | display_volume | format | min_iops | max_iops |
> +----+------------+-----------+---------+--------------+-------------+-----------+------+--------------------------------------+------------+--------+--------------------------------------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+----------------------------+-------------+---------------------+----------+---------------------+---------+-------+------------+--------------+-----------+----------------+--------+----------+----------+
> | 6 | 2 | 1 | 1 | NULL | NULL | NULL | test | 9972a317-8f8f-49d3-b91a-7eac8c193b20 | 5368709120 | NULL | 30608de5-9cdb-48c8-a321-509f9b993afb | NULL | 1 | NULL | NULL | DATADISK | NULL | 3 | NULL | NULL | 0 | 2013-07-09 15:13:22 | NULL | 2013-07-09 15:27:47 | NULL | Ready | NULL | 10 | NULL | 1 | VHD | NULL | NULL |
> +----+------------+-----------+---------+--------------+-------------+-----------+------+--------------------------------------+------------+--------+--------------------------------------+--------+----------------+------------+---------+-------------+-----------+------------------+-------------+----------------------------+-------------+---------------------+----------+---------------------+---------+-------+------------+--------------+-----------+----------------+--------+----------+----------+
> 1 row in set (0.01 sec)
> mysql> select * from volume_store_ref;
> +----+----------+-----------+---------+---------------------+---------------------+--------+--------------+------------+---------------+----------------+----------+-----------+------------+------------------------------------------------------+------+-----------+-----------+--------------+---------+---------------------+
> | id | store_id | volume_id | zone_id | created | last_updated | job_id | download_pct | size | physical_size | download_state | checksum | error_str | local_path | install_path | url | state | destroyed | update_count | ref_cnt | updated |
> +----+----------+-----------+---------+---------------------+---------------------+--------+--------------+------------+---------------+----------------+----------+-----------+------------+------------------------------------------------------+------+-----------+-----------+--------------+---------+---------------------+
> | 2 | 1 | 6 | 0 | 2013-07-09 15:19:57 | 2013-07-09 15:25:03 | NULL | 0 | 5368709120 | 0 | NULL | NULL | NULL | NULL | volumes/2/6/727c5651-56b4-466c-993b-9384c29b9c41.vhd | NULL | Ready | 0 | 2 | 0 | 2013-07-09 15:20:16 |
> | 3 | 2 | 6 | 0 | 2013-07-09 15:25:02 | NULL | NULL | 0 | 2114048 | 0 | NULL | NULL | NULL | NULL | volumes/2/6/727c5651-56b4-466c-993b-9384c29b9c41.vhd | NULL | Creating | 0 | 1 | 0 | 2013-07-09 15:25:03 |
> | 5 | 2 | 6 | 0 | 2013-07-09 15:27:47 | NULL | NULL | 0 | 0 | 0 | NULL | NULL | NULL | NULL | volumes/2/6 | NULL | Allocated | 0 | 0 | 0 | NULL |
> +----+----------+-----------+---------+---------------------+---------------------+--------+--------------+------------+---------------+----------------+----------+-----------+------------+------------------------------------------------------+------+-----------+-----------+--------------+---------+---------------------+
> 3 rows in set (0.00 sec)
--
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