[
https://issues.apache.org/jira/browse/CLOUDSTACK-692?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13769529#comment-13769529
]
Joris van Lieshout commented on CLOUDSTACK-692:
-----------------------------------------------
How to clean up on XenServer after you have hit this bug:
1. Find the sparse_dd process
ps -ef | grep sparse_dd
2. Find the vbd of the destination sparse_dd device
xe vbd-list device=${dest device f.i. xvbd} vm-uuid=${UUID of Dom0}
3. Find tapdisk2 process for this vbd
xe vbd-param-get uuid=${UUID VBD step2} param-name=vdi-uuid
tap-ctl list | grep ${uuid of VDI}
ls ${path of vhd from tap-ctl list}
4. Also get the uuid and name of the SR for later use
xe vdi-param-get uuid=${ uuid of VDI } param-name=sr-uuid
xe vdi-param-get uuid=${ uuid of VDI } param-name=sr-name-label
5. !!!!ONLY continue if the vhd does not exist!!!!
6. Create a dummy file to make the cleanup process go smooth
touch ${path of vhd from tap-ctl list but with .raw instead of .vhd}
7. Kill the sparse_dd process
kill -9 ${PID of sparse_dd process step 1}
8. !!! It can take up to 10 minutes for this process to be killed. Only
continue when the process is gone !!!
ps –ef | grep ${PID of sparse_dd process step 1}
9. Close, detach and free the tapdisk2 process. Get your info from the
previous tap-ctl list
tap-ctl close -m ${TAPMINOR} -p ${TAPPID}
tap-ctl detach -m ${TAPMINOR} -p ${TAPPID}
tap-ctl free -m ${TAPMINOR}
10. Now unplug the vbd but put it in background because the process
sometimes hangs
xe vbd-unplug uuid=${uuid of VBD} &
11. If the vbd unplug hangs check in /var/log/xensource.log to see if it
hangs on “watching xenstore paths: [
/local/domain/0/backend/vbd/0/51712/shutdown-done;
/local/domain/0/error/device/vbd/51712/error ] with timeout 1200.000000
seconds” by searching for the last line containing VBD.unplug. If so, AND ONLY
IF SO, execute:
xenstore-write /local/domain/0/backend/vbd/0/${get this from the
xensourse.log}/shutdown-done Ok
12. It’s now safe to forget all the vdi’s and unplug the pbd and forget the
sr. The script below will also do it for stuff on other HVs in the cluster if
CS has tried snapshotting there.
DESTSRs=`xe sr-list name-label=${name-label of sr (looks like uuid) from step
4, not the uuid of the sr.} --minimal | tr "," "\n"`
for SRloop in $DESTSRs
do
PBD=`xe sr-param-get uuid=$SRloop param-name=PBDs`
VDIs=`xe sr-param-get uuid=$SRloop param-name=VDIs | sed 's/;\ */\n/g'`
for VDIloop in $VDIs
do
echo " Forgetting VDI $VDIloop"
xe vdi-forget uuid=$VDIloop
done
echo " Unplugging PBD $PBD"
xe pbd-unplug uuid=$PBD
echo " Forgetting SR $SRloop"
xe sr-forget uuid=$SRloop
done
13. And now everything is ready for another snapshot attempt. Let’s hope
the Storage Cleanup process keeps its cool. ;)
> The StorageManager-Scavenger deletes snapshots that are still in the process
> of being created.
> ----------------------------------------------------------------------------------------------
>
> Key: CLOUDSTACK-692
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-692
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Snapshot
> Reporter: Joris van Lieshout
> Priority: Minor
>
> Hi there,
> I think we ran into a bug due to a concurrence of circumstances regarding
> snapshotting and the cleanup of snapshots.
> The CleanupSnapshotBackup process on the SSVM deletes vhd files that are not
> known in the database but when, especially long running snapshot, are being
> copied to secondary storeage there is a gap between the start and finish of
> the VDI-copy, where the uuid of the destination vhd is not registered in the
> database. If the CleanupSnapshotBackup deletes the destinaion vhd during this
> window it results in hanging sparse_dd process on the XenServer hypervisor
> pointing to a tapdisk2 process with no file behind it.
> ===Secondary storage vm (2 hour time difference due to time zone). second to
> last line you see the vhd being deleted.
> 2013-09-04 03:14:45,721 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:)
> Request:Seq 261-1870805144: { Cmd , MgmtId: 345052370018, via: 261, Ver: v1,
> Flags: 100011,
> [{"CleanupSnapshotBackupCommand":{"secondaryStoragePoolURL":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"validBackupUUIDs":["1a56760b-d1c0-4620-8cf7-271951500d70","b6157bc9-085b-4ed6-95c2-4341f31c64bf","1ff967e3-3606-4112-9155-b1145b2ef576","12fbe4e3-1fdd-4c35-a961-0fce07cff584","278e9915-4f94-40c8-bef4-9c6bc82d4653","6fba1dd7-4736-47b3-9eed-148304c0e192","b9d8c9d8-6445-463b-b4e1-ab3b3f3a67a2","40ba5d72-c69a-46c2-973b-0570c1cabeac","774f2b0e-cdaf-4594-a9f9-4f872dcaad6e","8269f50b-6bec-427c-8186-540df6a75dbf","7b0c6e75-40cf-4dd7-826a-09b39f3da7b5","df7eac9c-137a-4655-9d21-d781916351f1","11ec2db1-a2fc-4221-ae1a-c1ab2bd59509","dfc348e1-af50-4d77-b4a0-6e86fc954e1c","98f64c0f-7498-4c70-8b70-beaefd723b45","c42f9dd5-079d-4b77-86dc-c19b7fbed817"],"wait":0}}]
> }
> 2013-09-04 03:14:45,722 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:)
> Processing command: com.cloud.agent.api.CleanupSnapshotBackupCommand
> 2013-09-04 03:14:45,723 DEBUG [storage.resource.NfsSecondaryStorageResource]
> (agentRequest-Handler-2:) Executing: mount
> 2013-09-04 03:14:45,732 DEBUG [storage.resource.NfsSecondaryStorageResource]
> (agentRequest-Handler-2:) Execution is successful.
> 2013-09-04 03:14:45,772 WARN [storage.resource.NfsSecondaryStorageResource]
> (agentRequest-Handler-2:) snapshot 8ca9fea4-8a98-4cc3-bba7-cc1dcf32bb24.vhd
> is not recorded in DB, remove it
> 2013-09-04 03:14:45,772 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:)
> Seq 261-1870805144: { Ans: , MgmtId: 345052370018, via: 261, Ver: v1, Flags:
> 10, [{"Answer":{"result":true,"wait":0}}] }
> ==== management-server.log. here you see the snapshot being created, the
> copyToSecStorage process starting, eventually timing out due to the hanging
> vdi-copy, failing on retrying because vdi in use (although not existing any
> more the vdi is still know on xen), retrying some more on another HV and
> eventuall giving up because it tries to create a duplicate SR.
> 2013-09-04 04:27:10,931 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-69:job-95137) Executing
> com.cloud.api.commands.CreateSnapshotCmd for job-95137
> 2013-09-04 04:27:10,971 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 91-780303147: Sending { Cmd , MgmtId:
> 345052370017, via: 91, Ver: v1, Flags: 100011,
> [{"ManageSnapshotCommand":{"_commandSwitch":"-c","_volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","_pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"_snapshotName":"vlstws3_ROOT-2736_20130904022710","_snapshotId":71889,"_vmName":"i-45-2736-VM","wait":0}}]
> }
> 2013-09-04 04:27:10,971 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 91-780303147: Executing: { Cmd , MgmtId:
> 345052370017, via: 91, Ver: v1, Flags: 100011,
> [{"ManageSnapshotCommand":{"_commandSwitch":"-c","_volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","_pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"_snapshotName":"vlstws3_ROOT-2736_20130904022710","_snapshotId":71889,"_vmName":"i-45-2736-VM","wait":0}}]
> }
> 2013-09-04 04:27:12,949 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 91-780303147: Received: { Ans: , MgmtId:
> 345052370017, via: 91, Ver: v1, Flags: 10, { ManageSnapshotAnswer } }
> 2013-09-04 04:27:12,991 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 91-780303148: Sending { Cmd , MgmtId:
> 345052370017, via: 91, Ver: v1, Flags: 100011,
> [{"BackupSnapshotCommand":{"isVolumeInactive":false,"vmName":"i-45-2736-VM","snapshotId":71889,"pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"b290385b-466d-3243-a939-3d242164e034","snapshotUuid":"6396ec81-4128-44ca-a121-d9f1bf789d6c","snapshotName":"vlstws3_ROOT-2736_20130904022710","secondaryStorageUrl":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","wait":21600}}]
> }
> 2013-09-04 04:27:12,991 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 91-780303148: Executing: { Cmd , MgmtId:
> 345052370017, via: 91, Ver: v1, Flags: 100011,
> [{"BackupSnapshotCommand":{"isVolumeInactive":false,"vmName":"i-45-2736-VM","snapshotId":71889,"pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"b290385b-466d-3243-a939-3d242164e034","snapshotUuid":"6396ec81-4128-44ca-a121-d9f1bf789d6c","snapshotName":"vlstws3_ROOT-2736_20130904022710","secondaryStorageUrl":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","wait":21600}}]
> }
> 2013-09-04 04:27:12,992 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 91-780303148: Executing request
> 2013-09-04 04:27:13,561 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Creating a not shared SR for
> nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1/snapshots/45/5863
> 2013-09-04 04:27:14,499 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Checking 00e04f60-4c80-37e4-9abe-855b16fbc9e1 or SR
> a4ca3b8c-6e6d-5f07-cb71-f6c9b7f950cb on
> XS[d868bf32-d747-4ec0-b1c2-fba3df1c85bd-192.168.52.15]
> 2013-09-04 04:27:14,512 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Host 192.168.52.15
> OpaqueRef:5ee9850b-b15c-b39b-dd27-ff226a1b3126: Created a SR; UUID is
> a4ca3b8c-6e6d-5f07-cb71-f6c9b7f950cb device config is
> {serverpath=/volumes/pool0/MCCP-SHARED-1-1/snapshots/45/5863,
> server=mccpnas7.storage.mccp.mcinfra.net}
> 2013-09-04 10:27:12,992 DEBUG [agent.manager.AgentAttache]
> (Job-Executor-69:job-95137) Seq 91-780303148: Waiting some more time because
> this is the current command
> 2013-09-04 10:27:34,262 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Async 21600 seconds timeout for task
> com.xensource.xenapi.Task@ec1aac0e
> 2013-09-04 10:27:34,585 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Host 192.168.52.15
> OpaqueRef:5ee9850b-b15c-b39b-dd27-ff226a1b3126: Removing SR
> 2013-09-04 10:27:34,624 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Host 192.168.52.15
> OpaqueRef:5ee9850b-b15c-b39b-dd27-ff226a1b3126: Catch XenAPIException: This
> operation cannot be performed because this VDI is in use by some other
> operation
> 2013-09-04 10:27:34,650 DEBUG [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Host 192.168.52.15
> OpaqueRef:5ee9850b-b15c-b39b-dd27-ff226a1b3126: Catch XenAPIException: This
> operation cannot be performed because this VDI is in use by some other
> operation
> 2013-09-04 10:27:34,650 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) Host 192.168.52.15
> OpaqueRef:5ee9850b-b15c-b39b-dd27-ff226a1b3126: Unable to remove SR
> 2013-09-04 10:27:34,650 WARN [xen.resource.CitrixResourceBase]
> (DirectAgent-441:null) BackupSnapshot Failed due to Async 21600 seconds
> timeout for task com.xensource.xenapi.Task@ec1aac0e
> 2013-09-04 10:27:34,651 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 91-780303148: Response Received:
> 2013-09-04 10:27:34,651 DEBUG [agent.transport.Request]
> (DirectAgent-441:null) Seq 91-780303148: Processing: { Ans: , MgmtId:
> 345052370017, via: 91, Ver: v1, Flags: 10,
> [{"BackupSnapshotAnswer":{"full":true,"result":false,"details":"BackupSnapshot
> Failed due to Async 21600 seconds timeout for task
> com.xensource.xenapi.Task@ec1aac0e","wait":0}}] }
> 2013-09-04 10:27:34,651 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 91-780303148: Received: { Ans: , MgmtId:
> 345052370017, via: 91, Ver: v1, Flags: 10, { BackupSnapshotAnswer } }
> 2013-09-04 10:27:34,651 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) The result for
> com.cloud.agent.api.BackupSnapshotCommand is BackupSnapshot Failed due to
> Async 21600 seconds timeout for task com.xensource.xenapi.Task@ec1aac0e
> through 91
> 2013-09-04 10:29:34,652 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) Retrying...
> 2013-09-04 10:29:34,659 DEBUG [agent.manager.ClusteredAgentAttache]
> (Job-Executor-69:job-95137) Seq 89-1251159458: Forwarding Seq 89-1251159458:
> { Cmd , MgmtId: 345052370017, via: 89, Ver: v1, Flags: 100011,
> [{"BackupSnapshotCommand":{"isVolumeInactive":false,"vmName":"i-45-2736-VM","snapshotId":71889,"pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"b290385b-466d-3243-a939-3d242164e034","snapshotUuid":"6396ec81-4128-44ca-a121-d9f1bf789d6c","snapshotName":"vlstws3_ROOT-2736_20130904022710","secondaryStorageUrl":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","wait":21600}}]
> } to 345052370018
> 2013-09-04 10:29:43,085 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 89-1251159458: Received: { Ans: , MgmtId:
> 345052370017, via: 89, Ver: v1, Flags: 10, { BackupSnapshotAnswer } }
> 2013-09-04 10:29:43,086 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) The result for
> com.cloud.agent.api.BackupSnapshotCommand is BackupSnapshot Failed due to Can
> not create second storage SR mountpoint:
> mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1/snapshots/45/5863
> due to SR_BACKEND_FAILURE_40The SR scan failed [opterr=['INTERNAL_ERROR',
> 'Db_exn.Uniqueness_constraint_violation("VDI", "uuid",
> "df7eac9c-137a-4655-9d21-d781916351f1")']] through 89
> 2013-09-04 10:30:17,489 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Ping from 109
> 2013-09-04 10:31:18,345 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 95-1001324546: Executing request
> 2013-09-04 10:31:18,642 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 95-1001324546: Response Received:
> 2013-09-04 10:31:18,642 DEBUG [agent.transport.Request]
> (DirectAgent-441:null) Seq 95-1001324546: Processing: { Ans: , MgmtId:
> 345052370017, via: 95, Ver: v1, Flags: 10,
> [{"Answer":{"result":true,"wait":0}}] }
> 2013-09-04 10:31:19,423 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 41-1598291970: Executing request
> 2013-09-04 10:31:19,663 DEBUG [agent.manager.DirectAgentAttache]
> (DirectAgent-441:null) Seq 41-1598291970: Response Received:
> 2013-09-04 10:31:19,663 DEBUG [agent.transport.Request]
> (DirectAgent-441:null) Seq 41-1598291970: Processing: { Ans: , MgmtId:
> 345052370017, via: 41, Ver: v1, Flags: 10,
> [{"Answer":{"result":true,"wait":0}}] }
> 2013-09-04 10:31:43,086 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) Retrying...
> 2013-09-04 10:31:43,091 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 93-156960768: Sending { Cmd , MgmtId:
> 345052370017, via: 93, Ver: v1, Flags: 100011,
> [{"BackupSnapshotCommand":{"isVolumeInactive":false,"vmName":"i-45-2736-VM","snapshotId":71889,"pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"b290385b-466d-3243-a939-3d242164e034","snapshotUuid":"6396ec81-4128-44ca-a121-d9f1bf789d6c","snapshotName":"vlstws3_ROOT-2736_20130904022710","secondaryStorageUrl":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","wait":21600}}]
> }
> 2013-09-04 10:31:43,091 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 93-156960768: Executing: { Cmd , MgmtId:
> 345052370017, via: 93, Ver: v1, Flags: 100011,
> [{"BackupSnapshotCommand":{"isVolumeInactive":false,"vmName":"i-45-2736-VM","snapshotId":71889,"pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"b290385b-466d-3243-a939-3d242164e034","snapshotUuid":"6396ec81-4128-44ca-a121-d9f1bf789d6c","snapshotName":"vlstws3_ROOT-2736_20130904022710","secondaryStorageUrl":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","wait":21600}}]
> }
> 2013-09-04 10:31:56,375 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 93-156960768: Received: { Ans: , MgmtId:
> 345052370017, via: 93, Ver: v1, Flags: 10, { BackupSnapshotAnswer } }
> 2013-09-04 10:31:56,376 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) The result for
> com.cloud.agent.api.BackupSnapshotCommand is BackupSnapshot Failed due to Can
> not create second storage SR mountpoint:
> mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1/snapshots/45/5863
> due to SR_BACKEND_FAILURE_40The SR scan failed [opterr=['INTERNAL_ERROR',
> 'Db_exn.Uniqueness_constraint_violation("VDI", "uuid",
> "df7eac9c-137a-4655-9d21-d781916351f1")']] through 93
> 2013-09-04 10:33:56,376 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) Retrying...
> 2013-09-04 10:33:56,381 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 95-1001356346: Sending { Cmd , MgmtId:
> 345052370017, via: 95, Ver: v1, Flags: 100011,
> [{"BackupSnapshotCommand":{"isVolumeInactive":false,"vmName":"i-45-2736-VM","snapshotId":71889,"pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"b290385b-466d-3243-a939-3d242164e034","snapshotUuid":"6396ec81-4128-44ca-a121-d9f1bf789d6c","snapshotName":"vlstws3_ROOT-2736_20130904022710","secondaryStorageUrl":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","wait":21600}}]
> }
> 2013-09-04 10:33:56,381 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 95-1001356346: Executing: { Cmd , MgmtId:
> 345052370017, via: 95, Ver: v1, Flags: 100011,
> [{"BackupSnapshotCommand":{"isVolumeInactive":false,"vmName":"i-45-2736-VM","snapshotId":71889,"pool":{"id":208,"uuid":"b290385b-466d-3243-a939-3d242164e034","host":"mccpnas3-4-vip1.mccp.mcinfra.net","path":"/volumes/pool0/MCCP-S-SBP1-1_MCCP-XEN-1","port":2049,"type":"NetworkFilesystem"},"primaryStoragePoolNameLabel":"b290385b-466d-3243-a939-3d242164e034","snapshotUuid":"6396ec81-4128-44ca-a121-d9f1bf789d6c","snapshotName":"vlstws3_ROOT-2736_20130904022710","secondaryStorageUrl":"nfs://mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1","dcId":1,"accountId":45,"volumeId":5863,"volumePath":"9cb7af90-ca88-4b34-aa6f-bc21c3d4a3aa","wait":21600}}]
> }
> 2013-09-04 10:34:13,682 DEBUG [agent.transport.Request]
> (Job-Executor-69:job-95137) Seq 95-1001356346: Received: { Ans: , MgmtId:
> 345052370017, via: 95, Ver: v1, Flags: 10, { BackupSnapshotAnswer } }
> 2013-09-04 10:34:13,683 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) The result for
> com.cloud.agent.api.BackupSnapshotCommand is BackupSnapshot Failed due to Can
> not create second storage SR mountpoint:
> mccpnas7.storage.mccp.mcinfra.net/volumes/pool0/MCCP-SHARED-1-1/snapshots/45/5863
> due to SR_BACKEND_FAILURE_40The SR scan failed [opterr=['INTERNAL_ERROR',
> 'Db_exn.Uniqueness_constraint_violation("VDI", "uuid",
> "df7eac9c-137a-4655-9d21-d781916351f1")']] through 95
> 2013-09-04 10:36:13,683 DEBUG [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) Retrying...
> 2013-09-04 10:36:13,685 WARN [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) Storage unavailable
> 2013-09-04 10:36:13,685 WARN [storage.snapshot.SnapshotManagerImpl]
> (Job-Executor-69:job-95137) Failed to back up snapshot on secondary storage,
> deleting the record from the DB
> 2013-09-04 10:36:13,702 ERROR [cloud.api.ApiDispatcher]
> (Job-Executor-69:job-95137) Exception while executing CreateSnapshotCmd:
> 2013-09-04 10:36:13,702 DEBUG [cloud.async.AsyncJobManagerImpl]
> (Job-Executor-69:job-95137) Complete async job-95137, jobStatus: 2,
> resultCode: 530, result: Error Code: 530 Error text: Created snapshot:
> com.cloud.storage.SnapshotVO$$EnhancerByCGLIB$$3173e384@40abfe02 on primary
> but failed to backup on secondary
--
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
