incubator-cloudstack-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Devdeep Singh (JIRA)" <j...@apache.org>
Subject [jira] [Assigned] (CLOUDSTACK-83) hitting exception when trying to take two consecutive snapshot on same volume
Date Tue, 18 Sep 2012 05:36:07 GMT

     [ https://issues.apache.org/jira/browse/CLOUDSTACK-83?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Devdeep Singh reassigned CLOUDSTACK-83:
---------------------------------------

    Assignee: deepti dohare  (was: Devdeep Singh)

Assigning to Deepti, who is investigating the issue.
                
> 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: deepti dohare
>            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

Mime
View raw message