[ https://issues.apache.org/jira/browse/CLOUDSTACK-4109?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13732979#comment-13732979 ]
Min Chen edited comment on CLOUDSTACK-4109 at 8/8/13 1:16 AM: -------------------------------------------------------------- The Copy failure is due to null volume.size in returned CopyCmdAnswer, so an exception is thrown in processing that CopyCmdAnswer. Commit 6ebfa923ff9a76b90b3d03634bfefa22d8841ccc is to fix the issue that control is still going on to generate url even if copyCommand failed. was (Author: minchen07): The Copy failure should have been fixed by commit 0243f043cb4814b0c8dbb13f44c34436db50de87 due to null volume.size in returned CopyCmdAnswer, so an exception is thrown in processing that CopyCmdAnswer. Commit 6ebfa923ff9a76b90b3d03634bfefa22d8841ccc is to fix the issue that control is still going on to generate url even if copyCommand failed. > [Object_store_refactor] Extract volume failed with NPE > ------------------------------------------------------ > > Key: CLOUDSTACK-4109 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4109 > 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: S3 for secondary, NFS for staging and ISCSI for primary storage > Reporter: Sanjeev N > Assignee: Min Chen > Priority: Critical > Fix For: 4.2.0 > > Attachments: cloud.dmp, management-server.rar > > > Extract volume failed with NPE > Steps to Reproduce: > ================ > 1.Bring up CS with VMWare cluster using S3 for secondary ,NFS for staging and > ISCSI for primary storage. > 2.Deploy guest vm with root disk > 3.Create a custom data disk and attach to the vm > 4.Dettach the data disk and try to extract the volume > Result: > ====== > Download volume failed with NPE but still UI prompted with URL to download > the volume even-though volume was not copied to S3 storage. > Log snippet as follows: > 2013-08-06 07:32:46,296 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-10:null) submit async job-25 = [ > 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ], details: AsyncJobVO {id:25, userId: > 2, accountId: 2, sessionKey: null, instanceType: Volume, instanceId: 11, cmd: > org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd, > cmdOriginator: null, cmdInfo: > {"response":"json","id":"003c0b9c-176f-463e-aac7-fdefde807c86","sessionkey":"foQa9K4dPmYo8uEiAcolaTVR6yI\u003d","cmdEventType":"VOLUME.EXTRACT","ctxUserId":"2","zoneid":"a7c59acd-1b2f-4f06-b50b-bd79e113c692","httpmethod":"GET","_":"1375788754095","ctxAccountId":"2","ctxStartEventId":"95","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-08-06 07:32:46,298 DEBUG [cloud.api.ApiServlet] (catalina-exec-10:null) > ===END=== 10.146.0.20 -- GET > command=extractVolume&id=003c0b9c-176f-463e-aac7-fdefde807c86&zoneid=a7c59acd-1b2f-4f06-b50b-bd79e113c692&mode=HTTP_DOWNLOAD&response=json&sessionkey=foQa9K4dPmYo8uEiAcolaTVR6yI%3D&_=1375788754095 > 2013-08-06 07:32:46,302 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) Executing > org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd for job-25 = [ > 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ] > 2013-08-06 07:32:46,395 DEBUG [storage.motion.AncientDataMotionStrategy] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) copyAsync > inspecting src type VOLUME copyAsync inspecting dest type VOLUME > 2013-08-06 07:32:46,406 DEBUG [storage.motion.AncientDataMotionStrategy] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) > needCacheStorage true, dest at volumes/2/11 dest role > Image7a16cf210c6c4af3b39a04c94dca7035 src role Primary > 2013-08-06 07:32:46,430 DEBUG [storage.motion.AncientDataMotionStrategy] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) copyAsync > inspecting src type VOLUME copyAsync inspecting dest type VOLUME > 2013-08-06 07:32:46,462 DEBUG [agent.transport.Request] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) Seq > 3-1317535767: Sending { Cmd , MgmtId: 6615759585382, via: 3, Ver: v1, Flags: > 100011, > [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"003c0b9c-176f-463e-aac7-fdefde807c86","volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"b845e7d4-562a-3b2d-8e59-b1df565f99e5","id":1,"poolType":"VMFS","host":"VMFS > datastore: > /sanjeev/openFiler","path":"/sanjeev/openFiler","port":0}},"name":"v1","size":5120,"path":"7a16cf210c6c4af3b39a04c94dca7035","volumeId":11,"accountId":2,"format":"OVA","id":11,"hypervisorType":"VMware"}},"destTO":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"uuid":"003c0b9c-176f-463e-aac7-fdefde807c86","volumeType":"DATADISK","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/home/sanjeev/sec_esx_os","_role":"ImageCache"}},"name":"v1","size":5120,"path":"volumes/2/11","volumeId":11,"accountId":2,"format":"OVA","id":11,"hypervisorType":"VMware"}},"executeInSequence":false,"wait":10800}}] > } > 2013-08-06 07:33:13,383 DEBUG [agent.transport.Request] > (AgentManager-Handler-15:null) Seq 3-1317535767: Processing: { Ans: , > MgmtId: 6615759585382, via: 3, Ver: v1, Flags: 10, > [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.VolumeObjectTO":{"path":"volumes/2/11/8a35b3a87c004558b087a5aa4527b46e","accountId":0,"id":0}},"result":true,"wait":0}}] > } > 2013-08-06 07:33:13,383 DEBUG [agent.transport.Request] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) Seq > 3-1317535767: Received: { Ans: , MgmtId: 6615759585382, via: 3, Ver: v1, > Flags: 10, { CopyCmdAnswer } } > 2013-08-06 07:33:13,448 DEBUG [storage.motion.AncientDataMotionStrategy] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) copy > object failed: java.lang.NullPointerException > 2013-08-06 07:33:13,449 DEBUG [storage.motion.AncientDataMotionStrategy] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) copy > failed > com.cloud.utils.exception.CloudRuntimeException: > java.lang.NullPointerException > at > org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyObject(AncientDataMotionStrategy.java:210) > at > org.apache.cloudstack.storage.motion.AncientDataMotionStrategy.copyAsync(AncientDataMotionStrategy.java:386) > at > org.apache.cloudstack.storage.motion.DataMotionServiceImpl.copyAsync(DataMotionServiceImpl.java:55) > at > org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolumeFromPrimaryToImage(VolumeServiceImpl.java:716) > at > org.apache.cloudstack.storage.volume.VolumeServiceImpl.copyVolume(VolumeServiceImpl.java:763) > at > com.cloud.storage.VolumeManagerImpl.extractVolume(VolumeManagerImpl.java:2788) > 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-08-06 07:33:13,457 DEBUG [cloud.api.ApiServlet] (catalina-exec-15:null) > ===END=== 10.146.0.20 -- GET > command=queryAsyncJobResult&jobId=448d8e6e-e4fe-46a5-b6f6-e839ff720052&response=json&sessionkey=foQa9K4dPmYo8uEiAcolaTVR6yI%3D&_=1375788781299 > 2013-08-06 07:33:13,478 INFO [datastore.driver.S3ImageStoreDriverImpl] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) > Generating pre-signed s3 entity extraction URL. > 2013-08-06 07:33:13,481 DEBUG [cloud.utils.S3Utils] (Job-Executor-26:job-25 = > [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) Creating S3 client with > configuration: [protocol: http, connectionTimeOut: 500000, maxErrorRetry: 2, > socketTimeout: 500000] > 2013-08-06 07:33:13,490 DEBUG [cloud.utils.S3Utils] (Job-Executor-26:job-25 = > [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) Setting the end point for S3 client > com.amazonaws.services.s3.AmazonS3Client@2a7484fd to 10.147.29.57:8080. > 2013-08-06 07:33:13,495 INFO [datastore.driver.S3ImageStoreDriverImpl] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) > Pre-Signed URL = > http://10.147.29.57:8080/imagestore/volumes%2F2%2F11?Expires=1375803193&AWSAccessKeyId=9M7I6JPYZHDNLG43TWCD&Signature=FO083cEUv5BjDQTgG0BnaNPMk7A%3D > 2013-08-06 07:33:13,520 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) Complete > async job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ], jobStatus: 1, > resultCode: 0, result: > org.apache.cloudstack.api.response.ExtractResponse@6a13b5e9 > 2013-08-06 07:33:13,528 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-26:job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ]) Done > executing org.apache.cloudstack.api.command.user.volume.ExtractVolumeCmd for > job-25 = [ 448d8e6e-e4fe-46a5-b6f6-e839ff720052 ] > Volume is copied to secondary staging storage bug failed in copying to S3 > storage. > From the logs I could say that there was a copyCommand only to copy volume > from primary to secondary staging storage but there was no copyCommand to > copy volume from staging storage to S3. > Attaching management server log file and cloud DB. -- 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