Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id AD1C610CF7 for ; Sat, 10 Aug 2013 02:45:57 +0000 (UTC) Received: (qmail 9945 invoked by uid 500); 10 Aug 2013 02:45:57 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 9793 invoked by uid 500); 10 Aug 2013 02:45:57 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 9765 invoked by uid 500); 10 Aug 2013 02:45:56 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 9761 invoked by uid 99); 10 Aug 2013 02:45:56 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 10 Aug 2013 02:45:56 +0000 Date: Sat, 10 Aug 2013 02:45:56 +0000 (UTC) From: "edison su (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Resolved] (CLOUDSTACK-4211) [Object_store_refactor] Failed to create snapshot with S3 on kvm MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-4211?page=3Dcom.atl= assian.jira.plugin.system.issuetabpanels:all-tabpanel ] edison su resolved CLOUDSTACK-4211. ----------------------------------- Resolution: Fixed =20 > [Object_store_refactor] Failed to create snapshot with S3 on kvm > ---------------------------------------------------------------- > > Key: CLOUDSTACK-4211 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-421= 1 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the defa= ult.)=20 > Components: KVM, Snapshot, Storage Controller > Affects Versions: 4.2.0 > Environment: Latest build from ACS 4.2 branch > Storage: S3 for secondary, NFS for secondary staging, and local storage f= or primary > Cluster: KVM > Reporter: Sanjeev N > Assignee: edison su > Priority: Critical > Fix For: 4.2.0 > > Attachments: cloud.dmp, management-server.rar > > > Failed to create snapshot with S3 on kvm > Steps to Reproduce: > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > 1. Bring up CS with KVM cluster using S3 for secondary, NFS for secondar= y staging, and local storage for primary > 2.Deploy guest vm using default cent os template with both root and data = disk > 3.Create snapshot on root/data disk > Result: > =3D=3D=3D=3D=3D > Snapshot creation failed with CloudRuntimeException: unsupported protocol > Observations: > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D > Snapshot is created on primary but failed to copy to secondary staging st= orage. > Following is the log snippet: > 2013-08-09 13:28:25,757 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:nul= l) =3D=3D=3DSTART=3D=3D=3D 10.146.0.20 -- GET command=3DcreateSnapshot&vo= lumeid=3D2b3fdf2f-579b-4771-8ac8-3d7ef2988a79&response=3Djson&sessionkey=3D= zXXHX4Nf5yJtILkB4BA8E75f9HA%3D&_=3D1376049616400 > 2013-08-09 13:28:25,956 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina= -exec-6:null) submit async job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba= 1 ], details: AsyncJobVO {id:17, userId: 3, accountId: 3, sessionKey: null,= instanceType: Snapshot, instanceId: 3, cmd: org.apache.cloudstack.api.comm= and.user.snapshot.CreateSnapshotCmd, cmdOriginator: null, cmdInfo: {"id":"3= ","response":"json","sessionkey":"zXXHX4Nf5yJtILkB4BA8E75f9HA\u003d","cmdEv= entType":"SNAPSHOT.CREATE","ctxUserId":"3","httpmethod":"GET","_":"13760496= 16400","volumeid":"2b3fdf2f-579b-4771-8ac8-3d7ef2988a79","ctxAccountId":"3"= ,"ctxStartEventId":"79"}, cmdVersion: 0, callbackType: 0, callbackAddress: = null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 7= 332683579487, completeMsid: null, lastUpdated: null, lastPolled: null, crea= ted: null} > 2013-08-09 13:28:25,959 DEBUG [cloud.api.ApiServlet] (catalina-exec-6:nul= l) =3D=3D=3DEND=3D=3D=3D 10.146.0.20 -- GET command=3DcreateSnapshot&volu= meid=3D2b3fdf2f-579b-4771-8ac8-3d7ef2988a79&response=3Djson&sessionkey=3DzX= XHX4Nf5yJtILkB4BA8E75f9HA%3D&_=3D1376049616400 > 2013-08-09 13:28:25,962 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Exec= utor-2:job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Executing org.a= pache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-17 =3D= [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ] > 2013-08-09 13:28:26,039 INFO [user.snapshot.CreateSnapshotCmd] (Job-Exec= utor-2:job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) VOLSS: createSn= apshotCmd starts:1376069306039 > 2013-08-09 13:28:26,313 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Seq 1-1681129511: Sendi= ng { Cmd , MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 100011, [{"org.a= pache.cloudstack.storage.command.CreateObjectCommand":{"data":{"org.apache.= cloudstack.storage.to.SnapshotObjectTO":{"volume":{"uuid":"2b3fdf2f-579b-47= 71-8ac8-3d7ef2988a79","volumeType":"DATADISK","dataStore":{"org.apache.clou= dstack.storage.to.PrimaryDataStoreTO":{"uuid":"c8c1d524-3f88-4faa-9092-9ee3= 7ac9e25e","id":1,"poolType":"Filesystem","host":"10.147.40.8","path":"/var/= lib/libvirt/images","port":0}},"name":"DATA-5","size":5368709120,"path":"98= 700ea8-2e2f-4cac-bb10-fb6c6bb11032","volumeId":7,"vmName":"i-3-5-VM","accou= ntId":3,"format":"QCOW2","id":7,"hypervisorType":"KVM"},"dataStore":{"org.a= pache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c8c1d524-3f88-4faa= -9092-9ee37ac9e25e","id":1,"poolType":"Filesystem","host":"10.147.40.8","pa= th":"/var/lib/libvirt/images","port":0}},"vmName":"i-3-5-VM","name":"test-v= m_DATA-5_20130809172825","hypervisorType":"KVM","id":3}},"wait":0}}] } > 2013-08-09 13:28:27,219 DEBUG [agent.transport.Request] (AgentManager-Han= dler-11:null) Seq 1-1681129511: Processing: { Ans: , MgmtId: 7332683579487= , via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.Crea= teObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO= ":{"path":"/var/lib/libvirt/images/98700ea8-2e2f-4cac-bb10-fb6c6bb11032/46d= 77288-3034-48f3-9864-c14bb47bc7bf","id":0}},"result":true,"wait":0}}] } > 2013-08-09 13:28:27,219 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Seq 1-1681129511: Recei= ved: { Ans: , MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 10, { CreateO= bjectAnswer } } > 2013-08-09 13:28:27,284 DEBUG [storage.motion.AncientDataMotionStrategy] = (Job-Executor-2:job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) copyAs= ync inspecting src type SNAPSHOT copyAsync inspecting dest type SNAPSHOT > 2013-08-09 13:28:27,330 DEBUG [storage.motion.AncientDataMotionStrategy] = (Job-Executor-2:job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) needCa= cheStorage true, dest at snapshots/3/7 dest role Image/var/lib/libvirt/imag= es/98700ea8-2e2f-4cac-bb10-fb6c6bb11032/46d77288-3034-48f3-9864-c14bb47bc7b= f src role Primary > 2013-08-09 13:28:27,433 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Seq 1-1681129512: Sendi= ng { Cmd , MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 100011, [{"org.a= pache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudst= ack.storage.to.SnapshotObjectTO":{"path":"/var/lib/libvirt/images/98700ea8-= 2e2f-4cac-bb10-fb6c6bb11032/46d77288-3034-48f3-9864-c14bb47bc7bf","volume":= {"uuid":"2b3fdf2f-579b-4771-8ac8-3d7ef2988a79","volumeType":"DATADISK","dat= aStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c8c= 1d524-3f88-4faa-9092-9ee37ac9e25e","id":1,"poolType":"Filesystem","host":"1= 0.147.40.8","path":"/var/lib/libvirt/images","port":0}},"name":"DATA-5","si= ze":5368709120,"path":"98700ea8-2e2f-4cac-bb10-fb6c6bb11032","volumeId":7,"= vmName":"i-3-5-VM","accountId":3,"format":"QCOW2","id":7,"hypervisorType":"= KVM"},"dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"= uuid":"c8c1d524-3f88-4faa-9092-9ee37ac9e25e","id":1,"poolType":"Filesystem"= ,"host":"10.147.40.8","path":"/var/lib/libvirt/images","port":0}},"vmName":= "i-3-5-VM","name":"test-vm_DATA-5_20130809172825","hypervisorType":"KVM","i= d":3}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path= ":"snapshots/3/7","volume":{"uuid":"2b3fdf2f-579b-4771-8ac8-3d7ef2988a79","= volumeType":"DATADISK","dataStore":{"org.apache.cloudstack.storage.to.Prima= ryDataStoreTO":{"uuid":"c8c1d524-3f88-4faa-9092-9ee37ac9e25e","id":1,"poolT= ype":"Filesystem","host":"10.147.40.8","path":"/var/lib/libvirt/images","po= rt":0}},"name":"DATA-5","size":5368709120,"path":"98700ea8-2e2f-4cac-bb10-f= b6c6bb11032","volumeId":7,"vmName":"i-3-5-VM","accountId":3,"format":"QCOW2= ","id":7,"hypervisorType":"KVM"},"dataStore":{"com.cloud.agent.api.to.S3TO"= :{"id":2,"uuid":"28c97b44-c81a-41db-9644-1f28c674d121","endPoint":"10.147.2= 9.56:8080","bucketName":"imagestore119","httpsFlag":false,"created":"Aug 9,= 2013 12:09:22 PM","enableRRS":false}},"vmName":"i-3-5-VM","name":"test-vm_= DATA-5_20130809172825","hypervisorType":"KVM","id":3}},"cacheTO":{"org.apac= he.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/3/7","volume"= :{"uuid":"2b3fdf2f-579b-4771-8ac8-3d7ef2988a79","volumeType":"DATADISK","da= taStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c8= c1d524-3f88-4faa-9092-9ee37ac9e25e","id":1,"poolType":"Filesystem","host":"= 10.147.40.8","path":"/var/lib/libvirt/images","port":0}},"name":"DATA-5","s= ize":5368709120,"path":"98700ea8-2e2f-4cac-bb10-fb6c6bb11032","volumeId":7,= "vmName":"i-3-5-VM","accountId":3,"format":"QCOW2","id":7,"hypervisorType":= "KVM"},"dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28= .7/export/home/sanjeev/sec_kvm_os","_role":"ImageCache"}},"vmName":"i-3-5-V= M","name":"test-vm_DATA-5_20130809172825","hypervisorType":"KVM","id":3}},"= executeInSequence":false,"wait":21600}}] } > 2013-08-09 13:28:27,444 DEBUG [agent.transport.Request] (AgentManager-Han= dler-13:null) Seq 1-1681129512: Processing: { Ans: , MgmtId: 7332683579487= , via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.Copy= CmdAnswer":{"result":false,"details":"unsupported protocol","wait":0}}] } > 2013-08-09 13:28:27,444 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Seq 1-1681129512: Recei= ved: { Ans: , MgmtId: 7332683579487, via: 1, Ver: v1, Flags: 10, { CopyCmd= Answer } } > 2013-08-09 13:28:27,462 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Seq 3-967704583: Sendin= g { Cmd , MgmtId: 7332683579487, via: 3, Ver: v1, Flags: 100011, [{"org.ap= ache.cloudstack.storage.command.DeleteCommand":{"data":{"org.apache.cloudst= ack.storage.to.SnapshotObjectTO":{"path":"snapshots/3/7","volume":{"uuid":"= 2b3fdf2f-579b-4771-8ac8-3d7ef2988a79","volumeType":"DATADISK","dataStore":{= "org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"c8c1d524-3f8= 8-4faa-9092-9ee37ac9e25e","id":1,"poolType":"Filesystem","host":"10.147.40.= 8","path":"/var/lib/libvirt/images","port":0}},"name":"DATA-5","size":53687= 09120,"path":"98700ea8-2e2f-4cac-bb10-fb6c6bb11032","volumeId":7,"vmName":"= i-3-5-VM","accountId":3,"format":"QCOW2","id":7,"hypervisorType":"KVM"},"da= taStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.147.28.7/export/= home/sanjeev/sec_kvm_os","_role":"ImageCache"}},"vmName":"i-3-5-VM","name":= "test-vm_DATA-5_20130809172825","hypervisorType":"KVM","id":3}},"wait":0}}]= } > 2013-08-09 13:28:27,784 DEBUG [agent.manager.AgentManagerImpl] (AgentMana= ger-Handler-12:null) SeqA 2-354: Processing Seq 2-354: { Cmd , MgmtId: -1,= via: 2, Ver: v1, Flags: 11, [{"com.cloud.agent.api.ConsoleProxyLoadReportC= ommand":{"_proxyVmId":2,"_loadInfo":"{\n \"connections\": [\n {\n = \"id\": 2,\n \"clientInfo\": \"\",\n \"host\": \"10.147.40.8\",\n= \"port\": 5905,\n \"tag\": \"5084fb7b-0113-4574-85e5-f85618a97a0= 4\",\n \"createTime\": 1376049502150,\n \"lastUsedTime\": 1376049= 608916\n }\n ]\n}","wait":0}}] } > 2013-08-09 13:28:27,798 DEBUG [agent.manager.AgentManagerImpl] (AgentMana= ger-Handler-12:null) SeqA 2-354: Sending Seq 2-354: { Ans: , MgmtId: 73326= 83579487, via: 2, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.AgentContr= olAnswer":{"result":true,"wait":0}}] } > 2013-08-09 13:28:27,905 DEBUG [agent.transport.Request] (AgentManager-Han= dler-14:null) Seq 3-967704583: Processing: { Ans: , MgmtId: 7332683579487,= via: 3, Ver: v1, Flags: 10, [{"com.cloud.agent.api.Answer":{"result":false= ,"details":"snapshot directory 3 doesn't exist","wait":0}}] } > 2013-08-09 13:28:27,906 DEBUG [agent.transport.Request] (Job-Executor-2:j= ob-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Seq 3-967704583: Receiv= ed: { Ans: , MgmtId: 7332683579487, via: 3, Ver: v1, Flags: 10, { Answer }= } > 2013-08-09 13:28:27,940 DEBUG [storage.snapshot.SnapshotManagerImpl] (Job= -Executor-2:job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Failed to = create snapshot > com.cloud.utils.exception.CloudRuntimeException: unsupported protocol > at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.bac= kupSnapshot(SnapshotServiceImpl.java:286) > at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrate= gy.backupSnapshot(XenserverSnapshotStrategy.java:137) > at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrate= gy.takeSnapshot(XenserverSnapshotStrategy.java:256) > at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(Sn= apshotManagerImpl.java:1004) > at org.apache.cloudstack.storage.volume.VolumeServiceImpl.takeSna= pshot(VolumeServiceImpl.java:1256) > at com.cloud.storage.VolumeManagerImpl.takeSnapshot(VolumeManager= Impl.java:2674) > at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshot= Cmd.execute(CreateSnapshotCmd.java:170) > 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(ThreadPoolEx= ecutor.java:1146) > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolE= xecutor.java:615) > at java.lang.Thread.run(Thread.java:679) > 2013-08-09 13:28:27,954 DEBUG [storage.volume.VolumeServiceImpl] (Job-Exe= cutor-2:job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Take snapshot:= 7 failed: com.cloud.utils.exception.CloudRuntimeException: Failed to creat= e snapshot > 2013-08-09 13:28:27,955 DEBUG [cloud.server.StatsCollector] (StatsCollect= or-2:null) VmStatsCollector is running... > 2013-08-09 13:28:27,984 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Exec= utor-2:job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ]) Complete async = job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ], jobStatus: 2, resultCo= de: 530, result: Error Code: 530 Error text: Failed to create snapshot due = to an internal error creating snapshot for volume 7 > 2013-08-09 13:28:28,221 DEBUG [cloud.server.StatsCollector] (StatsCollect= or-1:null) HostStatsCollector is running... > 2013-08-09 13:28:28,702 DEBUG [agent.transport.Request] (StatsCollector-2= :null) Seq 1-1681129513: Received: { Ans: , MgmtId: 7332683579487, via: 1,= Ver: v1, Flags: 10, { GetVmStatsAnswer } } > 2013-08-09 13:28:28,775 DEBUG [agent.transport.Request] (StatsCollector-1= :null) Seq 1-1681129514: Received: { Ans: , MgmtId: 7332683579487, via: 1,= Ver: v1, Flags: 10, { GetHostStatsAnswer } } > 2013-08-09 13:28:29,045 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:nu= ll) =3D=3D=3DSTART=3D=3D=3D 10.146.0.20 -- GET command=3DqueryAsyncJobRes= ult&jobId=3D0c5003b9-e341-46c4-b58f-c9181a7ccba1&response=3Djson&sessionkey= =3DzXXHX4Nf5yJtILkB4BA8E75f9HA%3D&_=3D1376049619735 > 2013-08-09 13:28:29,065 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina= -exec-24:null) Async job-17 =3D [ 0c5003b9-e341-46c4-b58f-c9181a7ccba1 ] co= mpleted > 2013-08-09 13:28:29,075 DEBUG [cloud.api.ApiServlet] (catalina-exec-24:nu= ll) =3D=3D=3DEND=3D=3D=3D 10.146.0.20 -- GET command=3DqueryAsyncJobResul= t&jobId=3D0c5003b9-e341-46c4-b58f-c9181a7ccba1&response=3Djson&sessionkey= =3DzXXHX4Nf5yJtILkB4BA8E75f9HA%3D&_=3D1376049619735 > 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 administrato= rs For more information on JIRA, see: http://www.atlassian.com/software/jira