[ https://issues.apache.org/jira/browse/CLOUDSTACK-83?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13460094#comment-13460094 ]
Anthony Xu commented on CLOUDSTACK-83: -------------------------------------- can ping secondary storage 10.147.28.7, but cannot ssh or mount. is 10.147.28.7 a linux nfs server or NFS appliance? if it is NFS appliacne, can you change to Linux NFS server? then we can avoid issue caused by NFS appliance configuration. US qa tries reproducing the issue now. > 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":"5728f1d8-e898-4c27-a698-c3108fafc580","_pool":{"id":200,"uuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","host":"10.147.28.7","path":"/export/home/shweta/asfprimary","port":2049,"type":"NetworkFilesystem"},"_snapshotPath":"8522d3f9-353a-422e-8f4c-b9e9772c47f8","_snapshotName":"cent-snap_ROOT-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":"5728f1d8-e898-4c27-a698-c3108fafc580","_pool":{"id":200,"uuid":"6ce86454-a33f-3551-a1df-bf9cf191dded","host":"10.147.28.7","path":"/export/home/shweta/asfprimary","port":2049,"type":"NetworkFilesystem"},"_snapshotPath":"8522d3f9-353a-422e-8f4c-b9e9772c47f8","_snapshotName":"cent-snap_ROOT-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-9032003c45a6","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":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"6ce86454-a33f-3551-a1df-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,"accountId":2,"volumeId":26,"volumePath":"5728f1d8-e898-4c27-a698-c3108fafc580","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":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"6ce86454-a33f-3551-a1df-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,"accountId":2,"volumeId":26,"volumePath":"5728f1d8-e898-4c27-a698-c3108fafc580","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