cloudstack-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "angeline shen (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CLOUDSTACK-4939) Failed to create snapshot (KVM, Multiple hosts, Sharedstorage)
Date Fri, 08 Nov 2013 20:33:19 GMT

    [ https://issues.apache.org/jira/browse/CLOUDSTACK-4939?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13817655#comment-13817655 ] 

angeline shen commented on CLOUDSTACK-4939:
-------------------------------------------

Verified  build  http://repo-ccp.citrix.com/releases/ASF/rhel/6.4/4.2/CloudPlatform-4.2.1-41-rhel6.4.tar.gz

MS      rhel6.4             10.223.50.3    
host     rhel6.4 kvm     10.223.51.3       10.223.51.4

1. advance zone.   Deploy  6 VMs  with some on each host.
2. Perform volume snapshot on ROOT volume of VM.
    snapshot requests should only be sent to the host where the  VM is deployed.

Test result  :

Host1     10.223.51.3          contains   i-2-5-VM                 i-2-6-VM        i-2-7-VM
Host2     10.223.51.4          contains   i-2-7-VM                 i-2-8-VM        i-2-9-VM
                              
10.223.51.3   /var/log/cloudstack/agent/agent.log:

i-2-5-VM:
2013-11-08 06:19:04,147 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 1-1258424034:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.NetworkUsageAnswer":{"routerName":"r-4-VM"," 
bytesSent":78720,"bytesReceived":0,"result":true,"details":"","wait":0}}] } 
2013-11-08 06:19:04,250 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 
2013-11-08 06:19:04,251 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Seq 1-1258424035:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 10, [{"com.cloud.agent.api.NetworkUsageAnswer":{"routerName":"r-4-VM","bytesSent":78720,"bytesReceived":0,"result":true,"details":"","wait":0}}] } 
2013-11-08 06:19:06,573 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 06:19:06,936 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 06:19:06,937 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-581:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":1,"wait":0}}] } 
2013-11-08 06:19:06,943 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) Received response: Seq 1-581:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":1,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 06:19:11,029 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 06:19:27,777 DEBUG [kvm.resource.KVMHAMonitor] (Thread-762:null) Found NFS storage pool 79884886-a3ee-31a7-856c-805e18c48f88 in libvirt, continuing 
2013-11-08 06:19:27,778 DEBUG [kvm.resource.KVMHAMonitor] (Thread-762:null) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.223.110.232 -p /export/home/angie/primary/kvm63 -m /mnt/79884886-a3ee-31a7-856c-805e18c48f88 -h 10.223.51.3  
2013-11-08 06:19:27,823 DEBUG [kvm.resource.KVMHAMonitor] (Thread-762:null) Execution is successful. 
2013-11-08 06:19:29,998 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-3:null) Execution is successful. 
2013-11-08 06:19:31,083 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Seq 1-1258424023:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/9/2c012c56-c3f7-424c-be2a-369c23210627","id":0}},"result":true,"wait":0}}] } 
2013-11-08 06:19:31,091 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Request:Seq 1-1258424024:  { Cmd , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/66c1b2d8-50c7-4142-ba0b-90e118dfebac/6aae68ec-d0cd-49a1-92ed-48dca5c0be35","volume":{"uuid":"e26af82d-7f7e-42f3-9333-374e02d7389c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-5","size":8589934592,"path":"66c1b2d8-50c7-4142-ba0b-90e118dfebac","volumeId":6,"vmName":"i-2-5-VM","accountId":2,"format":"QCOW2","id":6,"hypervisorType":"KVM"},"parentSnapshotPath":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/66c1b2d8-50c7-4142-ba0b-90e118dfebac/84eab2d6-91de-4db3-8920-f7b4854687ee","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-5-VM","name":"z1V2_ROOT-5_20131108141610","hypervisorType":"KVM","id":78}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/6","volume":{"uuid":"e26af82d-7f7e-42f3-9333-374e02d7389c","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-5","size":8589934592,"path":"66c1b2d8-50c7-4142-ba0b-90e118dfebac","volumeId":6,"vmName":"i-2-5-VM","accountId":2,"format":"QCOW2","id":6,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/6/84eab2d6-91de-4db3-8920-f7b4854687ee","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-5-VM","name":"z1V2_ROOT-5_20131108141610","hypervisorType":"KVM","id":78}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 06:19:31,091 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 06:19:31,095 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uuid, need to create it 
2013-11-08 06:19:31,095 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 06:19:31,096 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Checking path of existing pool 53bdaa9f-66af-46fb-9d23-24498b2e06f9 against pool we want to create 
2013-11-08 06:19:31,099 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 
2013-11-08 06:19:31,102 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Attempting to create storage pool 83602b3b-9b52-3016-871d-10883d294c18 
2013-11-08 06:19:31,102 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) <pool type='netfs'> 
<name>83602b3b-9b52-3016-871d-10883d294c18</name> 
<uuid>83602b3b-9b52-3016-871d-10883d294c18</uuid> 



i-2-6-VM:
2013-11-08 06:14:13,071 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Executing: /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -b /mnt/79884886-a3ee-31a7-856c-805e18c48f88/5b84df1b- 
4df4-4d64-89dd-4ca8304a81e8 -n 7473d60f-00e6-4319-a819-4eb16091e690 -p /mnt/83602b3b-9b52-3016-871d-10883d294c18/snapshots/2/7 -t 7473d60f-00e6-4319-a819-4eb16091e690  
2013-11-08 06:14:15,826 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:17,475 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Executing: /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -d /mnt/79884886-a3ee-31a7-856c-805e18c48f88/5b84df1b- 
4df4-4d64-89dd-4ca8304a81e8 -n 7473d60f-00e6-4319-a819-4eb16091e690  
2013-11-08 06:14:17,649 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:17,746 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 1-1258424018:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData" 
:{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/7/7473d60f-00e6-4319-a819-4eb16091e690","id":0}},"result":true,"wait":0}}] } 
2013-11-08 06:14:24,360 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 06:14:25,915 DEBUG [kvm.resource.KVMHAMonitor] (Thread-757:null) Found NFS storage pool 79884886-a3ee-31a7-856c-805e18c48f88 in libvirt, continuing 
2013-11-08 06:14:25,915 DEBUG [kvm.resource.KVMHAMonitor] (Thread-757:null) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.223.110.232 -p /export/home/angie/primary/kvm63 -m /mnt/79884886 
-a3ee-31a7-856c-805e18c48f88 -h 10.223.51.3  
2013-11-08 06:14:25,940 DEBUG [kvm.resource.KVMHAMonitor] (Thread-757:null) Execution is successful. 
2013-11-08 06:14:38,182 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetStorageStatsCommand 
2013-11-08 06:14:53,230 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 06:14:53,231 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 06:14:53,782 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:53,783 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 06:14:53,789 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:53,789 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 06:14:53,794 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:54,001 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Can't get vm stats: org.libvirt.LibvirtException: Timed out during operation: cannot acquire state change lock 
2013-11-08 06:15:06,570 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 06:15:06,768 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 06:15:06,769 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-577:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newState 
s":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":1,"wait":0}}] } 
2013-11-08 06:15:06,775 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Received response: Seq 1-577:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType" 
:"Routing","hostId":1,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 06:15:08,021 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Seq 1-1258424015:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data 
":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/70b69af1-cae9-4fa4-b3a6-2669e3d09e1b/77599676-4d14-40e1-9b58-38ee660272db","id":0}},"result":true,"wait":0}}] } 
2013-11-08 06:15:08,612 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Request:Seq 1-1258424022:  { Cmd , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{" 
srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/70b69af1-cae9-4fa4-b3a6-2669e3d09e1b/77599676-4d14-40e1-9b58-38ee660272db","volume":{"uuid":"2ed53bb4-7ed2-47f2-bdc9- 
66e698ba78ce","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/ho 
me/angie/primary/kvm63","port":2049}},"name":"ROOT-6","size":8589934592,"path":"70b69af1-cae9-4fa4-b3a6-2669e3d09e1b","volumeId":8,"vmName":"i-2-6-VM","accountId":2,"format":"QCOW2","id":8,"hypervisorType":"KVM"},"parentSnapshot 
Path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/70b69af1-cae9-4fa4-b3a6-2669e3d09e1b/a7f7d40d-bcc6-4a4f-9175-66411480fdfd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e 
18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-6-VM","name":"z1adminV3_ROOT-6_20131108141611","hypervisorType":"KVM","id":79}},"destT 
O":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/8","volume":{"uuid":"2ed53bb4-7ed2-47f2-bdc9-66e698ba78ce","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uui 
d":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-6","size":8589934592,"path":"70b69af1-cae9-4fa4-b3a6-26 
69e3d09e1b","volumeId":8,"vmName":"i-2-6-VM","accountId":2,"format":"QCOW2","id":8,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/8/a7f7d40d-bcc6-4a4f-9175-66411480fdfd","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_ 
url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-6-VM","name":"z1adminV3_ROOT-6_20131108141611","hypervisorType":"KVM","id":79}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 06:15:08,612 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 06:15:08,615 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uui 
d, need to create it 
2013-11-08 06:15:08,615 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 06:15:08,617 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Checking path of existing pool 53bdaa9f-66af-46fb-9d23-24498b2e06f9 against pool we want to create 
2013-11-08 06:15:08,620 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 
2013-11-08 06:15:08,624 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Attempting to create storage pool 83602b3b-9b52-3016-871d-10883d294c18 
2013-11-08 06:15:08,624 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) <pool type='netfs'> 







2013-11-08 06:14:13,071 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Executing: /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -b /mnt/79884886-a3ee-31a7-856c-805e18c48f88/5b84df1b- 
4df4-4d64-89dd-4ca8304a81e8 -n 7473d60f-00e6-4319-a819-4eb16091e690 -p /mnt/83602b3b-9b52-3016-871d-10883d294c18/snapshots/2/7 -t 7473d60f-00e6-4319-a819-4eb16091e690  
2013-11-08 06:14:15,826 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:17,475 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Executing: /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -d /mnt/79884886-a3ee-31a7-856c-805e18c48f88/5b84df1b- 
4df4-4d64-89dd-4ca8304a81e8 -n 7473d60f-00e6-4319-a819-4eb16091e690  
2013-11-08 06:14:17,649 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:17,746 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 1-1258424018:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData" 
:{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/7/7473d60f-00e6-4319-a819-4eb16091e690","id":0}},"result":true,"wait":0}}] } 
2013-11-08 06:14:24,360 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 06:14:25,915 DEBUG [kvm.resource.KVMHAMonitor] (Thread-757:null) Found NFS storage pool 79884886-a3ee-31a7-856c-805e18c48f88 in libvirt, continuing 
2013-11-08 06:14:25,915 DEBUG [kvm.resource.KVMHAMonitor] (Thread-757:null) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.223.110.232 -p /export/home/angie/primary/kvm63 -m /mnt/79884886 
-a3ee-31a7-856c-805e18c48f88 -h 10.223.51.3  
2013-11-08 06:14:25,940 DEBUG [kvm.resource.KVMHAMonitor] (Thread-757:null) Execution is successful. 
2013-11-08 06:14:38,182 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetStorageStatsCommand 
2013-11-08 06:14:53,230 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 06:14:53,231 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 06:14:53,782 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:53,783 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 06:14:53,789 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:53,789 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 06:14:53,794 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:14:54,001 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Can't get vm stats: org.libvirt.LibvirtException: Timed out during operation: cannot acquire state change lock 
2013-11-08 06:15:06,570 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 06:15:06,768 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 06:15:06,769 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-577:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newState 
s":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":1,"wait":0}}] } 
2013-11-08 06:15:06,775 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null) Received response: Seq 1-577:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType" 
:"Routing","hostId":1,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 06:15:08,021 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Seq 1-1258424015:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data 
":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/70b69af1-cae9-4fa4-b3a6-2669e3d09e1b/77599676-4d14-40e1-9b58-38ee660272db","id":0}},"result":true,"wait":0}}] } 
2013-11-08 06:15:08,612 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Request:Seq 1-1258424022:  { Cmd , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{" 
srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/70b69af1-cae9-4fa4-b3a6-2669e3d09e1b/77599676-4d14-40e1-9b58-38ee660272db","volume":{"uuid":"2ed53bb4-7ed2-47f2-bdc9- 
66e698ba78ce","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/ho 
me/angie/primary/kvm63","port":2049}},"name":"ROOT-6","size":8589934592,"path":"70b69af1-cae9-4fa4-b3a6-2669e3d09e1b","volumeId":8,"vmName":"i-2-6-VM","accountId":2,"format":"QCOW2","id":8,"hypervisorType":"KVM"},"parentSnapshot 
Path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/70b69af1-cae9-4fa4-b3a6-2669e3d09e1b/a7f7d40d-bcc6-4a4f-9175-66411480fdfd","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e 
18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-6-VM","name":"z1adminV3_ROOT-6_20131108141611","hypervisorType":"KVM","id":79}},"destT 
O":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/8","volume":{"uuid":"2ed53bb4-7ed2-47f2-bdc9-66e698ba78ce","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uui 
d":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-6","size":8589934592,"path":"70b69af1-cae9-4fa4-b3a6-26 
69e3d09e1b","volumeId":8,"vmName":"i-2-6-VM","accountId":2,"format":"QCOW2","id":8,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/8/a7f7d40d-bcc6-4a4f-9175-66411480fdfd","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_ 
url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-6-VM","name":"z1adminV3_ROOT-6_20131108141611","hypervisorType":"KVM","id":79}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 06:15:08,612 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 06:15:08,615 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uui 
d, need to create it 
2013-11-08 06:15:08,615 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 06:15:08,617 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Checking path of existing pool 53bdaa9f-66af-46fb-9d23-24498b2e06f9 against pool we want to create 
2013-11-08 06:15:08,620 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 
2013-11-08 06:15:08,624 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Attempting to create storage pool 83602b3b-9b52-3016-871d-10883d294c18 
2013-11-08 06:15:08,624 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) <pool type='netfs'> 

i-2-7-VM:
2013-11-08 06:16:27,291 DEBUG [kvm.resource.KVMHAMonitor] (Thread-759:null) Execution is successful. 
2013-11-08 06:16:42,685 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.GetStorageStatsCommand 
2013-11-08 06:16:55,510 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 06:16:55,510 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 06:16:56,041 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 06:16:56,042 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 06:16:56,048 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 06:16:56,048 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 06:16:56,054 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 06:17:06,570 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 06:17:06,895 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 06:17:06,896 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-579:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newState 
s":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":1,"wait":0}}] } 
2013-11-08 06:17:06,902 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response: Seq 1-579:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType" 
:"Routing","hostId":1,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 06:17:10,520 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 06:17:16,761 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 06:17:20,848 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 1-1258424022:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData" 
:{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/8/77599676-4d14-40e1-9b58-38ee660272db","id":0}},"result":true,"wait":0}}] } 
2013-11-08 06:17:20,856 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Request:Seq 1-1258424023:  { Cmd , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/7ac73bd3-9e02-46db-af5a-5bf55a59747d/2c012c56-c3f7-424c-be2a-369c23210627","volume":{"uuid":"69f5267c-19cc-40f8-b4ad-d848386db0fe","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-7","size":8589934592,"path":"7ac73bd3-9e02-46db-af5a-5bf55a59747d","volumeId":9,"vmName":"i-2-7-VM","accountId":2,"format":"QCOW2","id":9,"hypervisorType":"KVM"},"parentSnapshotPath":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/7ac73bd3-9e02-46db-af5a-5bf55a59747d/5d914d37-f00f-4e30-8bf6-af870c51ab32","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-7-VM","name":"z1V4_ROOT-7_20131108141611","hypervisorType":"KVM","id":80}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/9","volume":{"uuid":"69f5267c-19cc-40f8-b4ad-d848386db0fe","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-7","size":8589934592,"path":"7ac73bd3-9e02-46db-af5a-5bf55a59747d","volumeId":9,"vmName":"i-2-7-VM","accountId":2,"format":"QCOW2","id":9,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/9/5d914d37-f00f-4e30-8bf6-af870c51ab32","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-7-VM","name":"z1V4_ROOT-7_20131108141611","hypervisorType":"KVM","id":80}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 06:17:20,856 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 06:17:20,859 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uuid, need to create it 
2013-11-08 06:17:20,860 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 06:17:20,861 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) Checking path of existing pool 53bdaa9f-66af-46fb-9d23-24498b2e06f9 against pool we want to create 
2013-11-08 06:17:20,864 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 
2013-11-08 06:17:20,867 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) Attempting to create storage pool 83602b3b-9b52-3016-871d-10883d294c18 
2013-11-08 06:17:20,867 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-3:null) <pool type='netfs'> 
<name>83602b3b-9b52-3016-871d-10883d294c18</name> 
<uuid>83602b3b-9b52-3016-871d-10883d294c18</uuid> 
<source> 
<host name='10.223.110.232'/> 
<dir path='/export/home/angie/secondary/kvm63'/> 
</source> 
<target> 
<path>/mnt/83602b3b-9b52-3016-871d-10883d294c18</path> 
</target> 


i-2-7-VM:

2013-11-08 10:17:12,875 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 10:17:17,178 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 10:17:17,178 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 10:17:17,701 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 10:17:17,702 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 10:17:17,707 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 10:17:17,708 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 10:17:17,732 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 10:17:56,187 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1000:null) Found NFS storage pool 79884886-a3ee-31a7-856c-805e18c48f88 in libvirt, continuing 
2013-11-08 10:17:56,188 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1000:null) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.223.110.232 -p /export/home/angie/primary/kvm63 -m /mnt/7988488 
6-a3ee-31a7-856c-805e18c48f88 -h 10.223.51.3  
2013-11-08 10:17:57,895 DEBUG [kvm.resource.KVMHAMonitor] (Thread-1000:null) Execution is successful. 
2013-11-08 10:18:06,601 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 10:18:07,081 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 10:18:07,082 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 1-820:  { Cmd , MgmtId: -1, via: 1, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newState 
s":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":1,"wait":0}}] } 
2013-11-08 10:18:07,089 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null) Received response: Seq 1-820:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType" 
:"Routing","hostId":1,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 10:18:13,139 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 10:18:18,294 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 10:18:18,295 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 10:18:18,834 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful. 
2013-11-08 10:18:18,835 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 10:18:18,841 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful. 
2013-11-08 10:18:18,842 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 10:18:18,847 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful. 
2013-11-08 10:18:29,896 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: com.cloud.agent.api.GetStorageStatsCommand 
2013-11-08 10:18:52,274 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 10:18:54,917 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 1-1258424740:  { Ans: , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData" 
:{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/6/538c361d-5655-45ff-aaa0-4ce574fc8165","id":0}},"result":true,"wait":0}}] } 
2013-11-08 10:18:54,925 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Request:Seq 1-1258424741:  { Cmd , MgmtId: 206915885077197, via: 1, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{" 
srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/7ac73bd3-9e02-46db-af5a-5bf55a59747d/281df958-928b-4315-b877-57ff48eb1a27","volume":{"uuid":"69f5267c-19cc-40f8-b4ad- 
d848386db0fe","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/ho 
me/angie/primary/kvm63","port":2049}},"name":"ROOT-7","size":8589934592,"path":"7ac73bd3-9e02-46db-af5a-5bf55a59747d","volumeId":9,"vmName":"i-2-7-VM","accountId":2,"format":"QCOW2","id":9,"hypervisorType":"KVM"},"parentSnapshot 
Path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/7ac73bd3-9e02-46db-af5a-5bf55a59747d/696519ca-3e28-403a-adad-ea317f699d96","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e 
18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-7-VM","name":"z1V4_ROOT-7_20131108181611","hypervisorType":"KVM","id":112}},"destTO":{ 
"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/9","volume":{"uuid":"69f5267c-19cc-40f8-b4ad-d848386db0fe","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":" 
79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-7","size":8589934592,"path":"7ac73bd3-9e02-46db-af5a-5bf55a 
59747d","volumeId":9,"vmName":"i-2-7-VM","accountId":2,"format":"QCOW2","id":9,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/9/696519ca-3e28-403a-adad-ea317f699d96","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url" 
:"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-7-VM","name":"z1V4_ROOT-7_20131108181611","hypervisorType":"KVM","id":112}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 10:18:54,925 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 10:18:54,929 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uui 
d, need to create it 
2013-11-08 10:18:54,929 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 10:18:54,930 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) Checking path of existing pool 53bdaa9f-66af-46fb-9d23-24498b2e06f9 against pool we want to create 
2013-11-08 10:18:54,934 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 
2013-11-08 10:18:54,937 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) Attempting to create storage pool 83602b3b-9b52-3016-871d-10883d294c18 
2013-11-08 10:18:54,937 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-1:null) <pool type='netfs'> 




host   10.223.51.4  contains VMs    	i-2-3-VM	i-2-8-VM	i-2-9-VM

/var/log/cloudstack/agent/agent.log:

i-2-3-VM:

2013-11-08 10:14:14,341 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Executing: /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -b /mnt/79884886-a3ee-31a7-856c-805e18c48f88/d15ee947-d8e6-456e-865d-ab9161b0d15c -n 1c39e621-fec1-493c-878c-ae94943a061b -p /mnt/83602b3b-9b52-3016-871d-10883d294c18/snapshots/2/4 -t 1c39e621-fec1-493c-878c-ae94943a061b  
2013-11-08 10:14:16,849 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 10:14:17,075 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 10:14:17,075 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 10:14:17,206 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Executing: /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -d /mnt/79884886-a3ee-31a7-856c-805e18c48f88/d15ee947-d8e6-456e-865d-ab9161b0d15c -n 1c39e621-fec1-493c-878c-ae94943a061b  
2013-11-08 10:14:17,286 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 10:14:17,376 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 4-804653139:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/4/1c39e621-fec1-493c-878c-ae94943a061b","id":0}},"result":true,"wait":0}}] } 
2013-11-08 10:14:17,632 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Execution is successful. 
2013-11-08 10:14:17,633 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 10:14:17,638 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Execution is successful. 
2013-11-08 10:14:17,639 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 10:14:17,643 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-4:null) Execution is successful. 
2013-11-08 10:14:40,093 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Seq 4-804653135:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/886c020f-908e-4d0b-881c-ddbf441e4dae/a44f39ab-39af-4527-b1c1-3ff476762301","id":0}},"result":true,"wait":0}}] } 
2013-11-08 10:14:40,519 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Request:Seq 4-804653141:  { Cmd , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/886c020f-908e-4d0b-881c-ddbf441e4dae/a44f39ab-39af-4527-b1c1-3ff476762301","volume":{"uuid":"9e4730dc-760a-4e17-b53a-76dc0c022827","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-3","size":8589934592,"path":"886c020f-908e-4d0b-881c-ddbf441e4dae","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"QCOW2","id":3,"hypervisorType":"KVM"},"parentSnapshotPath":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/886c020f-908e-4d0b-881c-ddbf441e4dae/b09ef62a-39f0-48e7-812b-0b08376008a2","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-3-VM","name":"z1V1_ROOT-3_20131108181610","hypervisorType":"KVM","id":109}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/3","volume":{"uuid":"9e4730dc-760a-4e17-b53a-76dc0c022827","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-3","size":8589934592,"path":"886c020f-908e-4d0b-881c-ddbf441e4dae","volumeId":3,"vmName":"i-2-3-VM","accountId":2,"format":"QCOW2","id":3,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/3/b09ef62a-39f0-48e7-812b-0b08376008a2","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-3-VM","name":"z1V1_ROOT-3_20131108181610","hypervisorType":"KVM","id":109}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 10:14:40,520 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 10:14:40,523 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uuid, need to create it 
2013-11-08 10:14:40,523 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 10:14:40,525 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Checking path of existing pool 39ae06ee-d458-4a91-8bd1-8a1871955297 against pool we want to create 
2013-11-08 10:14:40,528 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 
2013-11-08 10:14:40,531 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) Attempting to create storage pool 83602b3b-9b52-3016-871d-10883d294c18 
2013-11-08 10:14:40,532 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-5:null) <pool type='netfs'> 
<name>83602b3b-9b52-3016-871d-10883d294c18</name> 
<uuid>83602b3b-9b52-3016-871d-10883d294c18</uuid> 


i-2-8-VM:
2013-11-08 10:14:58,834 DEBUG [kvm.resource.KVMHAMonitor] (Thread-997:null) Execution is successful. 
2013-11-08 10:15:09,829 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Seq 4-804653136:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"o 
rg.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/f2ec326a-cb29-48a1-ad16-bff8c8161e68/ff336e88-296e-4d93-ae28-360e50d46714","id":0}},"result":true,"wait":0}}] } 
2013-11-08 10:15:12,154 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 10:15:12,351 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 10:15:12,353 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 4-817:  { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}] } 
2013-11-08 10:15:12,359 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response: Seq 4-817:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 10:15:15,279 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Seq 4-804653137:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/8d23ea1a-518d-47d1-9f60-ed9fdf55799f/aa31a30f-31dd-4355-b807-afa0e08e65ca","id":0}},"result":true,"wait":0}}] } 
2013-11-08 10:15:18,247 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 10:15:18,247 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 10:15:18,777 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 10:15:18,777 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 10:15:18,783 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 10:15:18,784 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 10:15:18,791 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 10:15:58,842 DEBUG [kvm.resource.KVMHAMonitor] (Thread-998:null) Found NFS storage pool 79884886-a3ee-31a7-856c-805e18c48f88 in libvirt, continuing 
2013-11-08 10:15:58,843 DEBUG [kvm.resource.KVMHAMonitor] (Thread-998:null) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.223.110.232 -p /export/home/angie/primary/kvm63 -m /mnt/79884886-a3ee-31a7-856c-805e18c48f88 -h 10.223.51.4  
2013-11-08 10:15:58,914 DEBUG [kvm.resource.KVMHAMonitor] (Thread-998:null) Execution is successful. 
2013-11-08 10:16:12,156 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 10:16:12,370 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 10:16:12,371 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 4-818:  { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}] } 
2013-11-08 10:16:12,379 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null) Received response: Seq 4-818:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 10:16:15,469 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 10:16:19,345 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 10:16:19,345 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 10:16:19,869 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 
2013-11-08 10:16:19,870 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 10:16:19,887 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 
2013-11-08 10:16:19,888 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 10:16:19,904 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 
2013-11-08 10:16:37,570 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 10:16:38,005 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 4-804653141:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/3/a44f39ab-39af-4527-b1c1-3ff476762301","id":0}},"result":true,"wait":0}}] } 
2013-11-08 10:16:38,019 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Request:Seq 4-804653143:  { Cmd , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/f2ec326a-cb29-48a1-ad16-bff8c8161e68/ff336e88-296e-4d93-ae28-360e50d46714","volume":{"uuid":"13d496ba-0398-47e0-9c3e-86d749b39062","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-8","size":8589934592,"path":"f2ec326a-cb29-48a1-ad16-bff8c8161e68","volumeId":10,"vmName":"i-2-8-VM","accountId":2,"format":"QCOW2","id":10,"hypervisorType":"KVM"},"parentSnapshotPath":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/f2ec326a-cb29-48a1-ad16-bff8c8161e68/725f0a6b-1c1a-45d7-8827-a2ce11eaac8c","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-8-VM","name":"z1V5_ROOT-8_20131108181612","hypervisorType":"KVM","id":113}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/10","volume":{"uuid":"13d496ba-0398-47e0-9c3e-86d749b39062","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-8","size":8589934592,"path":"f2ec326a-cb29-48a1-ad16-bff8c8161e68","volumeId":10,"vmName":"i-2-8-VM","accountId":2,"format":"QCOW2","id":10,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/10/725f0a6b-1c1a-45d7-8827-a2ce11eaac8c","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/home/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-8-VM","name":"z1V5_ROOT-8_20131108181612","hypervisorType":"KVM","id":113}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 10:16:38,020 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 10:16:38,023 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uuid, need to create it 
2013-11-08 10:16:38,023 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 10:16:38,025 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Checking path of existing pool 39ae06ee-d458-4a91-8bd1-8a1871955297 against pool we want to create 
2013-11-08 10:16:38,028 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 
2013-11-08 10:16:38,031 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) Attempting to create storage pool 83602b3b-9b52-3016-871d-10883d294c18 
2013-11-08 10:16:38,031 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-4:null) <pool type='netfs'> 
<name>83602b3b-9b52-3016-871d-10883d294c18</name> 
<uuid>83602b3b-9b52-3016-871d-10883d294c18</uuid> 



i-2-9-VM:

2013-11-08 09:14:45,516 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-1:null) Executing: /usr/share/cloudstack-common/scripts/storage/qcow2/managesnapshot.sh -b /mnt/79884886-a3ee-31a7-856c-805e18c48f88/886c020f-908e 
-4d0b-881c-ddbf441e4dae -n b09ef62a-39f0-48e7-812b-0b08376008a2 -p /mnt/83602b3b-9b52-3016-871d-10883d294c18/snapshots/2/3 -t b09ef62a-39f0-48e7-812b-0b08376008a2  
2013-11-08 09:14:52,793 DEBUG [kvm.resource.KVMHAMonitor] (Thread-937:null) Found NFS storage pool 79884886-a3ee-31a7-856c-805e18c48f88 in libvirt, continuing 
2013-11-08 09:14:52,793 DEBUG [kvm.resource.KVMHAMonitor] (Thread-937:null) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.223.110.232 -p /export/home/angie/primary/kvm63 -m /mnt/79884886-a3e 
e-31a7-856c-805e18c48f88 -h 10.223.51.4  
2013-11-08 09:14:53,278 DEBUG [kvm.resource.KVMHAMonitor] (Thread-937:null) Execution is successful. 
2013-11-08 09:14:58,794 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetStorageStatsCommand 
2013-11-08 09:15:04,502 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 09:15:10,906 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Seq 4-804652979:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"o 
rg.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/8d23ea1a-518d-47d1-9f60-ed9fdf55799f/a60c38f1-3904-4df5-b2b7-e1102b529c81","id":0}},"result":true,"wait":0}}] } 
2013-11-08 09:15:11,315 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Seq 4-804652978:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CreateObjectAnswer":{"data":{"o 
rg.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/f2ec326a-cb29-48a1-ad16-bff8c8161e68/725f0a6b-1c1a-45d7-8827-a2ce11eaac8c","id":0}},"result":true,"wait":0}}] } 
2013-11-08 09:15:12,147 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 09:15:12,323 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 09:15:12,324 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 4-757:  { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{ 
},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}] } 
2013-11-08 09:15:12,330 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null) Received response: Seq 4-757:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Ro 
uting","hostId":4,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 09:15:12,796 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 09:15:12,796 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 09:15:13,351 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 09:15:13,352 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 09:15:13,357 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 09:15:13,358 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 09:15:13,363 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 
2013-11-08 09:15:53,282 DEBUG [kvm.resource.KVMHAMonitor] (Thread-938:null) Found NFS storage pool 79884886-a3ee-31a7-856c-805e18c48f88 in libvirt, continuing 
2013-11-08 09:15:53,282 DEBUG [kvm.resource.KVMHAMonitor] (Thread-938:null) Executing: /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i 10.223.110.232 -p /export/home/angie/primary/kvm63 -m /mnt/79884886-a3e 
e-31a7-856c-805e18c48f88 -h 10.223.51.4  
2013-11-08 09:15:53,349 DEBUG [kvm.resource.KVMHAMonitor] (Thread-938:null) Execution is successful. 
2013-11-08 09:16:11,501 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null) Processing command: com.cloud.agent.api.GetVmStatsCommand 
2013-11-08 09:16:12,150 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Executing: /usr/share/cloudstack-common/scripts/vm/network/security_group.py get_rule_logs_for_vms  
2013-11-08 09:16:12,355 DEBUG [kvm.resource.LibvirtComputingResource] (UgentTask-5:null) Execution is successful. 
2013-11-08 09:16:12,356 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending ping: Seq 4-758:  { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11, [{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{ 
},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}] } 
2013-11-08 09:16:12,362 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) Received response: Seq 4-758:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 100010, [{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Ro 
uting","hostId":4,"wait":0},"result":true,"wait":0}}] } 
2013-11-08 09:16:13,972 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Processing command: com.cloud.agent.api.GetHostStatsCommand 
2013-11-08 09:16:13,972 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c idle=$(top -b -n 1|grep Cpu\(s\):|cut -d% -f4|cut -d, -f2);echo $idle  
2013-11-08 09:16:14,493 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful. 
2013-11-08 09:16:14,493 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c freeMem=$(free|grep cache:|awk '{print $4}');echo $freeMem  
2013-11-08 09:16:14,498 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful. 
2013-11-08 09:16:14,499 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Executing: /bin/bash -c free|grep Mem:|awk '{print $2}'  
2013-11-08 09:16:14,504 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) Execution is successful. 
2013-11-08 09:16:25,790 DEBUG [kvm.storage.KVMStorageProcessor] (agentRequest-Handler-1:null) Execution is successful. 
2013-11-08 09:16:26,271 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null) Seq 4-804652983:  { Ans: , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"or 
g.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/3/b09ef62a-39f0-48e7-812b-0b08376008a2","id":0}},"result":true,"wait":0}}] } 
2013-11-08 09:16:26,279 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Request:Seq 4-804652986:  { Cmd , MgmtId: 206915885077197, via: 4, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO 
":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/mnt/79884886-a3ee-31a7-856c-805e18c48f88/8d23ea1a-518d-47d1-9f60-ed9fdf55799f/a60c38f1-3904-4df5-b2b7-e1102b529c81","volume":{"uuid":"826204fd-2ca1-4e9b-bf50-e5d6dd32e 
231","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/prim 
ary/kvm63","port":2049}},"name":"ROOT-9","size":8589934592,"path":"8d23ea1a-518d-47d1-9f60-ed9fdf55799f","volumeId":11,"vmName":"i-2-9-VM","accountId":2,"format":"QCOW2","id":11,"hypervisorType":"KVM"},"parentSnapshotPath":"/mnt/798 
84886-a3ee-31a7-856c-805e18c48f88/8d23ea1a-518d-47d1-9f60-ed9fdf55799f/664449d4-e9eb-4522-b875-832f41bb2f5e","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-805e18c48f88","id":1,"p 
oolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"vmName":"i-2-9-VM","name":"z1V6_ROOT-9_20131108171612","hypervisorType":"KVM","id":106}},"destTO":{"org.apache.cloudstack. 
storage.to.SnapshotObjectTO":{"path":"snapshots/2/11","volume":{"uuid":"826204fd-2ca1-4e9b-bf50-e5d6dd32e231","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"79884886-a3ee-31a7-856c-80 
5e18c48f88","id":1,"poolType":"NetworkFilesystem","host":"10.223.110.232","path":"/export/home/angie/primary/kvm63","port":2049}},"name":"ROOT-9","size":8589934592,"path":"8d23ea1a-518d-47d1-9f60-ed9fdf55799f","volumeId":11,"vmName" 
:"i-2-9-VM","accountId":2,"format":"QCOW2","id":11,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/11/664449d4-e9eb-4522-b875-832f41bb2f5e","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://10.223.110.232/export/h 
ome/angie/secondary/kvm63","_role":"Image"}},"vmName":"i-2-9-VM","name":"z1V6_ROOT-9_20131108171612","hypervisorType":"KVM","id":106}},"executeInSequence":true,"wait":21600}}] } 
2013-11-08 09:16:26,279 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: org.apache.cloudstack.storage.command.CopyCommand 
2013-11-08 09:16:26,282 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) createStoragePool didn't find existing running pool: org.libvirt.LibvirtException: Storage pool not found: no pool with matching uuid, n 
eed to create it 
2013-11-08 09:16:26,282 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) Didn't find an existing storage pool 83602b3b-9b52-3016-871d-10883d294c18 by UUID, checking for pools with duplicate paths 
2013-11-08 09:16:26,283 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) Checking path of existing pool 39ae06ee-d458-4a91-8bd1-8a1871955297 against pool we want to create 
2013-11-08 09:16:26,286 DEBUG [kvm.storage.LibvirtStorageAdaptor] (agentRequest-Handler-2:null) Checking path of existing pool 79884886-a3ee-31a7-856c-805e18c48f88 against pool we want to create 








 

> Failed to create snapshot (KVM, Multiple hosts, Sharedstorage)
> --------------------------------------------------------------
>
>                 Key: CLOUDSTACK-4939
>                 URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4939
>             Project: CloudStack
>          Issue Type: Bug
>      Security Level: Public(Anyone can view this level - this is the default.) 
>          Components: KVM, Snapshot
>    Affects Versions: 4.2.0, 4.2.1
>         Environment: CentOS 6.4, KVM, Shared mount point primary storage, GFS2, iSCSI
>            Reporter: Ivan Kozlov
>            Assignee: edison su
>            Priority: Blocker
>              Labels: kvm, sharedstorage, snapshot
>             Fix For: 4.2.1
>
>         Attachments: 4939.doc, 513agent.doc, 514agent.doc, management-server(1).log.gz
>
>
> With one host snapshots are created ok. After adding second host some snapshots fail (Failed to create snapshot due to an internal error creating snapshot for volume 14) stucking with state "CreatedOnPrimary". Even when all VMs are running on the same host.
> debug libvirt log shows:
> 2013-10-23 17:31:21.634+0000: 20007: debug : virStorageFileGetMetadataInternal:673 : path=/mnt/48a148f6-3373-3af2-8667-2f240988163d/snapshots, fd=31, format=2
> 2013-10-23 17:32:57.189+0000: 20015: debug : qemuSnapObjFromName:233 : Domain snapshot not found: no domain snapshot with matching name '909848a0-b3ec-4657-a53a-c449dc24365b'
> 2013-10-23 17:32:57.474+0000: 20009: debug : virStorageFileGetMetadataInternal:673 : path=/mnt/48a148f6-3373-3af2-8667-2f240988163d/snapshots, fd=31, format=2
> 2013-10-23 17:34:28.264+0000: 20008: debug : qemuSnapObjFromName:233 : Domain snapshot not found: no domain snapshot with matching name 'f4e51b11-ac79-4a6a-b887-8926ffbd5cca'
> management server log:
> 2013-10-23 20:29:50,561 INFO  [user.snapshot.CreateSnapshotCmd] (Job-Executor-52:job-94 = [ 42f8d6e0-762e-4f01-a7d5-daff2e31be13 ]) VOLSS: createSnapshotCmd starts:1382549390561
> 2013-10-23 20:29:52,053 DEBUG [agent.transport.Request] (Job-Executor-52:job-94 = [ 42f8d6e0-762e-4f01-a7d5-daff2e31be13 ]) Seq 6-1170407437: Waiting for Seq 1170407434 Scheduling:  { Cmd , MgmtId: 161342718518, via: 6, Ver: v1, Flags: 100111, [{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"/primary/d59c6574-8ff9-41e4-86e5-ce560f30d717/f4e51b11-ac79-4a6a-b887-8926ffbd5cca","volume":{"uuid":"02c07659-59d3-42f2-8928-1d899cef94e7","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"2c8e7b93-2d02-4c47-99ce-7bcd8670554a","id":2,"poolType":"SharedMountPoint","host":"localhost","path":"/primary","port":0}},"name":"ROOT-14","size":8589934592,"path":"d59c6574-8ff9-41e4-86e5-ce560f30d717","volumeId":14,"vmName":"i-2-14-VM","accountId":2,"format":"QCOW2","id":14,"hypervisorType":"KVM"},"parentSnapshotPath":"/primary/d59c6574-8ff9-41e4-86e5-ce560f30d717/ab317705-7368-4a40-9d1c-da2c8a7b1824","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"2c8e7b93-2d02-4c47-99ce-7bcd8670554a","id":2,"poolType":"SharedMountPoint","host":"localhost","path":"/primary","port":0}},"vmName":"i-2-14-VM","name":"t1_ROOT-14_20131023172950","hypervisorType":"KVM","id":33}},"destTO":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/14","volume":{"uuid":"02c07659-59d3-42f2-8928-1d899cef94e7","volumeType":"ROOT","dataStore":{"org.apache.cloudstack.storage.to.PrimaryDataStoreTO":{"uuid":"2c8e7b93-2d02-4c47-99ce-7bcd8670554a","id":2,"poolType":"SharedMountPoint","host":"localhost","path":"/primary","port":0}},"name":"ROOT-14","size":8589934592,"path":"d59c6574-8ff9-41e4-86e5-ce560f30d717","volumeId":14,"vmName":"i-2-14-VM","accountId":2,"format":"QCOW2","id":14,"hypervisorType":"KVM"},"parentSnapshotPath":"snapshots/2/14/ab317705-7368-4a40-9d1c-da2c8a7b1824","dataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.168.10.31/export/secondary","_role":"Image"}},"vmName":"i-2-14-VM","name":"t1_ROOT-14_20131023172950","hypervisorType":"KVM","id":33}},"executeInSequence":true,"wait":21600}}] }
> 2013-10-23 20:31:21,560 DEBUG [agent.transport.Request] (AgentManager-Handler-8:null) Seq 6-1170407434: Processing:  { Ans: , MgmtId: 161342718518, via: 6, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name '65113136-dfb5-4cea-8e65-1065462ca2fe'","wait":0}}] }
> 2013-10-23 20:31:21,832 DEBUG [storage.snapshot.SnapshotManagerImpl] (Job-Executor-49:job-91 = [ e2bf2454-4273-4a89-bc38-35add8297eb1 ]) Failed to create snapshot
> com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name '65113136-dfb5-4cea-8e65-1065462ca2fe'
>         at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
>         at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 2013-10-23 20:31:21,999 DEBUG [storage.volume.VolumeServiceImpl] (Job-Executor-49:job-91 = [ e2bf2454-4273-4a89-bc38-35add8297eb1 ]) Take snapshot: 18 failed
> com.cloud.utils.exception.CloudRuntimeException: Failed to create snapshot
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1040)
>         at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> Caused by: com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name '65113136-dfb5-4cea-8e65-1065462ca2fe'
>         at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
> 2013-10-23 20:31:22,167 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-49:job-91 = [ e2bf2454-4273-4a89-bc38-35add8297eb1 ]) Complete async job-91 = [ e2bf2454-4273-4a89-bc38-35add8297eb1 ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to create snapshot due to an internal error creating snapshot for volume 18
> 2013-10-23 20:31:24,709 DEBUG [agent.transport.Request] (AgentManager-Handler-13:null) Seq 9-1437990929: Processing:  { Ans: , MgmtId: 161342718518, via: 9, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"newData":{"org.apache.cloudstack.storage.to.SnapshotObjectTO":{"path":"snapshots/2/16/157016cb-5e57-428f-b747-5d9b628d2864","id":0}},"result":true,"wait":0}}] }
> 2013-10-23 20:31:25,760 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-51:job-93 = [ 25e157c0-f966-401e-9263-c42dac56e0c1 ]) Done executing org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd for job-93 = [ 25e157c0-f966-401e-9263-c42dac56e0c1 ]
> 2013-10-23 20:32:57,416 DEBUG [agent.transport.Request] (AgentManager-Handler-8:null) Seq 6-1170407435: Processing:  { Ans: , MgmtId: 161342718518, via: 6, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name '909848a0-b3ec-4657-a53a-c449dc24365b'","wait":0}}] }
> 2013-10-23 20:32:57,680 DEBUG [storage.snapshot.SnapshotManagerImpl] (Job-Executor-50:job-92 = [ b8bbb5be-54ba-43df-b429-5b5fb61416ad ]) Failed to create snapshot
> com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name '909848a0-b3ec-4657-a53a-c449dc24365b'
>         at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
>         at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 2013-10-23 20:32:57,763 DEBUG [storage.volume.VolumeServiceImpl] (Job-Executor-50:job-92 = [ b8bbb5be-54ba-43df-b429-5b5fb61416ad ]) Take snapshot: 17 failed
> com.cloud.utils.exception.CloudRuntimeException: Failed to create snapshot
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1040)
>         at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> Caused by: com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name '909848a0-b3ec-4657-a53a-c449dc24365b'
>         at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
> 2013-10-23 20:32:57,849 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-50:job-92 = [ b8bbb5be-54ba-43df-b429-5b5fb61416ad ]) Complete async job-92 = [ b8bbb5be-54ba-43df-b429-5b5fb61416ad ], jobStatus: 2, resultCode: 530, result: Error Code: 530 Error text: Failed to create snapshot due to an internal error creating snapshot for volume 17
> 2013-10-23 20:33:50,627 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Snapshot scheduler.poll is being called at 2013-10-23 17:33:50 GMT
> 2013-10-23 20:33:50,627 DEBUG [storage.snapshot.SnapshotSchedulerImpl] (SnapshotPollTask:null) Got 0 snapshots to be executed at 2013-10-23 17:33:50 GMT
> 2013-10-23 20:34:28,514 DEBUG [agent.transport.Request] (AgentManager-Handler-3:null) Seq 6-1170407437: Processing:  { Ans: , MgmtId: 161342718518, via: 6, Ver: v1, Flags: 110, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name 'f4e51b11-ac79-4a6a-b887-8926ffbd5cca'","wait":0}}] }
> 2013-10-23 20:34:28,779 DEBUG [storage.snapshot.SnapshotManagerImpl] (Job-Executor-52:job-94 = [ 42f8d6e0-762e-4f01-a7d5-daff2e31be13 ]) Failed to create snapshot
> com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name 'f4e51b11-ac79-4a6a-b887-8926ffbd5cca'
>         at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)
>         at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> 2013-10-23 20:34:28,870 DEBUG [storage.volume.VolumeServiceImpl] (Job-Executor-52:job-94 = [ 42f8d6e0-762e-4f01-a7d5-daff2e31be13 ]) Take snapshot: 14 failed
> com.cloud.utils.exception.CloudRuntimeException: Failed to create snapshot
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1040)
>         at org.apache.cloudstack.api.command.user.snapshot.CreateSnapshotCmd.execute(CreateSnapshotCmd.java:170)
> Caused by: com.cloud.utils.exception.CloudRuntimeException: org.libvirt.LibvirtException: Domain snapshot not found: no domain snapshot with matching name 'f4e51b11-ac79-4a6a-b887-8926ffbd5cca'
>         at org.apache.cloudstack.storage.snapshot.SnapshotServiceImpl.backupSnapshot(SnapshotServiceImpl.java:280)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.backupSnapshot(XenserverSnapshotStrategy.java:138)
>         at org.apache.cloudstack.storage.snapshot.XenserverSnapshotStrategy.takeSnapshot(XenserverSnapshotStrategy.java:264)
>         at com.cloud.storage.snapshot.SnapshotManagerImpl.takeSnapshot(SnapshotManagerImpl.java:1013)



--
This message was sent by Atlassian JIRA
(v6.1#6144)

Mime
View raw message