[
https://issues.apache.org/jira/browse/CLOUDSTACK-597?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13526676#comment-13526676
]
Trevor Francis commented on CLOUDSTACK-597:
-------------------------------------------
2012-12-07 19:10:28,294 INFO [utils.nio.NioClient] (Agent-Selector:null) SSL:
Handshake done
2012-12-07 19:10:28,328 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) Detecting a new state but couldn't find a old state so
adding it to the changes: r-6-VM
2012-12-07 19:10:28,329 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) Detecting a new state but couldn't find a old state so
adding it to the changes: r-5-VM
2012-12-07 19:10:29,833 DEBUG [kvm.resource.LibvirtCapXMLParser]
(Agent-Handler-1:null) Found /usr/bin/kvm as a suiteable emulator
Agent Log:
2012-12-07 19:10:29,834 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) Executing: /bin/bash -c qemu-img --help|grep convert
2012-12-07 19:10:29,863 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) Execution is successful.
2012-12-07 19:10:29,864 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) convert [-c] [-p] [-f fmt] [-t cache] [-O output_fmt]
[-o options] [-s snapshot_name] [-S sparse_size] filename [filename2 [...]]
output_filename
2012-12-07 19:10:29,864 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) cpus=16, speed=2600, ram=67543527424, dom0ram=805306368
2012-12-07 19:10:29,869 DEBUG [cloud.resource.ServerResourceBase]
(Agent-Handler-1:null) Parameters for private nic: 172.16.0.12 -
00:25:90:77:a0:9f-255.255.0.0
2012-12-07 19:10:29,869 DEBUG [cloud.resource.ServerResourceBase]
(Agent-Handler-1:null) Parameters for storage nic: 172.16.0.12 -
00:25:90:77:a0:9f-255.255.0.0
2012-12-07 19:10:29,869 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) Executing:
/usr/lib/cloud/common/scripts/vm/hypervisor/versions.sh
2012-12-07 19:10:29,904 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) Execution is successful.
2012-12-07 19:10:29,944 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Executing: hostname
2012-12-07 19:10:29,950 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Execution is successful.
2012-12-07 19:10:29,951 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Executing: hostname
2012-12-07 19:10:29,957 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Execution is successful.
2012-12-07 19:10:30,059 INFO [cloud.serializer.GsonHelper]
(Agent-Handler-1:null) Default Builder inited.
2012-12-07 19:10:30,083 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Sending Startup: Seq 4-0: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 1,
[{"StartupRoutingCommand":{"cpus":16,"speed":2600,"memory":67543527424,"dom0MinMemory":805306368,"poolSync":false,"vms":{"r-6-VM":{"state":"Stopped"},"r-5-VM":{"state":"Stopped"}},"caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS":"Ubuntu","Host.OS.Kernel.Version":"3.2.0-34-generic","Host.OS.Version":"12.04"},"type":"Routing","dataCenter":"1","pod":"1","cluster":"1","guid":"16ccae39-95ea-3f12-a7a9-efcfe8ec8e06-LibvirtComputingResource","name":"compute1","id":4,"version":"4.0.0-incubating.20121024195401","privateIpAddress":"172.16.0.12","privateMacAddress":"00:25:90:77:a0:9f","privateNetmask":"255.255.0.0","storageIpAddress":"172.16.0.12","storageNetmask":"255.255.0.0","storageMacAddress":"00:25:90:77:a0:9f","resourceName":"LibvirtComputingResource","gatewayIpAddress":"172.16.0.1","wait":0}},{"StartupStorageCommand":{"totalSize":0,"poolInfo":{"uuid":"f74c5bac-acca-4b64-b0ef-23b65e64548e","host":"172.16.0.12","localPath":"/var/lib/libvirt/images/","hostPath":"/var/lib/libvirt/images/","poolType":"Filesystem","capacityBytes":920889008128,"availableBytes":1829376000},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"1","pod":"1","guid":"16ccae39-95ea-3f12-a7a9-efcfe8ec8e06-LibvirtComputingResource","name":"compute1","id":4,"version":"4.0.0-incubating.20121024195401","resourceName":"LibvirtComputingResource","wait":0}}]
}
2012-12-07 19:10:30,083 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Startup task created
2012-12-07 19:10:30,125 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null)
Received response: Seq 4-0: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100000,
[{"StartupAnswer":{"hostId":4,"pingInterval":60,"result":true,"wait":0}}] }
2012-12-07 19:10:30,125 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null)
Startup task cancelled
2012-12-07 19:10:30,125 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
Proccess agent startup answer, agent id = 4
2012-12-07 19:10:30,125 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Set
agent id 4
2012-12-07 19:10:30,140 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null) Adding
a watch list
2012-12-07 19:10:30,140 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
Startup Response Received: agent id = 4
2012-12-07 19:10:30,160 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-1:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:10:30,170 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Request:Seq 4-1537736705: { Cmd , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}}] }
2012-12-07 19:10:30,171 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Processing command: com.cloud.agent.api.StopCommand
2012-12-07 19:10:30,202 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-5-VM
2012-12-07 19:10:30,264 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-1:null) Execution is successful.
2012-12-07 19:10:30,268 DEBUG [cloud.agent.Agent] (UgentTask-1:null) Sending
ping: Seq 4-1: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:10:30,316 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null)
Received response: Seq 4-1: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:10:30,331 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Execution is successful.
2012-12-07 19:10:30,332 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Try to stop the vm at first
2012-12-07 19:10:30,348 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'f6288de9-594a-3745-8071-997f8ca60a30'
2012-12-07 19:10:30,350 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Seq 4-1537736705: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2012-12-07 19:10:30,518 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Processing command: com.cloud.agent.api.NetworkUsageCommand
2012-12-07 19:10:30,524 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Executing:
/usr/lib/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh
169.254.2.253 -g
2012-12-07 19:10:37,556 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Exit value is 1
2012-12-07 19:10:37,557 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null)
2012-12-07 19:10:37,557 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Failed to execute networkUsage:
2012-12-07 19:10:37,560 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Seq 4-1537736706: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1, Flags: 10,
[{"NetworkUsageAnswer":{"routerName":"r-6-VM","bytesSent":0,"bytesReceived":0,"result":true,"details":"","wait":0}}]
}
2012-12-07 19:10:37,568 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null)
Request:Seq 4-1537736707: { Cmd , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"r-6-VM","wait":0}}] }
2012-12-07 19:10:37,568 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null)
Processing command: com.cloud.agent.api.StopCommand
2012-12-07 19:10:37,594 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-6-VM
2012-12-07 19:10:37,723 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Execution is successful.
2012-12-07 19:10:37,723 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Try to stop the vm at first
2012-12-07 19:10:37,734 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'5b34a307-7433-3ae8-b172-87a5668e193b'
2012-12-07 19:10:37,735 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null)
Seq 4-1537736707: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2012-12-07 19:10:37,826 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Request:Seq 4-1537736708: { Cmd , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100101,
[{"StopCommand":{"isProxy":false,"vmName":"r-5-VM","wait":0}},{"StopCommand":{"isProxy":false,"vmName":"r-6-VM","wait":0}}]
}
2012-12-07 19:10:37,826 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Processing command: com.cloud.agent.api.StopCommand
2012-12-07 19:10:37,829 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'f6288de9-594a-3745-8071-997f8ca60a30'
2012-12-07 19:10:37,831 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'f6288de9-594a-3745-8071-997f8ca60a30'
2012-12-07 19:10:37,831 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-5-VM
2012-12-07 19:10:37,957 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Execution is successful.
2012-12-07 19:10:37,958 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Try to stop the vm at first
2012-12-07 19:10:37,960 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to stop VM :r-5-VM :
2012-12-07 19:10:37,962 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get vm status:Domain not found: no
domain with matching uuid 'f6288de9-594a-3745-8071-997f8ca60a30'
2012-12-07 19:10:37,964 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get vm status:Domain not found: no
domain with matching uuid 'f6288de9-594a-3745-8071-997f8ca60a30'
2012-12-07 19:10:37,965 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get vm status:Domain not found: no
domain with matching uuid 'f6288de9-594a-3745-8071-997f8ca60a30'
2012-12-07 19:10:37,965 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Can't get vm's status, assume it's dead already
2012-12-07 19:10:37,967 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'f6288de9-594a-3745-8071-997f8ca60a30'
2012-12-07 19:10:37,967 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Processing command: com.cloud.agent.api.StopCommand
2012-12-07 19:10:37,970 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'5b34a307-7433-3ae8-b172-87a5668e193b'
2012-12-07 19:10:37,972 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'5b34a307-7433-3ae8-b172-87a5668e193b'
2012-12-07 19:10:37,972 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-6-VM
2012-12-07 19:10:38,100 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Execution is successful.
2012-12-07 19:10:38,101 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Try to stop the vm at first
2012-12-07 19:10:38,103 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to stop VM :r-6-VM :
2012-12-07 19:10:38,106 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get vm status:Domain not found: no
domain with matching uuid '5b34a307-7433-3ae8-b172-87a5668e193b'
2012-12-07 19:10:38,107 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get vm status:Domain not found: no
domain with matching uuid '5b34a307-7433-3ae8-b172-87a5668e193b'
2012-12-07 19:10:38,109 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get vm status:Domain not found: no
domain with matching uuid '5b34a307-7433-3ae8-b172-87a5668e193b'
2012-12-07 19:10:38,109 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Can't get vm's status, assume it's dead already
2012-12-07 19:10:38,110 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching uuid
'5b34a307-7433-3ae8-b172-87a5668e193b'
2012-12-07 19:10:38,112 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4:null)
Seq 4-1537736708: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1, Flags: 100,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}},{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}]
}
2012-12-07 19:10:38,120 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Request:Seq 4-1537736709: { Cmd , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100011, [{"CleanupNetworkRulesCmd":{"interval":1839,"wait":0}}] }
2012-12-07 19:10:38,120 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Processing command: com.cloud.agent.api.CleanupNetworkRulesCmd
2012-12-07 19:10:38,120 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Adding a watch list
2012-12-07 19:10:38,121 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-4:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py cleanup_rules
2012-12-07 19:10:38,121 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null)
Seq 4-1537736709: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1, Flags: 10,
[{"Answer":{"result":true,"wait":0}}] }
2012-12-07 19:10:38,130 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Request:Seq 4-1537736710: { Cmd , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100011,
[{"ModifyStoragePoolCommand":{"add":true,"pool":{"id":200,"uuid":"157108d3-89be-333c-9ead-f3d19dfd2367","host":"172.16.0.5","path":"/export/primary","port":2049,"type":"NetworkFilesystem"},"localPath":"/mnt//157108d3-89be-333c-9ead-f3d19dfd2367","wait":0}}]
}
2012-12-07 19:10:38,131 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Processing command: com.cloud.agent.api.ModifyStoragePoolCommand
2012-12-07 19:10:38,203 DEBUG [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-1:null) <pool type='netfs'>
2012-12-07 19:10:38,206 DEBUG [kvm.resource.LibvirtComputingResource]
(Agent-Handler-4:null) Execution is successful.
2012-12-07 19:10:38,207 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null) Watch
Sent: Seq 4-1537736709: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1, Flags:
10, [{"Answer":{"result":true,"details":"","wait":0}}] }
2012-12-07 19:10:38,478 DEBUG [cloud.agent.Agent] (agentRequest-Handler-1:null)
Seq 4-1537736710: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1, Flags: 10,
[{"ModifyStoragePoolAnswer":{"poolInfo":{"host":"172.16.0.5","localPath":"/mnt//157108d3-89be-333c-9ead-f3d19dfd2367","hostPath":"/export/primary","poolType":"NetworkFilesystem","capacityBytes":245945597952,"availableBytes":4432330752},"templateInfo":{},"result":true,"wait":0}}]
}
2012-12-07 19:10:38,530 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Request:Seq 4-1537736711: { Cmd , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100011,
[{"ModifyStoragePoolCommand":{"add":true,"pool":{"id":201,"uuid":"21beae1e-c6af-3fb5-8a80-ae1e419db1a5","host":"ceph","path":"rbd","userInfo":":","port":6789,"type":"RBD"},"localPath":"/mnt//17c1e9ec-eade-365c-9fb0-2dd9ae9a07d4","wait":0}}]
}
2012-12-07 19:10:38,530 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null)
Processing command: com.cloud.agent.api.ModifyStoragePoolCommand
2012-12-07 19:10:38,535 DEBUG [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-2:null) <pool type='rbd'>
2012-12-07 19:11:03,547 DEBUG [kvm.resource.KVMHAMonitor] (Thread-6:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:11:03,599 DEBUG [kvm.resource.KVMHAMonitor] (Thread-6:null)
Execution is successful.
2012-12-07 19:11:30,149 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-2:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:11:30,273 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-2:null) Execution is successful.
2012-12-07 19:11:30,275 DEBUG [cloud.agent.Agent] (UgentTask-2:null) Sending
ping: Seq 4-2: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:11:30,322 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null)
Received response: Seq 4-2: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:12:03,601 DEBUG [kvm.resource.KVMHAMonitor] (Thread-7:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:12:03,634 DEBUG [kvm.resource.KVMHAMonitor] (Thread-7:null)
Execution is successful.
2012-12-07 19:12:30,149 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-3:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:12:30,273 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-3:null) Execution is successful.
2012-12-07 19:12:30,276 DEBUG [cloud.agent.Agent] (UgentTask-3:null) Sending
ping: Seq 4-3: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:12:30,327 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null)
Received response: Seq 4-3: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:13:03,638 DEBUG [kvm.resource.KVMHAMonitor] (Thread-8:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:13:03,671 DEBUG [kvm.resource.KVMHAMonitor] (Thread-8:null)
Execution is successful.
2012-12-07 19:13:30,149 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-4:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:13:30,273 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-4:null) Execution is successful.
2012-12-07 19:13:30,277 DEBUG [cloud.agent.Agent] (UgentTask-4:null) Sending
ping: Seq 4-4: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:13:30,357 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null)
Received response: Seq 4-4: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:14:03,674 DEBUG [kvm.resource.KVMHAMonitor] (Thread-9:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:14:03,708 DEBUG [kvm.resource.KVMHAMonitor] (Thread-9:null)
Execution is successful.
2012-12-07 19:14:30,150 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:14:30,271 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Execution is successful.
2012-12-07 19:14:30,275 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 4-5: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:14:30,323 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null)
Received response: Seq 4-5: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:15:03,710 DEBUG [kvm.resource.KVMHAMonitor] (Thread-10:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:15:03,744 DEBUG [kvm.resource.KVMHAMonitor] (Thread-10:null)
Execution is successful.
2012-12-07 19:15:30,148 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:15:30,272 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Execution is successful.
2012-12-07 19:15:30,276 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 4-6: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:15:30,327 DEBUG [cloud.agent.Agent] (Agent-Handler-1:null)
Received response: Seq 4-6: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:16:03,746 DEBUG [kvm.resource.KVMHAMonitor] (Thread-11:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:16:03,781 DEBUG [kvm.resource.KVMHAMonitor] (Thread-11:null)
Execution is successful.
2012-12-07 19:16:30,149 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:16:30,272 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Execution is successful.
2012-12-07 19:16:30,276 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 4-7: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:16:30,325 DEBUG [cloud.agent.Agent] (Agent-Handler-2:null)
Received response: Seq 4-7: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:17:03,782 DEBUG [kvm.resource.KVMHAMonitor] (Thread-12:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:17:03,816 DEBUG [kvm.resource.KVMHAMonitor] (Thread-12:null)
Execution is successful.
2012-12-07 19:17:30,150 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:17:30,272 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Execution is successful.
2012-12-07 19:17:30,276 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 4-8: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:17:30,327 DEBUG [cloud.agent.Agent] (Agent-Handler-3:null)
Received response: Seq 4-8: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:18:03,819 DEBUG [kvm.resource.KVMHAMonitor] (Thread-13:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:18:03,852 DEBUG [kvm.resource.KVMHAMonitor] (Thread-13:null)
Execution is successful.
2012-12-07 19:18:30,150 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Executing:
/usr/lib/cloud/common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2012-12-07 19:18:30,272 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-5:null) Execution is successful.
2012-12-07 19:18:30,276 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending
ping: Seq 4-9: { Cmd , MgmtId: -1, via: 4, Ver: v1, Flags: 11,
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":4,"wait":0}}]
}
2012-12-07 19:18:30,325 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null)
Received response: Seq 4-9: { Ans: , MgmtId: 207379522204, via: 4, Ver: v1,
Flags: 100010,
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":4,"wait":0},"result":true,"wait":0}}]
}
2012-12-07 19:19:03,855 DEBUG [kvm.resource.KVMHAMonitor] (Thread-14:null)
Executing: /usr/lib/cloud/common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
172.16.0.5 -p /export/primary -m /mnt/157108d3-89be-333c-9ead-f3d19dfd2367 -h
172.16.0.12
2012-12-07 19:19:03,889 DEBUG [kvm.resource.KVMHAMonitor] (Thread-14:null)
Execution is successful.
> Management Server Restart loses hosts
> -------------------------------------
>
> Key: CLOUDSTACK-597
> URL: https://issues.apache.org/jira/browse/CLOUDSTACK-597
> Project: CloudStack
> Issue Type: Bug
> Security Level: Public(Anyone can view this level - this is the
> default.)
> Components: Management Server
> Affects Versions: 4.0.0
> Environment: Ubuntu 12.04 ~ 4.0.0-incubating.20121024195401
> NFS Primary Storage, Ceph Primary Storage, Local Storage
> Reporter: Trevor Francis
> Priority: Critical
>
> A cloud-management restart looses hosts. Hosts show "Disconnected" and are
> unable to reconnect. A Force Reconnect give me a : Command failed due to
> Internal Server Error :
> Agents are showing that they are connected to the management server.
--
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
