Thanks, Marcus. The virtual router can’t start, either.
2014-04-16 09:28:52,874 DEBUG [kvm.resource.KVMHAMonitor] (Thread-4:null)
Found NFS storage pool 9e3145ae-6074-4aa8-bbbf-05f2d8f284be in libvirt,
continuing
2014-04-16 09:28:52,875 DEBUG [kvm.resource.KVMHAMonitor] (Thread-4:null)
Executing:
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
192.168.0.131 -p /kvmPrimary -m /mnt/9e3145ae-6074-4aa8-bbbf-05f2d8f284be
-h 192.168.0.66
2014-04-16 09:28:52,901 DEBUG [kvm.resource.KVMHAMonitor] (Thread-4:null)
Execution is successful.
2014-04-16 09:28:53,485 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-2:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2014-04-16 09:28:53,623 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-2:null) Execution is successful.
2014-04-16 09:28:53,626 DEBUG [cloud.agent.Agent] (UgentTask-2:null)
Sending ping: Seq 5-2: { Cmd , MgmtId: -1, via: 5, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{}
,"newStates":{},"_hostVmStateReport":{},"_gatewayAccessible":true,"_vnetAcc
essible":true,"hostType":"Routing","hostId":5,"wait":0}}] }
2014-04-16 09:28:53,640 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null)
Received response: Seq 5-2: { Ans: , MgmtId: 345040294157, via: 5, Ver:
v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostI
d":5,"wait":0},"result":true,"wait":0}}] }
2014-04-16 09:29:03,044 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Request:Seq 5-6225930: { Cmd , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache
.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/3/535b2e9
9-c2f9-37fa-9667-abdd091eee41.qcow2","origUrl":"http://download.cloud.com/t
emplates/4.3/systemvm64template-2014-01-14-master-kvm.qcow2.bz2","uuid":"bb
63ad7c-bbfc-11e3-bb63-00505601110d","id":3,"format":"QCOW2","accountId":1,"
checksum":"85a1bed07bf43cbf022451cb2ecae4ff","hvm":false,"displayText":"Sys
temVM Template
(KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.
168.0.131/svm1_ccp_secondary
<http://192.168.0.131/svm1_ccp_secondary>","_role":"Image"}},"name":"routin
g-3","hypervisorType":"KVM"}},"destTO":{"org.apache.cloudstack.storage.to.T
emplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.3/system
vm64template-2014-01-14-master-kvm.qcow2.bz2","uuid":"bb63ad7c-bbfc-11e3-bb
63-00505601110d","id":3,"format":"QCOW2","accountId":1,"checksum":"85a1bed0
7bf43cbf022451cb2ecae4ff","hvm":false,"displayText":"SystemVM Template
(KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.
168.0.131/kvmPrimary
<http://192.168.0.131/kvmPrimary>","_role":"Primary","uuid":"9e3145ae-6074-
4aa8-bbbf-05f2d8f284be"}},"name":"routing-3","hypervisorType":"KVM"}},"exec
uteInSequence":true,"options":{},"wait":10800}}] }
2014-04-16 09:29:03,045 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Processing command:
org.apache.cloudstack.storage.command.CopyCommand
2014-04-16 09:29:03,047 WARN [cloud.agent.Agent]
(agentRequest-Handler-5:null) Caught:
java.lang.ClassCastException: com.cloud.agent.api.to.NfsTO cannot be cast
to org.apache.cloudstack.storage.to.PrimaryDataStoreTO
at
com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.copyTemplateToPrimaryS
torage(KVMStorageProcessor.java:150)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(Stora
geSubsystemCommandHandlerBase.java:75)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorage
Commands(StorageSubsystemCommandHandlerBase.java:50)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(L
ibvirtComputingResource.java:1359)
at com.cloud.agent.Agent.processRequest(Agent.java:498)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:806)
at com.cloud.utils.nio.Task.run(Task.java:83)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1
110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
603)
at java.lang.Thread.run(Thread.java:722)
2014-04-16 09:29:03,052 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Seq 5-6225930: { Ans: , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"java.lang.ClassCa
stException: com.cloud.agent.api.to.NfsTO cannot be cast to
org.apache.cloudstack.storage.to.PrimaryDataStoreTO\n\tat
com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.copyTemplateToPrimaryS
torage(KVMStorageProcessor.java:150)\n\tat
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(Stora
geSubsystemCommandHandlerBase.java:75)\n\tat
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorage
Commands(StorageSubsystemCommandHandlerBase.java:50)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(L
ibvirtComputingResource.java:1359)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:498)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:806)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1
110)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
603)\n\tat java.lang.Thread.run(Thread.java:722)\n","wait":0}}] }
2014-04-16 09:29:03,176 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Request:Seq 5-6225931: { Cmd , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":tr
ue,"checkBeforeCleanup":false,"vmName":"r-4-VM","wait":0}}] }
2014-04-16 09:29:03,177 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Processing command:
com.cloud.agent.api.StopCommand
2014-04-16 09:29:03,186 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find connection: KVM, for vm: r-4-VM,
continue
2014-04-16 09:29:03,198 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find connection: LXC, for vm: r-4-VM,
continue
2014-04-16 09:29:03,198 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find which hypervisor the vm used ,
then use the default hypervisor
2014-04-16 09:29:03,202 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:29:03,204 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:29:03,205 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:29:03,206 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-4-VM
2014-04-16 09:29:03,418 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Execution is successful.
2014-04-16 09:29:03,418 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Try to stop the vm at first
2014-04-16 09:29:03,420 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) VM r-4-VM doesn't exist, no need to stop it
2014-04-16 09:29:03,422 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Seq 5-6225931: { Ans: , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-04-16 09:29:03,600 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-2:null) Request:Seq 5-6225932: { Cmd , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":tr
ue,"checkBeforeCleanup":false,"vmName":"i-2-6-VM","wait":0}}] }
2014-04-16 09:29:03,600 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-2:null) Processing command:
com.cloud.agent.api.StopCommand
2014-04-16 09:29:03,604 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-2:null) can't find connection: KVM, for vm:
i-2-6-VM, continue
2014-04-16 09:29:03,606 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-2:null) can't find connection: LXC, for vm:
i-2-6-VM, continue
2014-04-16 09:29:03,606 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-2:null) can't find which hypervisor the vm used ,
then use the default hypervisor
2014-04-16 09:29:03,609 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'i-2-6-VM'
2014-04-16 09:29:03,611 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'i-2-6-VM'
2014-04-16 09:29:03,612 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'i-2-6-VM'
2014-04-16 09:29:03,612 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname i-2-6-VM
2014-04-16 09:29:03,813 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Execution is successful.
2014-04-16 09:29:03,813 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Try to stop the vm at first
2014-04-16 09:29:03,815 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) VM i-2-6-VM doesn't exist, no need to stop it
2014-04-16 09:29:03,816 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-2:null) Seq 5-6225932: { Ans: , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-04-16 09:29:04,352 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-3:null) Request:Seq 5-6225933: { Cmd , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 100111,
[{"org.apache.cloudstack.storage.command.CopyCommand":{"srcTO":{"org.apache
.cloudstack.storage.to.TemplateObjectTO":{"path":"template/tmpl/1/3/535b2e9
9-c2f9-37fa-9667-abdd091eee41.qcow2","origUrl":"http://download.cloud.com/t
emplates/4.3/systemvm64template-2014-01-14-master-kvm.qcow2.bz2","uuid":"bb
63ad7c-bbfc-11e3-bb63-00505601110d","id":3,"format":"QCOW2","accountId":1,"
checksum":"85a1bed07bf43cbf022451cb2ecae4ff","hvm":false,"displayText":"Sys
temVM Template
(KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.
168.0.131/svm1_ccp_secondary
<http://192.168.0.131/svm1_ccp_secondary>","_role":"Image"}},"name":"routin
g-3","hypervisorType":"KVM"}},"destTO":{"org.apache.cloudstack.storage.to.T
emplateObjectTO":{"origUrl":"http://download.cloud.com/templates/4.3/system
vm64template-2014-01-14-master-kvm.qcow2.bz2","uuid":"bb63ad7c-bbfc-11e3-bb
63-00505601110d","id":3,"format":"QCOW2","accountId":1,"checksum":"85a1bed0
7bf43cbf022451cb2ecae4ff","hvm":false,"displayText":"SystemVM Template
(KVM)","imageDataStore":{"com.cloud.agent.api.to.NfsTO":{"_url":"nfs://192.
168.0.131/kvmPrimary
<http://192.168.0.131/kvmPrimary>","_role":"Primary","uuid":"9e3145ae-6074-
4aa8-bbbf-05f2d8f284be"}},"name":"routing-3","hypervisorType":"KVM"}},"exec
uteInSequence":true,"options":{},"wait":10800}}] }
2014-04-16 09:29:04,352 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-3:null) Processing command:
org.apache.cloudstack.storage.command.CopyCommand
2014-04-16 09:29:04,353 WARN [cloud.agent.Agent]
(agentRequest-Handler-3:null) Caught:
java.lang.ClassCastException: com.cloud.agent.api.to.NfsTO cannot be cast
to org.apache.cloudstack.storage.to.PrimaryDataStoreTO
at
com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.copyTemplateToPrimaryS
torage(KVMStorageProcessor.java:150)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(Stora
geSubsystemCommandHandlerBase.java:75)
at
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorage
Commands(StorageSubsystemCommandHandlerBase.java:50)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(L
ibvirtComputingResource.java:1359)
at com.cloud.agent.Agent.processRequest(Agent.java:498)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:806)
at com.cloud.utils.nio.Task.run(Task.java:83)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1
110)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
603)
at java.lang.Thread.run(Thread.java:722)
2014-04-16 09:29:04,355 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-3:null) Seq 5-6225933: { Ans: , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.Answer":{"result":false,"details":"java.lang.ClassCa
stException: com.cloud.agent.api.to.NfsTO cannot be cast to
org.apache.cloudstack.storage.to.PrimaryDataStoreTO\n\tat
com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.copyTemplateToPrimaryS
torage(KVMStorageProcessor.java:150)\n\tat
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(Stora
geSubsystemCommandHandlerBase.java:75)\n\tat
com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorage
Commands(StorageSubsystemCommandHandlerBase.java:50)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(L
ibvirtComputingResource.java:1359)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:498)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:806)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1
110)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
603)\n\tat java.lang.Thread.run(Thread.java:722)\n","wait":0}}] }
2014-04-16 09:29:04,441 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-4:null) Request:Seq 5-6225934: { Cmd , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":tr
ue,"checkBeforeCleanup":false,"vmName":"r-4-VM","wait":0}}] }
2014-04-16 09:29:04,442 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-4:null) Processing command:
com.cloud.agent.api.StopCommand
2014-04-16 09:29:04,446 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-4:null) can't find connection: KVM, for vm: r-4-VM,
continue
2014-04-16 09:29:04,448 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-4:null) can't find connection: LXC, for vm: r-4-VM,
continue
2014-04-16 09:29:04,448 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-4:null) can't find which hypervisor the vm used ,
then use the default hypervisor
2014-04-16 09:29:04,453 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:29:04,455 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:29:04,457 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:29:04,457 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-4-VM
2014-04-16 09:29:04,660 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Execution is successful.
2014-04-16 09:29:04,661 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) Try to stop the vm at first
2014-04-16 09:29:04,663 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-4:null) VM r-4-VM doesn't exist, no need to stop it
2014-04-16 09:29:04,664 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-4:null) Seq 5-6225934: { Ans: , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-04-16 09:29:04,834 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Request:Seq 5-6225935: { Cmd , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 100111,
[{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":tr
ue,"checkBeforeCleanup":false,"vmName":"i-2-6-VM","wait":0}}] }
2014-04-16 09:29:04,834 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Processing command:
com.cloud.agent.api.StopCommand
2014-04-16 09:29:04,837 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-5:null) can't find connection: KVM, for vm:
i-2-6-VM, continue
2014-04-16 09:29:04,839 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-5:null) can't find connection: LXC, for vm:
i-2-6-VM, continue
2014-04-16 09:29:04,839 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-5:null) can't find which hypervisor the vm used ,
then use the default hypervisor
2014-04-16 09:29:04,842 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'i-2-6-VM'
2014-04-16 09:29:04,843 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'i-2-6-VM'
2014-04-16 09:29:04,845 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'i-2-6-VM'
2014-04-16 09:29:04,845 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname i-2-6-VM
2014-04-16 09:29:05,049 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Execution is successful.
2014-04-16 09:29:05,050 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) Try to stop the vm at first
2014-04-16 09:29:05,052 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-5:null) VM i-2-6-VM doesn't exist, no need to stop it
2014-04-16 09:29:05,054 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-5:null) Seq 5-6225935: { Ans: , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-04-16 09:29:08,977 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Processing command:
com.cloud.agent.api.GetStorageStatsCommand
2014-04-16 09:29:25,596 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-2:null) Processing command:
com.cloud.agent.api.GetHostStatsCommand
2014-04-16 09:29:25,596 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
2014-04-16 09:29:26,117 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Execution is successful.
2014-04-16 09:29:26,118 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Executing: /bin/bash -c freeMem=$(free|grep
cache:|awk '{print $4}');echo $freeMem
2014-04-16 09:29:26,126 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Execution is successful.
2014-04-16 09:29:26,127 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Executing: /bin/bash -c free|grep Mem:|awk
'{print $2}'
2014-04-16 09:29:26,133 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-2:null) Execution is successful.
2014-04-16 09:29:52,905 DEBUG [kvm.resource.KVMHAMonitor] (Thread-5:null)
Found NFS storage pool 9e3145ae-6074-4aa8-bbbf-05f2d8f284be in libvirt,
continuing
2014-04-16 09:29:52,906 DEBUG [kvm.resource.KVMHAMonitor] (Thread-5:null)
Executing:
/usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/kvmheartbeat.sh -i
192.168.0.131 -p /kvmPrimary -m /mnt/9e3145ae-6074-4aa8-bbbf-05f2d8f284be
-h 192.168.0.66
2014-04-16 09:29:52,943 DEBUG [kvm.resource.KVMHAMonitor] (Thread-5:null)
Execution is successful.
2014-04-16 09:29:53,485 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-3:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
get_rule_logs_for_vms
2014-04-16 09:29:53,613 DEBUG [kvm.resource.LibvirtComputingResource]
(UgentTask-3:null) Execution is successful.
2014-04-16 09:29:53,618 DEBUG [cloud.agent.Agent] (UgentTask-3:null)
Sending ping: Seq 5-3: { Cmd , MgmtId: -1, via: 5, Ver: v1, Flags: 11,
[{"com.cloud.agent.api.PingRoutingWithNwGroupsCommand":{"newGroupStates":{}
,"newStates":{},"_hostVmStateReport":{},"_gatewayAccessible":true,"_vnetAcc
essible":true,"hostType":"Routing","hostId":5,"wait":0}}] }
2014-04-16 09:29:53,634 DEBUG [cloud.agent.Agent] (Agent-Handler-4:null)
Received response: Seq 5-3: { Ans: , MgmtId: 345040294157, via: 5, Ver:
v1, Flags: 100010,
[{"com.cloud.agent.api.PingAnswer":{"_command":{"hostType":"Routing","hostI
d":5,"wait":0},"result":true,"wait":0}}] }
[root@rhelkvm1 agent]# tail -f /var/log/cloudstack/agent/agent.log
2014-04-16 09:30:56,988 DEBUG [kvm.resource.LibvirtConnection]
(agentRequest-Handler-1:null) can't find which hypervisor the vm used ,
then use the default hypervisor
2014-04-16 09:30:56,990 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:30:56,991 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:30:56,993 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Failed to get dom xml:
org.libvirt.LibvirtException: Domain not found: no domain with matching
name 'r-4-VM'
2014-04-16 09:30:56,993 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Executing:
/usr/share/cloudstack-common/scripts/vm/network/security_group.py
destroy_network_rules_for_vm --vmname r-4-VM
2014-04-16 09:30:57,200 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Execution is successful.
2014-04-16 09:30:57,201 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) Try to stop the vm at first
2014-04-16 09:30:57,203 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-1:null) VM r-4-VM doesn't exist, no need to stop it
2014-04-16 09:30:57,204 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-1:null) Seq 5-6225941: { Ans: , MgmtId:
345040294157, via: 5, Ver: v1, Flags: 110,
[{"com.cloud.agent.api.StopAnswer":{"result":true,"wait":0}}] }
2014-04-16 09:31:09,451 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-2:null) Processing command:
com.cloud.agent.api.GetStorageStatsCommand
2014-04-16 09:31:27,011 DEBUG [cloud.agent.Agent]
(agentRequest-Handler-3:null) Processing command:
com.cloud.agent.api.GetHostStatsCommand
2014-04-16 09:31:27,011 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
2014-04-16 09:31:27,541 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Execution is successful.
2014-04-16 09:31:27,542 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Executing: /bin/bash -c freeMem=$(free|grep
cache:|awk '{print $4}');echo $freeMem
2014-04-16 09:31:27,549 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Execution is successful.
2014-04-16 09:31:27,550 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Executing: /bin/bash -c free|grep Mem:|awk
'{print $2}'
2014-04-16 09:31:27,556 DEBUG [kvm.resource.LibvirtComputingResource]
(agentRequest-Handler-3:null) Execution is successful.
^C^C
[root@rhelkvm1 agent]#
David La Motta
Technical Marketing Engineer | Integrated Infrastructures
NetApp
Office: 1.919.476.5042
Mobile: 1.919.413.5600
On 4/16/14, 12:13 PM, "Marcus" <shadow...@gmail.com> wrote:
>turn on debugging for the agent:
>
>sed -i 's/INFO/DEBUG/g' /etc/cloudstack/agent/log4j-cloud.xml
>
>then look in /var/log/cloudstack/agent/agent.log
>
>
>On Wed, Apr 16, 2014 at 10:07 AM, La Motta, David
><david.lamo...@netapp.com> wrote:
>> Hi Jang, where exactly is that log file? :-)
>>
>>
>> David La Motta
>> Technical Marketing Engineer | Integrated Infrastructures
>>
>> NetApp
>> Office: 1.919.476.5042
>> Mobile: 1.919.413.5600
>>
>>
>>
>>
>> On 4/16/14, 11:25 AM, "Yitao Jiang" <willier...@gmail.com> wrote:
>>
>>>Hi, David
>>>
>>>Did u see anything wrong within kvm agent log file？
>>>
>>>
>>>
>>>Thanks,
>>>
>>>Yitao
>>>
>>>
>>>2014-04-16 22:59 GMT+08:00 La Motta, David <david.lamo...@netapp.com>:
>>>
>>>> Hey everybody, I am trying to deploy a VM instance in KVM using NFS
>>>>for
>>>> primary storage (on 4.3). Unfortunately, this is the exception I am
>>>> getting:
>>>>
>>>> 2014-04-16 06:44:53,128 DEBUG [o.a.c.e.o.VolumeOrchestrator]
>>>> (Work-Job-Executor-6:job-30/job-31 ctx-b83982e8) Unable to create
>>>> Vol[4|vm=4|ROOT]:java.lang.ClassCastException:
>>>> com.cloud.agent.api.to.NfsTO cannot be cast to
>>>> org.apache.cloudstack.storage.to.PrimaryDataStoreTO
>>>> at
>>>>
>>>>com.cloud.hypervisor.kvm.storage.KVMStorageProcessor.copyTemplateToPrim
>>>>ar
>>>>yS
>>>> torage(KVMStorageProcessor.java:150)
>>>> at
>>>>
>>>>com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(S
>>>>to
>>>>ra
>>>> geSubsystemCommandHandlerBase.java:75)
>>>> at
>>>>
>>>>com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleSto
>>>>ra
>>>>ge
>>>> Commands(StorageSubsystemCommandHandlerBase.java:50)
>>>> at
>>>>
>>>>com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeReque
>>>>st
>>>>(L
>>>> ibvirtComputingResource.java:1359)
>>>> at com.cloud.agent.Agent.processRequest(Agent.java:498)
>>>> at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:806)
>>>> at com.cloud.utils.nio.Task.run(Task.java:83)
>>>> at
>>>>
>>>>java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.ja
>>>>va
>>>>:1
>>>> 110)
>>>> at
>>>>
>>>>java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.j
>>>>av
>>>>a:
>>>> 603)
>>>> at java.lang.Thread.run(Thread.java:722)
>>>>
>>>>
>>>> Is this a known issue or are there any gotchas that I am overlooking?
>>>>
>>>> Thanks!
>>>>
>>>> // David
>>>>
>>>>
>>>> P.s., good to have seen some of you at CCCNA14 last week. Looking
>>>>forward
>>>> to Budapest.
>>>>
>>>>
>>
