I also tried to reproduce this bug in my setup again and I am also not able to reproduce it.
All the snapshot is successfully backed up . So making this bug as invalid and closing it. I'll reopen this issue if I faced it again . Thanks -----Original Message----- From: Chandan Purushothama (JIRA) [mailto:j...@apache.org] Sent: Friday, September 21, 2012 6:34 AM To: cloudstack-dev@incubator.apache.org Subject: [jira] [Commented] (CLOUDSTACK-83) hitting exception when trying to take two consecutive snapshot on same volume [ https://issues.apache.org/jira/browse/CLOUDSTACK-83?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13460108#comment-13460108 ] Chandan Purushothama commented on CLOUDSTACK-83: ------------------------------------------------ I am unable to reproduce this bug on my setup. I tried it on a freshly deployed VM (CentOS 5.6) with ntp server installed on it. My Setup is at 10.223.195.103. I tried on two other volumes too. Let me know if I need to check anything else, Secondary Storage Used in the Setup is a Linux Server: [root@nfs2 ~]# cat /etc/redhat-release CentOS release 5.6 (Final) [root@nfs2 ~]# ======= Git Info: ======= Git Revision: 54f9af1695bc359b02e9fc906b3b335cc0bfec41 Git URL: https://git-wip-us.apache.org/repos/asf/incubator-cloudstack.git > hitting exception when trying to take two consecutive snapshot on same > volume > ---------------------------------------------------------------------- > ------- > > Key: CLOUDSTACK-83 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-83 > Project: CloudStack > Issue Type: Bug > Components: Snapshot > Affects Versions: pre-4.0.0 > Environment: Git Revision: > 03df2fa9dd45c938f72cd1866044b09d1b0cc978 > Git URL: https://git-wip-us.apache.org/repos/asf/incubator-cloudstack.git > Reporter: shweta agarwal > Assignee: Anthony Xu > Priority: Blocker > Fix For: pre-4.0.0 > > Attachments: management-server.log.2012-09-12.gz > > > create a VM > Create a snapshot of its root volume > Once the snapshot is backedup try to take one more snapshot of same > volume Actual result: > Gets message Failed to back up snapshot on secondary storage MS log > shows : > 2012-09-12 15:16:47,338 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-18:null) submit async job-129, details: AsyncJobVO > {id:129, userId: 2, accountId: 2, sessionKey: null, instanceType: > Snapshot, instanceId: 20, cmd: > com.cloud.api.commands.CreateSnapshotCmd, cmdOriginator: null, > cmdInfo: > {"id":"20","response":"json","sessionkey":"h4CS2hXNWB/Djj6oc7EqZua14sg > \u003d","ctxUserId":"2","_":"1347443206549","volumeid":"8d62449d-b03c- > 4f27-8c14-9f2e1f2c1cea","ctxAccountId":"2","ctxStartEventId":"446"}, > cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, > processStatus: 0, resultCode: 0, result: null, initMsid: > 59793358248320, completeMsid: null, lastUpdated: null, lastPolled: > null, created: null} > 2012-09-12 15:16:47,339 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-32:job-129) Executing > com.cloud.api.commands.CreateSnapshotCmd for job-129 > 2012-09-12 15:16:47,382 DEBUG [agent.transport.Request] > (Job-Executor-32:job-129) Seq 2-1053884821: Sending { Cmd , MgmtId: > 59793358248320, via: 2, Ver: v1, Flags: 100011, > [{"ManageSnapshotCommand":{"_commandSwitch":"-c","_volumePath":"5728f1 > d8-e898-4c27-a698-c3108fafc580","_pool":{"id":200,"uuid":"6ce86454-a33 > f-3551-a1df-bf9cf191dded","host":"10.147.28.7","path":"/export/home/sh > weta/asfprimary","port":2049,"type":"NetworkFilesystem"},"_snapshotPat > h":"8522d3f9-353a-422e-8f4c-b9e9772c47f8","_snapshotName":"cent-snap_R > OOT-16_20120912094647","_snapshotId":20,"_vmName":"i-2-16-VM","wait":0 > }}] } > 2012-09-12 15:16:47,383 DEBUG [agent.transport.Request] > (Job-Executor-32:job-129) Seq 2-1053884821: Executing: { Cmd , > MgmtId: 59793358248320, via: 2, Ver: v1, Flags: 100011, > [{"ManageSnapshotCommand":{"_commandSwitch":"-c","_volumePath":"5728f1 > d8-e898-4c27-a698-c3108fafc580","_pool":{"id":200,"uuid":"6ce86454-a33 > f-3551-a1df-bf9cf191dded","host":"10.147.28.7","path":"/export/home/sh > weta/asfprimary","port":2049,"type":"NetworkFilesystem"},"_snapshotPat > h":"8522d3f9-353a-422e-8f4c-b9e9772c47f8","_snapshotName":"cent-snap_R > OOT-16_20120912094647","_snapshotId":20,"_vmName":"i-2-16-VM","wait":0 > }}] } > 2012-09-12 15:16:47,383 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-284:null) Seq 2-1053884821: Executing request > 2012-09-12 15:16:49,425 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-284:null) Seq 2-1053884821: Response Received: > 2012-09-12 15:16:49,426 DEBUG [agent.transport.Request] > (DirectAgent-284:null) Seq 2-1053884821: Processing: { Ans: , MgmtId: > 59793358248320, via: 2, Ver: v1, Flags: 10, > [{"ManageSnapshotAnswer":{"_snapshotPath":"60da197d-3de9-4eb6-8a4c-903 > 2003c45a6","result":true,"wait":0}}] } > 2012-09-12 15:16:49,426 DEBUG [agent.transport.Request] > (Job-Executor-32:job-129) Seq 2-1053884821: Received: { Ans: , > MgmtId: 59793358248320, via: 2, Ver: v1, Flags: 10, { > ManageSnapshotAnswer } } > 2012-09-12 15:16:49,469 DEBUG [agent.transport.Request] > (Job-Executor-32:job-129) Seq 2-1053884822: Sending { Cmd , MgmtId: > 59793358248320, via: 2, Ver: v1, Flags: 100011, > [{"BackupSnapshotCommand":{"prevSnapshotUuid":"8522d3f9-353a-422e-8f4c > -b9e9772c47f8","prevBackupUuid":"a030a6af-9663-461c-b746-8a7a814d9694" > ,"isVolumeInactive":false,"vmName":"i-2-16-VM","snapshotId":20,"pool": > {"id":200,"uuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","host":"10.147 > .28.7","path":"/export/home/shweta/asfprimary","port":2049,"type":"Net > workFilesystem"},"primaryStoragePoolNameLabel":"6ce86454-a33f-3551-a1d > f-bf9cf191dded","snapshotUuid":"60da197d-3de9-4eb6-8a4c-9032003c45a6", > "snapshotName":"cent-snap_ROOT-16_20120912094647","secondaryStorageUrl > ":"nfs://10.147.28.7/export/home/shweta/asfsecondary","dcId":1,"accoun > tId":2,"volumeId":26,"volumePath":"5728f1d8-e898-4c27-a698-c3108fafc58 > 0","wait":21600}}] } > 2012-09-12 15:16:49,470 DEBUG [agent.transport.Request] > (Job-Executor-32:job-129) Seq 2-1053884822: Executing: { Cmd , > MgmtId: 59793358248320, via: 2, Ver: v1, Flags: 100011, > [{"BackupSnapshotCommand":{"prevSnapshotUuid":"8522d3f9-353a-422e-8f4c > -b9e9772c47f8","prevBackupUuid":"a030a6af-9663-461c-b746-8a7a814d9694" > ,"isVolumeInactive":false,"vmName":"i-2-16-VM","snapshotId":20,"pool": > {"id":200,"uuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","host":"10.147 > .28.7","path":"/export/home/shweta/asfprimary","port":2049,"type":"Net > workFilesystem"},"primaryStoragePoolNameLabel":"6ce86454-a33f-3551-a1d > f-bf9cf191dded","snapshotUuid":"60da197d-3de9-4eb6-8a4c-9032003c45a6", > "snapshotName":"cent-snap_ROOT-16_20120912094647","secondaryStorageUrl > ":"nfs://10.147.28.7/export/home/shweta/asfsecondary","dcId":1,"accoun > tId":2,"volumeId":26,"volumePath":"5728f1d8-e898-4c27-a698-c3108fafc58 > 0","wait":21600}}] } > 2012-09-12 15:16:49,470 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-79:null) Seq 2-1053884822: Executing request > 2012-09-12 15:16:50,893 DEBUG [cloud.server.StatsCollector] > (StatsCollector-3:null) VmStatsCollector is running... > 2012-09-12 15:16:50,912 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-211:null) Seq 2-1053884823: Executing request > 2012-09-12 15:16:51,130 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-211:null) Vm cpu utilization 0.16 > 2012-09-12 15:16:51,130 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-211:null) Vm cpu utilization 0.83 > 2012-09-12 15:16:51,130 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-211:null) Seq 2-1053884823: Response Received: > 2012-09-12 15:16:51,130 DEBUG [agent.transport.Request] > (StatsCollector-3:null) Seq 2-1053884823: Received: { Ans: , MgmtId: > 59793358248320, via: 2, Ver: v1, Flags: 10, { GetVmStatsAnswer } } > 2012-09-12 15:16:53,079 WARN [xen.resource.CitrixResourceBase] > (DirectAgent-79:null) Task failed! Task record: uuid: > ef4ca152-46a8-cba7-9c45-e1f0038cf51a > nameLabel: Async.host.call_plugin > nameDescription: > allowedOperations: [] > currentOperations: {} > created: Wed Sep 12 15:16:50 IST 2012 > finished: Wed Sep 12 15:16:52 IST 2012 > status: FAILURE > residentOn: com.xensource.xenapi.Host@63abd2e5 > progress: 1.0 > type: <none/> > result: > errorInfo: [XENAPI_PLUGIN_FAILURE, backupSnapshot, SROSError, > Error reporting error, unknown key Unexpected error while trying to set > parent of > /var/run/cloud_mount/1/snapshots/2/26/ca5d6199-1541-4443-b48f-de88f5ca8a15.vhd > to > /var/run/cloud_mount/1/snapshots/2/26/a030a6af-9663-461c-b746-8a7a814d9694.vhd] > otherConfig: {} > subtaskOf: com.xensource.xenapi.Task@aaf13f6f > subtasks: [] > 2012-09-12 15:16:53,088 WARN [xen.resource.CitrixResourceBase] > (DirectAgent-79:null) callHostPlugin failed for cmd: backupSnapshot with args > dcId: 1, secondaryStorageMountPath: > 10.147.28.7:/export/home/shweta/asfsecondary, accountId: 2, volumeId: 26, > backupUuid: ca5d6199-1541-4443-b48f-de88f5ca8a15, prevBackupUuid: > a030a6af-9663-461c-b746-8a7a814d9694, snapshotUuid: > 60da197d-3de9-4eb6-8a4c-9032003c45a6, isISCSI: false, primaryStorageSRUuid: > f7ab128c-9c49-cce6-1a5b-c53feccba16f, due to Task failed! Task record: > uuid: ef4ca152-46a8-cba7-9c45-e1f0038cf51a > nameLabel: Async.host.call_plugin > nameDescription: > allowedOperations: [] > currentOperations: {} > created: Wed Sep 12 15:16:50 IST 2012 > finished: Wed Sep 12 15:16:52 IST 2012 > status: FAILURE > residentOn: com.xensource.xenapi.Host@63abd2e5 > progress: 1.0 > type: <none/> > result: > errorInfo: [XENAPI_PLUGIN_FAILURE, backupSnapshot, SROSError, > Error reporting error, unknown key Unexpected error while trying to set > parent of > /var/run/cloud_mount/1/snapshots/2/26/ca5d6199-1541-4443-b48f-de88f5ca8a15.vhd > to > /var/run/cloud_mount/1/snapshots/2/26/a030a6af-9663-461c-b746-8a7a814d9694.vhd] > otherConfig: {} > subtaskOf: com.xensource.xenapi.Task@aaf13f6f > subtasks: [] > Task failed! Task record: uuid: > ef4ca152-46a8-cba7-9c45-e1f0038cf51a > nameLabel: Async.host.call_plugin > nameDescription: > allowedOperations: [] > currentOperations: {} > created: Wed Sep 12 15:16:50 IST 2012 > finished: Wed Sep 12 15:16:52 IST 2012 > status: FAILURE > residentOn: com.xensource.xenapi.Host@63abd2e5 > progress: 1.0 > type: <none/> > result: > errorInfo: [XENAPI_PLUGIN_FAILURE, backupSnapshot, SROSError, > Error reporting error, unknown key Unexpected error while trying to set > parent of > /var/run/cloud_mount/1/snapshots/2/26/ca5d6199-1541-4443-b48f-de88f5ca8a15.vhd > to > /var/run/cloud_mount/1/snapshots/2/26/a030a6af-9663-461c-b746-8a7a814d9694.vhd] > otherConfig: {} > subtaskOf: com.xensource.xenapi.Task@aaf13f6f > subtasks: [] > at > com.cloud.hypervisor.xen.resource.CitrixResourceBase.checkForSuccess(CitrixResourceBase.java:3146) > at > com.cloud.hypervisor.xen.resource.CitrixResourceBase.callHostPluginAsync(CitrixResourceBase.java:3459) > at > com.cloud.hypervisor.xen.resource.CitrixResourceBase.backupSnapshot(CitrixResourceBase.java:3410) > at > com.cloud.hypervisor.xen.resource.CitrixResourceBase.execute(CitrixResourceBase.java:6532) > at > com.cloud.hypervisor.xen.resource.CitrixResourceBase.executeRequest(CitrixResourceBase.java:469) > at > com.cloud.hypervisor.xen.resource.XenServer56Resource.executeRequest(XenServer56Resource.java:73) > at > com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:191) > 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) > 2012-09-12 15:16:54,137 WARN [xen.resource.CitrixResourceBase] > (DirectAgent-79:null) Could not copy backupUuid: null of volumeId: 26 > from primary storage f7ab128c-9c49-cce6-1a5b-c53feccba16f to secondary > storage 10.147.28.7:/export/home/shweta/asfsecondary due to null > 2012-09-12 15:16:54,149 DEBUG [xen.resource.CitrixResourceBase] > (DirectAgent-79:null) Successfully destroyed snapshot on volume: > 5728f1d8-e898-4c27-a698-c3108fafc580 execept this current snapshot > 60da197d-3de9-4eb6-8a4c-9032003c45a6 > 2012-09-12 15:16:54,149 DEBUG [agent.manager.DirectAgentAttache] > (DirectAgent-79:null) Seq 2-1053884822: Response Received: > 2012-09-12 15:16:54,150 DEBUG [agent.transport.Request] > (DirectAgent-79:null) Seq 2-1053884822: Processing: { Ans: , MgmtId: > 59793358248320, via: 2, Ver: v1, Flags: 10, > [{"BackupSnapshotAnswer":{"full":false,"result":false,"wait":0}}] } > 2012-09-12 15:16:54,150 DEBUG [agent.transport.Request] > (Job-Executor-32:job-129) Seq 2-1053884822: Received: { Ans: , MgmtId: > 59793358248320, via: 2, Ver: v1, Flags: 10, { BackupSnapshotAnswer } } > @ > 2012-09-12 15:18:54,153 WARN [storage.snapshot.SnapshotManagerImpl] > (Job-Executor-32:job-129) Storage unavailable > com.cloud.exception.StorageUnavailableException: Resource [StoragePool:200] > is unreachable: Unable to send command to the pool 200 due to there is no > enabled hosts up in this cluster > at > com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2190) > at > com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2215) > at > com.cloud.storage.snapshot.SnapshotManagerImpl.sendToPool(SnapshotManagerImpl.java:256) > at > com.cloud.storage.snapshot.SnapshotManagerImpl.backupSnapshotToSecondaryStorage(SnapshotManagerImpl.java:654) > at > com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34) > at > com.cloud.storage.snapshot.SnapshotManagerImpl.createSnapshot(SnapshotManagerImpl.java:463) > at > com.cloud.utils.component.ComponentLocator$InterceptorDispatcher.intercept(ComponentLocator.java:1231) > at > com.cloud.storage.snapshot.SnapshotManagerImpl.createSnapshot(SnapshotManagerImpl.java:130) > at > com.cloud.api.commands.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:155) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138) > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:449) > 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) > 2012-09-12 15:18:54,154 WARN [storage.snapshot.SnapshotManagerImpl] > (Job-Executor-32:job-129) Failed to back up snapshot on secondary > storage, deleting the record from the DB > 2012-09-12 15:18:54,182 ERROR [cloud.api.ApiDispatcher] > (Job-Executor-32:job-129) Exception while executing CreateSnapshotCmd: > com.cloud.utils.exception.CloudRuntimeException: Created snapshot: > com.cloud.storage.SnapshotVO$$EnhancerByCGLIB$$7b65b9ee@10fc2cb on primary > but failed to backup on secondary > at > com.cloud.storage.snapshot.SnapshotManagerImpl.createSnapshot(SnapshotManagerImpl.java:475) > at > com.cloud.utils.component.ComponentLocator$InterceptorDispatcher.intercept(ComponentLocator.java:1231) > at > com.cloud.storage.snapshot.SnapshotManagerImpl.createSnapshot(SnapshotManagerImpl.java:130) > at > com.cloud.api.commands.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:155) > at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138) > at > com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:449) > 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) > 2012-09-12 15:18:54,183 DEBUG [cloud.async.AsyncJobManagerImpl] > (Job-Executor-32:job-129) Complete async job-129, jobStatus: 2, > resultCode: 530, result: Error Code: 530 Error text: Created snapshot: > com.cloud.storage.SnapshotVO$$EnhancerByCGLIB$$7b65b9ee@10fc2cb on > primary but failed to backup on secondary > 2012-09-12 15:18:57,804 DEBUG [cloud.async.AsyncJobManagerImpl] > (catalina-exec-16:null) Async job-129 completed > > Expected result: > Snapshot creation should be successful Additional information . > I have checked on secondary storage that the particular snapshot id exists > in follwing location which xen host complains of not finding > "snapshots/2/26/a030a6af-9663-461c-b746-8a7a814d9694.vhd " -- 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
