Sanjeev N created CLOUDSTACK-3707:
-------------------------------------
Summary: [Object_Store_Refactor] Failed to extract volume using
local storage as primary and S3 as secondary storage
Key: CLOUDSTACK-3707
URL: https://issues.apache.org/jira/browse/CLOUDSTACK-3707
Project: CloudStack
Issue Type: Bug
Security Level: Public (Anyone can view this level - this is the default.)
Components: Storage Controller, Volumes
Affects Versions: 4.2.0
Environment: Latest build from ACS 4.2 branch.
Cluster: KVM
Storage: S3 for secondary and Local for Primary
Reporter: Sanjeev N
Priority: Critical
Fix For: 4.2.0
[Object_Store_Refactor] Failed to extract volume using local storage as primary
and S3 as secondary storage
Steps to Reproduce:
================
1.Bring up CS in advanced zone with kvm cluster
2.Use s3 for the secondary storage and Local storage for Primary
3.Deploy a guest vm
4.Create a custom disk offering with type Local and create a data disk using it
5.Bring the data disk to ready state (Attach to and detach from the vm)
6.Now try to download the voluem
Observations:
===========
Download volume failed but UI prompted with URL to download the volume.
Did not find volume either in Cache Storage or in S3 bucket .
Following is the log snippet from management server log file:
2013-07-22 05:29:07,126 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null)
===START=== 10.146.0.20 -- GET
command=extractVolume&id=51a52b74-a6c0-4ee1-9508-07accf4c0eb6&zoneid=95fa0404-76ef-450b-b919-02b41134fb0b&mode=HTTP_DOWNLOAD&response=json&sessionkey=jZa5Sz7FdnclZTONr7andJxhx%2Bs%3D&_=1374485347356
2013-07-22 05:29:07,273 DEBUG [cloud.async.AsyncJobManagerImpl]
(catalina-exec-2:null) submit async job-27 = [
cdb6535d-fc7d-46c5-8a22-8533aac4c171 ], details: AsyncJobVO {id:27, userId: 2,
accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 9, cmd:
org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd, cmdOriginator:
null, cmdInfo:
{"response":"json","id":"51a52b74-a6c0-4ee1-9508-07accf4c0eb6","sessionkey":"jZa5Sz7FdnclZTONr7andJxhx+s\u003d","cmdEventType":"VOLUME.EXTRACT","ctxUserId":"2","zoneid":"95fa0404-76ef-450b-b919-02b41134fb0b","httpmethod":"GET","_":"1374485347356","ctxAccountId":"2","ctxStartEventId":"111","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-22 05:29:07,276 DEBUG [cloud.api.ApiServlet] (catalina-exec-2:null)
===END=== 10.146.0.20 -- GET
command=extractVolume&id=51a52b74-a6c0-4ee1-9508-07accf4c0eb6&zoneid=95fa0404-76ef-450b-b919-02b41134fb0b&mode=HTTP_DOWNLOAD&response=json&sessionkey=jZa5Sz7FdnclZTONr7andJxhx%2Bs%3D&_=1374485347356
2013-07-22 05:29:07,279 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Executing
org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd for job-27 = [
cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]
2013-07-22 05:29:07,345 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) copyAsync
inspecting src type VOLUME copyAsync inspecting dest type VOLUME
2013-07-22 05:29:07,353 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ])
needCacheStorage true, dest at volumes/2/9 dest role
Image26d98086-58b4-461c-9fee-c47c9bd1f565 src role Primary
2013-07-22 05:29:07,374 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) copyAsync
inspecting src type VOLUME copyAsync inspecting dest type VOLUME
2013-07-22 05:29:07,387 DEBUG [agent.manager.AgentAttache]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Request
seq: 1081016695
2013-07-22 05:29:07,388 DEBUG [agent.manager.AgentAttache]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) waiting to
send 1081016695
2013-07-22 05:29:07,388 DEBUG [agent.manager.AgentAttache]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) entering
synchronize block for sending 1081016695
2013-07-22 05:29:07,389 DEBUG [agent.transport.Request] (Job-Executor-20:job-27
= [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Seq 1-1081016695: Sending { Cmd ,
MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 100011,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"51a52b74-a6c0-4ee1-9508-07accf4c0eb6","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"41bebe55-fa87-4581-b93a-7aeda2e9afd4","id":1,"poolType":"Filesystem","host":"10.147.40.14","path":"/var/lib/libvirt/images","port":0}},"name":"local","size":0,"path":"26d98086-58b4-461c-9fee-c47c9bd1f565","volumeId":9,"accountId":2,"format":"QCOW2","id":9}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"51a52b74-a6c0-4ee1-9508-07accf4c0eb6","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_kvm_os","_role":"ImageCache"}},"name":"local","size":0,"path":"volumes/2/9","volumeId":9,"accountId":2,"format":"QCOW2","id":9}},"executeInSequence":false,"wait":10800}}]
}
2013-07-22 05:29:07,395 DEBUG [agent.transport.Request]
(AgentManager-Handler-6:null) Seq 1-1081016695: Processing: { Ans: , MgmtId:
6615759585382, via: 1, Ver: v1, Flags: 10,
[{"com.cloud.agent.api.UnsupportedAnswer":{"result":false,"details":"Unsupported
command issued:org.apache.cloudstack.storage.command.CopyCommand. Are you
sure you got the right type of server?","wait":0}}] }
2013-07-22 05:29:07,395 DEBUG [agent.transport.Request] (Job-Executor-20:job-27
= [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Seq 1-1081016695: Received: { Ans:
, MgmtId: 6615759585382, via: 1, Ver: v1, Flags: 10, { UnsupportedAnswer } }
2013-07-22 05:29:07,395 WARN [agent.manager.AgentManagerImpl]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Unsupported
Command: Unsupported command
issued:org.apache.cloudstack.storage.command.CopyCommand. Are you sure you got
the right type of server?
2013-07-22 05:29:07,408 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) copy object
failed: java.lang.NullPointerException
2013-07-22 05:29:07,408 DEBUG [storage.motion.AncientDataMotionStrategy]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) copy failed
com.cloud.utils.exception.CloudRuntimeException: java.lang.NullPointerException
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyObject(AncientDataMotionStrategy.java:207)
at
org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:354)
at
org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolumeFromPrimaryToImage(VolumeServiceImpl.java:682)
at
org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolume(VolumeServiceImpl.java:729)
at
com.cloud.storage.VolumeManagerImpl.extractVolume(VolumeManagerImpl.java:2780)
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: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:679)
2013-07-22 05:29:07,434 INFO [datastore.driver.S3ImageStoreDriverImpl]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Generating
pre-signed s3 entity extraction URL.
2013-07-22 05:29:07,435 DEBUG [cloud.utils.S3Utils] (Job-Executor-20:job-27 = [
cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Creating S3 client with configuration:
[protocol: http, connectionTimeOut: 50000, maxErrorRetry: 3, socketTimeout:
50000]
2013-07-22 05:29:07,444 DEBUG [cloud.utils.S3Utils] (Job-Executor-20:job-27 = [
cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Setting the end point for S3 client
com.amazonaws.services.s3.AmazonS3Client@c8eb2a6 to 10.147.29.57:8080.
2013-07-22 05:29:07,445 INFO [datastore.driver.S3ImageStoreDriverImpl]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Pre-Signed
URL =
http://10.147.29.57:8080/imagestore/volumes%2F2%2F9?Expires=1374488947&AWSAccessKeyId=9M7I6JPYZHDNLG43TWCD&Signature=ZZF%2BOx4Y5JDZEGGnPxdM4Mu1Qzc%3D
2013-07-22 05:29:07,460 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Complete
async job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ], jobStatus: 1,
resultCode: 0, result:
org.apache.cloudstack.api.response.ExtractResponse@541ab121
2013-07-22 05:29:07,466 DEBUG [cloud.async.AsyncJobManagerImpl]
(Job-Executor-20:job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]) Done
executing org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd for
job-27 = [ cdb6535d-fc7d-46c5-8a22-8533aac4c171 ]
--
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