You are viewing a plain text version of this content. The canonical link for it is here.

Posted to users@cloudstack.apache.org by Mahfuj Jia <ma...@gmail.com> on 2013/01/15 16:22:02 UTC

Host installed ok. Only problem appears to be with the System VMs coming up

Hi, I am using CloudStack4 official installation guide and successfully
installed the following things


1. One Management Server. (Linux Centos x86_64)
2. One KVM host server. (Linux Centos x86_64)

Cloudstack 4.0 installation process:

At Management Server:

1. Install cloud-client. (Successfully)
2. Install Mysql Server. (Succesfully)
3. Cloud Database Created. (Successfully)
4. NFS Server installed. (Successfully).
5. NFS Share. (Successfully)


At Client Machine:

1. Install cloud-agent. (Successfully)
2. NFS mount. (Successfully)

The main problem is after successfully adding host from CloudStack user
interface  when System VM coming up following exceptions has thrown

 *Exception while trying to start secondary storage vm*
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to Unable to get answer
that is of class com.cloud.agent.api.StartAnswer

2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Failed to start instance VM[SecondaryStorageVm|s-142-VM]
java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer

2013-01-15 03:05:55,580 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl]
(secstorage-1:null)*Primary secondary storage is not even started,
wait until next turn
*


How I  will solve this problem.Please if you have any recommendation tell
me.

Re: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Mahfuj Jia <ma...@gmail.com>.

Thanks for replying

I am using kvm hypervisor

And the Management server exception is

2013-01-15 05:39:55,678 WARN
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Exception while trying to start secondary storage vm
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to
com.cloud.agent.api.Answer cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        ... 20 more
2013-01-15 05:39:55,679 INFO
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Unable to start secondary storage vm for standby capacity,
secStorageVm vm Id : 296, will recycle it and start a new one
2013-01-15 05:39:55,679 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl]
(secstorage-1:null) Primary secondary storage is not even started,
wait until next turn
2013-01-15 05:40:00,255 DEBUG [cloud.template.TemplateManagerImpl]
(consoleproxy-1:null) Downloading 3 via 1
2013-01-15 05:40:00,260 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227198: Sending  { Cmd , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 100111,
[{"storage.PrimaryStorageDownloadCommand":{"localPath":"/var/lib/libvirt/images/","poolUuid":"9652649a-6c25-403a-88b8-7e609f706e27","poolId":201,"secondaryStorageUrl":"nfs://192.168.71.50/export/secondary","primaryStorageUrl":"nfs://192.168.71.41/var/lib/libvirt/images/","url":"nfs://192.168.71.50/export/secondary/template/tmpl/1/3/","format":"QCOW2","accountId":1,"name":"routing-3","wait":10800}}]
}
2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
(AgentManager-Handler-14:null) Seq 1-2027227198: Processing:  { Ans: ,
MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
[{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)\n\tat
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-14:null) Seq 1-2027227198: No more commands
found
2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227198: Received:  { Ans: , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 110, { Answer } }
2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentManagerImpl]
(consoleproxy-1:null) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)

2013-01-15 05:40:00,342 ERROR [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Failed to start instance
VM[ConsoleProxy|v-83-VM]
java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be
cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-15 05:40:00,349 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Cleaning up resources for the vm
VM[ConsoleProxy|v-83-VM] in Starting state
2013-01-15 05:40:00,351 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227199: Sending  { Cmd , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 100111,
[{"StopCommand":{"isProxy":false,"vmName":"v-83-VM","wait":0}}] }
2013-01-15 05:40:00,601 DEBUG [agent.transport.Request]
(AgentManager-Handler-15:null) Seq 1-2027227199: Processing:  { Ans: ,
MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2013-01-15 05:40:00,602 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-15:null) Seq 1-2027227199: No more commands
found
2013-01-15 05:40:00,602 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227199: Received:  { Ans: , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,650 DEBUG [network.guru.ControlNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[329-83-null-null-null
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,662 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(consoleproxy-1:null) Releasing ip address for
reservationId=37122d6d-0259-4b1a-8638-6b6148037bd9, instance=330
2013-01-15 05:40:00,666 DEBUG [network.guru.PodBasedNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[330-83-null-null-null
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully released network resources for the
vm VM[ConsoleProxy|v-83-VM]
2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully cleanued up resources for the vm
VM[ConsoleProxy|v-83-VM] in Starting state
2013-01-15 05:40:00,678 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Starting to Stopped
with event: OperationFailedvm's original host id: null new host id:
null host id before state transition: 1
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total CPU: 8000 and CPU after
applying overprovisioning: 8000
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release cpu from host: 1, old used:
500,reserved: 0, actual total: 8000, total with overprovisioning:
8000; new used: 0,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release mem from host: 1, old used:
1073741824,reserved: 0, total: 16726679552; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-01-15 05:40:00,685 WARN
[cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Exception while trying to start console proxy
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to
com.cloud.agent.api.Answer cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        ... 19 more

An this is KVM cloud agent exception


[root@kvm01 agent]# tail -f agent.log
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-16 01:51:18,634 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-1:null) org.libvirt.LibvirtException: internal
error Child process (/bin/mount
192.168.71.50:/export/secondary/template/tmpl/1/3
/mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit
status 32
2013-01-16 01:51:18,640 WARN  [cloud.agent.Agent]
(agentRequest-Handler-1:null) Caught:
java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-16 01:51:18,956 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-4:null) org.libvirt.LibvirtException: internal
error Child process (/bin/mount
192.168.71.50:/export/secondary/template/tmpl/1/3
/mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit
status 32
2013-01-16 01:51:18,961 WARN  [cloud.agent.Agent]
(agentRequest-Handler-4:null) Caught:


If you have any suggestion please give me.I am stacked in this portion
since 2 weeks

Thanks










On 1/18/13, Asmita Vagyani <As...@sigma-systems.com> wrote:
> Hi Mahfuj,
> What is the exception stacktrace you get?
> Which is the hypervisor you are using?
> Also, the primary and secondary storage have to be set up as a part of zone
> configuration, if done properly then system vm will get intialized
> automatcially into cloudstack.
>
> Thanks and Regards.
>
> Asmita Patil Vagyani.
>
>
> -----Original Message-----
> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
> Sent: 17 January 2013 PM 06:35
> To: cloudstack-users@incubator.apache.org
> Subject: Re: Host installed ok. Only problem appears to be with the System
> VMs coming up
>
> Do you have any suggestion or steps or documentation that  can install the
> cloud stack4 with successfully installed system vm.I have followed official
> document and successfully installed every thing without error but when
> system vm coming up give me secondary storage exception.Please help me.
>
> On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
>> Thanks for your reply
>>
>> How do I test the storage pool is reachable to the host?Yes I manually
>> mount it and verify  the primary storage mount point can be mounted on
>> the host and its reachable.In graphical User Interface Secondary
>> storage allocation 0%.
>>
>> Please give me instructions that How can I setup System VM and also
>> the primary and secondary storage successfully.
>>
>> Thanks Please reply
>>
>>
>> On 1/16/13, Rajesh Battala <ra...@citrix.com> wrote:
>>> Hi Mahfuj,
>>>
>>> From the logs it looks like issue while mounting the primary storage
>>> mount point on the host.
>>> Is the storage pool is reachable to the host?.
>>> Can you manually mount it and verify whether the primary storage
>>> mount point can be mounted on the host or not and its reachable.
>>>
>>> Thanks
>>> Rajesh Battala
>>>
>>> -----Original Message-----
>>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>>> Sent: Wednesday, January 16, 2013 4:13 PM
>>> To: cloudstack-users@incubator.apache.org
>>> Subject: Re: Host installed ok. Only problem appears to be with the
>>> System VMs coming up
>>>
>>> Hi I am waiting for your reply
>>>
>>> This is our Management server log
>>> 2013-01-15 05:39:55,615 DEBUG [network.guru.PodBasedNetworkGuru]
>>> (secstorage-1:null) Released nic: NicProfile[1181-296-null-null-null
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking JuniperSRX to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking Netscaler to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking F5BigIP to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking VirtualRouter to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking Ovs to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking ExternalDhcpServer to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking BareMetal to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking SecurityGroupProvider to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking VpcVirtualRouter to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking NiciraNvp to release
>>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,627 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
>>> (secstorage-1:null) Releasing ip address for
>>> reservationId=a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf, instance=1182
>>> 2013-01-15 05:39:55,643 DEBUG
>>> [network.router.VirtualNetworkApplianceManagerImpl]
>>> (RouterStatusMonitor-1:null) Found 0 routers.
>>> 2013-01-15 05:39:55,650 DEBUG [network.guru.PodBasedNetworkGuru]
>>> (secstorage-1:null) Released nic: NicProfile[1182-296-null-null-null
>>> 2013-01-15 05:39:55,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking JuniperSRX to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking Netscaler to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking F5BigIP to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking VirtualRouter to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking Ovs to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking ExternalDhcpServer to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking BareMetal to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking SecurityGroupProvider to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking VpcVirtualRouter to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>>> (secstorage-1:null) Asking NiciraNvp to release
>>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>>> (secstorage-1:null) Successfully released network resources for the
>>> vm VM[SecondaryStorageVm|s-296-VM]
>>> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>>> (secstorage-1:null) Successfully cleanued up resources for the vm
>>> VM[SecondaryStorageVm|s-296-VM] in Starting state
>>> 2013-01-15 05:39:55,671 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (secstorage-1:null) VM state transitted from :Starting to Stopped
>>> with
>>> event: OperationFailedvm's original host id: null new host id: null
>>> host id before state transition: 1
>>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (secstorage-1:null) Hosts's actual total CPU: 8000 and CPU after
>>> applying
>>> overprovisioning: 8000
>>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (secstorage-1:null) release cpu from host: 1, old used: 1000,reserved:
>>> 0, actual total: 8000, total with overprovisioning: 8000; new used:
>>> 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
>>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (secstorage-1:null) release mem from host: 1, old used:
>>> 1342177280,reserved: 0, total: 16726679552; new used:
>>> 1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
>>> 2013-01-15 05:39:55,678 WARN
>>> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
>>> Exception while trying to start secondary storage vm
>>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>>> unreachable: Host 1: Unable to start instance due to
>>> com.cloud.agent.api.Answer cannot be cast to
>>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>>         at
>>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
>>>         at
>>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
>>>         at
>>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
>>>         at
>>> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
>>>         at
>>> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>>         at
>>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>>         at
>>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>>         at
>>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>>         at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>>         at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>>         at java.lang.Thread.run(Thread.java:679)
>>> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
>>> cannot be cast to
>>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>         at
>>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>>         at
>>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>>         at
>>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>>         at
>>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>>         ... 20 more
>>> 2013-01-15 05:39:55,679 INFO
>>> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
>>> Unable to start secondary storage vm for standby capacity,
>>> secStorageVm vm Id :
>>> 296, will recycle it and start a new one
>>> 2013-01-15 05:39:55,679 INFO
>>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>>> (secstorage-1:null) Primary secondary storage is not even started,
>>> wait until next turn
>>> 2013-01-15 05:40:00,255 DEBUG [cloud.template.TemplateManagerImpl]
>>> (consoleproxy-1:null) Downloading 3 via 1
>>> 2013-01-15 05:40:00,260 DEBUG [agent.transport.Request]
>>> (consoleproxy-1:null) Seq 1-2027227198: Sending  { Cmd , MgmtId:
>>> 52242164673, via: 1, Ver: v1, Flags: 100111,
>>> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/var/lib/libv
>>> irt/images/","poolUuid":"9652649a-6c25-403a-88b8-7e609f706e27","poolI
>>> d":201,"secondaryStorageUrl":"nfs://192.168.71.50/export/secondary","
>>> primaryStorageUrl":"nfs://192.168.71.41/var/lib/libvirt/images/","url
>>> ":"nfs://192.168.71.50/export/secondary/template/tmpl/1/3/","format":
>>> "QCOW2","accountId":1,"name":"routing-3","wait":10800}}]
>>> }
>>> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
>>> (AgentManager-Handler-14:null) Seq 1-2027227198: Processing:  { Ans:
>>> ,
>>> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
>>> [{"Answer":{"result":false,"details":"java.lang.NullPointerException\
>>> n\tat
>>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStorageP
>>> ool(LibvirtStorageAdaptor.java:462)\n\tat
>>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePool
>>> ByURI(LibvirtStorageAdaptor.java:745)\n\tat
>>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool
>>> ByURI(KVMStoragePoolManager.java:52)\n\tat
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(Li
>>> bvirtComputingResource.java:2017)\n\tat
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeReq
>>> uest(LibvirtComputingResource.java:1009)\n\tat
>>> com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
>>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\ta
>>> t com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
>>> java:1110)\n\tat
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
>>> .java:603)\n\tat java.lang.Thread.run(Thread.java:679)\n","wait":0}}]
>>> }
>>> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentAttache]
>>> (AgentManager-Handler-14:null) Seq 1-2027227198: No more commands
>>> found
>>> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
>>> (consoleproxy-1:null) Seq 1-2027227198: Received:  { Ans: , MgmtId:
>>> 52242164673, via: 1, Ver: v1, Flags: 110, { Answer } }
>>> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentManagerImpl]
>>> (consoleproxy-1:null) Details from executing class
>>> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
>>> java.lang.NullPointerException
>>>         at
>>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>>>         at
>>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>>         at
>>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>>         at
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>>         at
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>>         at
>>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>>         at java.lang.Thread.run(Thread.java:679)
>>>
>>> 2013-01-15 05:40:00,342 ERROR [cloud.vm.VirtualMachineManagerImpl]
>>> (consoleproxy-1:null) Failed to start instance
>>> VM[ConsoleProxy|v-83-VM]
>>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be
>>> cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>         at
>>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>>         at
>>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>>         at
>>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>>         at
>>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>>         at
>>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>>         at
>>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>>         at
>>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>>         at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>>         at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>>         at java.lang.Thread.run(Thread.java:679)
>>> 2013-01-15 05:40:00,349 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>>> (consoleproxy-1:null) Cleaning up resources for the vm
>>> VM[ConsoleProxy|v-83-VM] in Starting state
>>> 2013-01-15 05:40:00,351 DEBUG [agent.transport.Request]
>>> (consoleproxy-1:null) Seq 1-2027227199: Sending  { Cmd , MgmtId:
>>> 52242164673, via: 1, Ver: v1, Flags: 100111,
>>> [{"StopCommand":{"isProxy":false,"vmName":"v-83-VM","wait":0}}] }
>>> 2013-01-15 05:40:00,601 DEBUG [agent.transport.Request]
>>> (AgentManager-Handler-15:null) Seq 1-2027227199: Processing:  { Ans:
>>> ,
>>> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
>>> [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
>>> 2013-01-15 05:40:00,602 DEBUG [agent.manager.AgentAttache]
>>> (AgentManager-Handler-15:null) Seq 1-2027227199: No more commands
>>> found
>>> 2013-01-15 05:40:00,602 DEBUG [agent.transport.Request]
>>> (consoleproxy-1:null) Seq 1-2027227199: Received:  { Ans: , MgmtId:
>>> 52242164673, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking JuniperSRX to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking Netscaler to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking F5BigIP to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking VirtualRouter to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking Ovs to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking ExternalDhcpServer to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking BareMetal to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking SecurityGroupProvider to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking VpcVirtualRouter to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking NiciraNvp to release
>>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>>> 2013-01-15 05:40:00,650 DEBUG [network.guru.ControlNetworkGuru]
>>> (consoleproxy-1:null) Released nic: NicProfile[329-83-null-null-null
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking JuniperSRX to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking Netscaler to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking F5BigIP to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking VirtualRouter to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking Ovs to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking ExternalDhcpServer to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking BareMetal to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking SecurityGroupProvider to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking VpcVirtualRouter to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking NiciraNvp to release
>>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,662 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
>>> (consoleproxy-1:null) Releasing ip address for
>>> reservationId=37122d6d-0259-4b1a-8638-6b6148037bd9, instance=330
>>> 2013-01-15 05:40:00,666 DEBUG [network.guru.PodBasedNetworkGuru]
>>> (consoleproxy-1:null) Released nic: NicProfile[330-83-null-null-null
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking JuniperSRX to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking Netscaler to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking F5BigIP to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking VirtualRouter to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking Ovs to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking ExternalDhcpServer to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking BareMetal to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking SecurityGroupProvider to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking VpcVirtualRouter to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>>> (consoleproxy-1:null) Asking NiciraNvp to release
>>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>>> (consoleproxy-1:null) Successfully released network resources for the
>>> vm VM[ConsoleProxy|v-83-VM]
>>> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>>> (consoleproxy-1:null) Successfully cleanued up resources for the vm
>>> VM[ConsoleProxy|v-83-VM] in Starting state
>>> 2013-01-15 05:40:00,678 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (consoleproxy-1:null) VM state transitted from :Starting to Stopped
>>> with
>>> event: OperationFailedvm's original host id: null new host id:
>>> null host id before state transition: 1
>>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (consoleproxy-1:null) Hosts's actual total CPU: 8000 and CPU after
>>> applying
>>> overprovisioning: 8000
>>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (consoleproxy-1:null) release cpu from host: 1, old used:
>>> 500,reserved: 0, actual total: 8000, total with overprovisioning:
>>> 8000; new used: 0,reserved:0; movedfromreserved:
>>> false,moveToReserveredfalse
>>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>>> (consoleproxy-1:null) release mem from host: 1, old used:
>>> 1073741824,reserved: 0, total: 16726679552; new used: 0,reserved:0;
>>> movedfromreserved: false,moveToReserveredfalse
>>> 2013-01-15 05:40:00,685 WARN
>>> [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
>>> Exception while trying to start console proxy
>>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>>> unreachable: Host 1: Unable to start instance due to
>>> com.cloud.agent.api.Answer cannot be cast to
>>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>>>         at
>>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>>         at
>>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>>         at
>>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>>         at
>>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>>         at
>>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>>         at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>>         at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>>         at java.lang.Thread.run(Thread.java:679)
>>> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
>>> cannot be cast to
>>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>         at
>>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>>         at
>>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>>         at
>>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>>         at
>>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>>         at
>>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>>         ... 19 more
>>>
>>>
>>>
>>>
>>>
>>> ---------------------------------------------
>>>
>>>
>>> And this is KVM Agent log
>>>
>>>
>>> [root@kvm01 agent]# tail -f agent.log
>>>         at
>>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>>         at
>>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>>         at
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>>         at
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>>         at
>>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>>         at java.lang.Thread.run(Thread.java:679)
>>> 2013-01-16 01:51:18,634 ERROR [kvm.storage.LibvirtStorageAdaptor]
>>> (agentRequest-Handler-1:null) org.libvirt.LibvirtException: internal
>>> error Child process (/bin/mount
>>> 192.168.71.50:/export/secondary/template/tmpl/1/3
>>> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit
>>> status
>>> 32
>>> 2013-01-16 01:51:18,640 WARN  [cloud.agent.Agent]
>>> (agentRequest-Handler-1:null) Caught:
>>> java.lang.NullPointerException
>>>         at
>>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>>>         at
>>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>>         at
>>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>>         at
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>>         at
>>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>>         at
>>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>>         at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>>         at java.lang.Thread.run(Thread.java:679)
>>> 2013-01-16 01:51:18,956 ERROR [kvm.storage.LibvirtStorageAdaptor]
>>> (agentRequest-Handler-4:null) org.libvirt.LibvirtException: internal
>>> error Child process (/bin/mount
>>> 192.168.71.50:/export/secondary/template/tmpl/1/3
>>> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit
>>> status
>>> 32
>>> 2013-01-16 01:51:18,961 WARN  [cloud.agent.Agent]
>>> (agentRequest-Handler-4:null) Caught:
>>>
>>>
>>>
>>> On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
>>>> Thanks for your replying
>>>>
>>>> I have send you Logs.zip file.Please sir give me suggestion.
>>>>
>>>> On Tue, Jan 15, 2013 at 10:07 PM, Rajesh Battala
>>>> <ra...@citrix.com>wrote:
>>>>
>>>>> Hi Mahfuj,
>>>>> Can you post the DEBUG log of MS and kvm agent.
>>>>>
>>>>> Thanks
>>>>> Rajesh Battala
>>>>>
>>>>> -----Original Message-----
>>>>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>>>>> Sent: Tuesday, January 15, 2013 8:52 PM
>>>>> To: cloudstack-users@incubator.apache.org
>>>>> Subject: Host installed ok. Only problem appears to be with the
>>>>> System VMs coming up
>>>>>
>>>>> Hi, I am using CloudStack4 official installation guide and
>>>>> successfully installed the following things
>>>>>
>>>>>
>>>>> 1. One Management Server. (Linux Centos x86_64) 2. One KVM host
>>>>> server.
>>>>> (Linux Centos x86_64)
>>>>>
>>>>> Cloudstack 4.0 installation process:
>>>>>
>>>>> At Management Server:
>>>>>
>>>>> 1. Install cloud-client. (Successfully) 2. Install Mysql Server.
>>>>> (Succesfully) 3. Cloud Database Created. (Successfully) 4. NFS
>>>>> Server installed.
>>>>> (Successfully).
>>>>> 5. NFS Share. (Successfully)
>>>>>
>>>>>
>>>>> At Client Machine:
>>>>>
>>>>> 1. Install cloud-agent. (Successfully) 2. NFS mount. (Successfully)
>>>>>
>>>>> The main problem is after successfully adding host from CloudStack
>>>>> user interface  when System VM coming up following exceptions has
>>>>> thrown
>>>>>
>>>>>  *Exception while trying to start secondary storage vm*
>>>>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>>>>> unreachable: Host 1: Unable to start instance due to Unable to get
>>>>> answer that is of class com.cloud.agent.api.StartAnswer
>>>>>
>>>>> 2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
>>>>> (secstorage-1:null) Failed to start instance
>>>>> VM[SecondaryStorageVm|s-142-VM]
>>>>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be
>>>>> cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>>>
>>>>> 2013-01-15 03:05:55,580 INFO
>>>>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>>>>> (secstorage-1:null)*Primary secondary storage is not even started,
>>>>> wait until next turn
>>>>> *
>>>>>
>>>>>
>>>>> How I  will solve this problem.Please if you have any
>>>>> recommendation tell me.
>>>>>
>>>>
>>>
>>
>
>
>

RE: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Asmita Vagyani <As...@sigma-systems.com>.

Hi Mahfuj,
What is the exception stacktrace you get?
Which is the hypervisor you are using?
Also, the primary and secondary storage have to be set up as a part of zone configuration, if done properly then system vm will get intialized automatcially into cloudstack.

Thanks and Regards.

Asmita Patil Vagyani. 


-----Original Message-----
From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com] 
Sent: 17 January 2013 PM 06:35
To: cloudstack-users@incubator.apache.org
Subject: Re: Host installed ok. Only problem appears to be with the System VMs coming up

Do you have any suggestion or steps or documentation that  can install the cloud stack4 with successfully installed system vm.I have followed official document and successfully installed every thing without error but when system vm coming up give me secondary storage exception.Please help me.

On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
> Thanks for your reply
>
> How do I test the storage pool is reachable to the host?Yes I manually 
> mount it and verify  the primary storage mount point can be mounted on 
> the host and its reachable.In graphical User Interface Secondary 
> storage allocation 0%.
>
> Please give me instructions that How can I setup System VM and also 
> the primary and secondary storage successfully.
>
> Thanks Please reply
>
>
> On 1/16/13, Rajesh Battala <ra...@citrix.com> wrote:
>> Hi Mahfuj,
>>
>> From the logs it looks like issue while mounting the primary storage 
>> mount point on the host.
>> Is the storage pool is reachable to the host?.
>> Can you manually mount it and verify whether the primary storage 
>> mount point can be mounted on the host or not and its reachable.
>>
>> Thanks
>> Rajesh Battala
>>
>> -----Original Message-----
>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>> Sent: Wednesday, January 16, 2013 4:13 PM
>> To: cloudstack-users@incubator.apache.org
>> Subject: Re: Host installed ok. Only problem appears to be with the 
>> System VMs coming up
>>
>> Hi I am waiting for your reply
>>
>> This is our Management server log
>> 2013-01-15 05:39:55,615 DEBUG [network.guru.PodBasedNetworkGuru]
>> (secstorage-1:null) Released nic: NicProfile[1181-296-null-null-null
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking JuniperSRX to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Netscaler to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking F5BigIP to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VirtualRouter to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Ovs to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking ExternalDhcpServer to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking BareMetal to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking SecurityGroupProvider to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking CiscoNexus1000vVSM to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VpcVirtualRouter to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking NiciraNvp to release 
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,627 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
>> (secstorage-1:null) Releasing ip address for 
>> reservationId=a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf, instance=1182
>> 2013-01-15 05:39:55,643 DEBUG
>> [network.router.VirtualNetworkApplianceManagerImpl]
>> (RouterStatusMonitor-1:null) Found 0 routers.
>> 2013-01-15 05:39:55,650 DEBUG [network.guru.PodBasedNetworkGuru]
>> (secstorage-1:null) Released nic: NicProfile[1182-296-null-null-null
>> 2013-01-15 05:39:55,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking JuniperSRX to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Netscaler to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking F5BigIP to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VirtualRouter to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Ovs to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking ExternalDhcpServer to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking BareMetal to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking SecurityGroupProvider to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking CiscoNexus1000vVSM to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VpcVirtualRouter to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking NiciraNvp to release 
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (secstorage-1:null) Successfully released network resources for the 
>> vm VM[SecondaryStorageVm|s-296-VM]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (secstorage-1:null) Successfully cleanued up resources for the vm 
>> VM[SecondaryStorageVm|s-296-VM] in Starting state
>> 2013-01-15 05:39:55,671 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) VM state transitted from :Starting to Stopped 
>> with
>> event: OperationFailedvm's original host id: null new host id: null 
>> host id before state transition: 1
>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) Hosts's actual total CPU: 8000 and CPU after 
>> applying
>> overprovisioning: 8000
>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) release cpu from host: 1, old used: 1000,reserved:
>> 0, actual total: 8000, total with overprovisioning: 8000; new used:
>> 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) release mem from host: 1, old used:
>> 1342177280,reserved: 0, total: 16726679552; new used:
>> 1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
>> 2013-01-15 05:39:55,678 WARN
>> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) 
>> Exception while trying to start secondary storage vm
>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>> unreachable: Host 1: Unable to start instance due to 
>> com.cloud.agent.api.Answer cannot be cast to 
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>         at
>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
>>         at
>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
>>         at
>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
>>         at
>> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
>>         at
>> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>         at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>         at
>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>         at
>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer 
>> cannot be cast to 
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>         at
>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>         at
>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>         at
>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>         ... 20 more
>> 2013-01-15 05:39:55,679 INFO
>> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) 
>> Unable to start secondary storage vm for standby capacity, 
>> secStorageVm vm Id :
>> 296, will recycle it and start a new one
>> 2013-01-15 05:39:55,679 INFO
>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>> (secstorage-1:null) Primary secondary storage is not even started, 
>> wait until next turn
>> 2013-01-15 05:40:00,255 DEBUG [cloud.template.TemplateManagerImpl]
>> (consoleproxy-1:null) Downloading 3 via 1
>> 2013-01-15 05:40:00,260 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227198: Sending  { Cmd , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 100111, 
>> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/var/lib/libv
>> irt/images/","poolUuid":"9652649a-6c25-403a-88b8-7e609f706e27","poolI
>> d":201,"secondaryStorageUrl":"nfs://192.168.71.50/export/secondary","
>> primaryStorageUrl":"nfs://192.168.71.41/var/lib/libvirt/images/","url
>> ":"nfs://192.168.71.50/export/secondary/template/tmpl/1/3/","format":
>> "QCOW2","accountId":1,"name":"routing-3","wait":10800}}]
>> }
>> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
>> (AgentManager-Handler-14:null) Seq 1-2027227198: Processing:  { Ans: 
>> ,
>> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110, 
>> [{"Answer":{"result":false,"details":"java.lang.NullPointerException\
>> n\tat 
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStorageP
>> ool(LibvirtStorageAdaptor.java:462)\n\tat
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePool
>> ByURI(LibvirtStorageAdaptor.java:745)\n\tat
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePool
>> ByURI(KVMStoragePoolManager.java:52)\n\tat
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(Li
>> bvirtComputingResource.java:2017)\n\tat
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeReq
>> uest(LibvirtComputingResource.java:1009)\n\tat
>> com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\ta
>> t com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
>> java:1110)\n\tat 
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
>> .java:603)\n\tat java.lang.Thread.run(Thread.java:679)\n","wait":0}}] 
>> }
>> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentAttache]
>> (AgentManager-Handler-14:null) Seq 1-2027227198: No more commands 
>> found
>> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227198: Received:  { Ans: , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 110, { Answer } }
>> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentManagerImpl]
>> (consoleproxy-1:null) Details from executing class
>> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
>> java.lang.NullPointerException
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>         at
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>         at
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>>
>> 2013-01-15 05:40:00,342 ERROR [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Failed to start instance 
>> VM[ConsoleProxy|v-83-VM]
>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be 
>> cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>         at
>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>         at
>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>         at
>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>         at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>         at
>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>         at
>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> 2013-01-15 05:40:00,349 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Cleaning up resources for the vm 
>> VM[ConsoleProxy|v-83-VM] in Starting state
>> 2013-01-15 05:40:00,351 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227199: Sending  { Cmd , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 100111, 
>> [{"StopCommand":{"isProxy":false,"vmName":"v-83-VM","wait":0}}] }
>> 2013-01-15 05:40:00,601 DEBUG [agent.transport.Request]
>> (AgentManager-Handler-15:null) Seq 1-2027227199: Processing:  { Ans: 
>> ,
>> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110, 
>> [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
>> 2013-01-15 05:40:00,602 DEBUG [agent.manager.AgentAttache]
>> (AgentManager-Handler-15:null) Seq 1-2027227199: No more commands 
>> found
>> 2013-01-15 05:40:00,602 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227199: Received:  { Ans: , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking JuniperSRX to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Netscaler to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking F5BigIP to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VirtualRouter to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Ovs to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking ExternalDhcpServer to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking BareMetal to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking SecurityGroupProvider to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VpcVirtualRouter to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking NiciraNvp to release 
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,650 DEBUG [network.guru.ControlNetworkGuru]
>> (consoleproxy-1:null) Released nic: NicProfile[329-83-null-null-null
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking JuniperSRX to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Netscaler to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking F5BigIP to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VirtualRouter to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Ovs to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking ExternalDhcpServer to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking BareMetal to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking SecurityGroupProvider to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VpcVirtualRouter to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking NiciraNvp to release 
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,662 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
>> (consoleproxy-1:null) Releasing ip address for 
>> reservationId=37122d6d-0259-4b1a-8638-6b6148037bd9, instance=330
>> 2013-01-15 05:40:00,666 DEBUG [network.guru.PodBasedNetworkGuru]
>> (consoleproxy-1:null) Released nic: NicProfile[330-83-null-null-null
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking JuniperSRX to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Netscaler to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking F5BigIP to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VirtualRouter to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Ovs to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking ExternalDhcpServer to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking BareMetal to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking SecurityGroupProvider to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VpcVirtualRouter to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking NiciraNvp to release 
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Successfully released network resources for the 
>> vm VM[ConsoleProxy|v-83-VM]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Successfully cleanued up resources for the vm 
>> VM[ConsoleProxy|v-83-VM] in Starting state
>> 2013-01-15 05:40:00,678 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) VM state transitted from :Starting to Stopped 
>> with
>> event: OperationFailedvm's original host id: null new host id:
>> null host id before state transition: 1
>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) Hosts's actual total CPU: 8000 and CPU after 
>> applying
>> overprovisioning: 8000
>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) release cpu from host: 1, old used:
>> 500,reserved: 0, actual total: 8000, total with overprovisioning:
>> 8000; new used: 0,reserved:0; movedfromreserved:
>> false,moveToReserveredfalse
>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) release mem from host: 1, old used:
>> 1073741824,reserved: 0, total: 16726679552; new used: 0,reserved:0;
>> movedfromreserved: false,moveToReserveredfalse
>> 2013-01-15 05:40:00,685 WARN
>> [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) 
>> Exception while trying to start console proxy
>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>> unreachable: Host 1: Unable to start instance due to 
>> com.cloud.agent.api.Answer cannot be cast to 
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>         at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>         at
>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>         at
>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer 
>> cannot be cast to 
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>         at
>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>         at
>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>         at
>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>         ... 19 more
>>
>>
>>
>>
>>
>> ---------------------------------------------
>>
>>
>> And this is KVM Agent log
>>
>>
>> [root@kvm01 agent]# tail -f agent.log
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>         at
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>         at
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> 2013-01-16 01:51:18,634 ERROR [kvm.storage.LibvirtStorageAdaptor]
>> (agentRequest-Handler-1:null) org.libvirt.LibvirtException: internal 
>> error Child process (/bin/mount
>> 192.168.71.50:/export/secondary/template/tmpl/1/3
>> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit 
>> status
>> 32
>> 2013-01-16 01:51:18,640 WARN  [cloud.agent.Agent]
>> (agentRequest-Handler-1:null) Caught:
>> java.lang.NullPointerException
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>         at
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>         at
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> 2013-01-16 01:51:18,956 ERROR [kvm.storage.LibvirtStorageAdaptor]
>> (agentRequest-Handler-4:null) org.libvirt.LibvirtException: internal 
>> error Child process (/bin/mount
>> 192.168.71.50:/export/secondary/template/tmpl/1/3
>> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit 
>> status
>> 32
>> 2013-01-16 01:51:18,961 WARN  [cloud.agent.Agent]
>> (agentRequest-Handler-4:null) Caught:
>>
>>
>>
>> On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
>>> Thanks for your replying
>>>
>>> I have send you Logs.zip file.Please sir give me suggestion.
>>>
>>> On Tue, Jan 15, 2013 at 10:07 PM, Rajesh Battala
>>> <ra...@citrix.com>wrote:
>>>
>>>> Hi Mahfuj,
>>>> Can you post the DEBUG log of MS and kvm agent.
>>>>
>>>> Thanks
>>>> Rajesh Battala
>>>>
>>>> -----Original Message-----
>>>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>>>> Sent: Tuesday, January 15, 2013 8:52 PM
>>>> To: cloudstack-users@incubator.apache.org
>>>> Subject: Host installed ok. Only problem appears to be with the 
>>>> System VMs coming up
>>>>
>>>> Hi, I am using CloudStack4 official installation guide and 
>>>> successfully installed the following things
>>>>
>>>>
>>>> 1. One Management Server. (Linux Centos x86_64) 2. One KVM host server.
>>>> (Linux Centos x86_64)
>>>>
>>>> Cloudstack 4.0 installation process:
>>>>
>>>> At Management Server:
>>>>
>>>> 1. Install cloud-client. (Successfully) 2. Install Mysql Server.
>>>> (Succesfully) 3. Cloud Database Created. (Successfully) 4. NFS 
>>>> Server installed.
>>>> (Successfully).
>>>> 5. NFS Share. (Successfully)
>>>>
>>>>
>>>> At Client Machine:
>>>>
>>>> 1. Install cloud-agent. (Successfully) 2. NFS mount. (Successfully)
>>>>
>>>> The main problem is after successfully adding host from CloudStack 
>>>> user interface  when System VM coming up following exceptions has 
>>>> thrown
>>>>
>>>>  *Exception while trying to start secondary storage vm*
>>>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>>>> unreachable: Host 1: Unable to start instance due to Unable to get 
>>>> answer that is of class com.cloud.agent.api.StartAnswer
>>>>
>>>> 2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
>>>> (secstorage-1:null) Failed to start instance 
>>>> VM[SecondaryStorageVm|s-142-VM]
>>>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be 
>>>> cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>>
>>>> 2013-01-15 03:05:55,580 INFO
>>>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>>>> (secstorage-1:null)*Primary secondary storage is not even started, 
>>>> wait until next turn
>>>> *
>>>>
>>>>
>>>> How I  will solve this problem.Please if you have any 
>>>> recommendation tell me.
>>>>
>>>
>>
>

Re: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Ahmad Emneina <Ah...@citrix.com>.

On 1/17/13 5:04 AM, "Mahfuj Jia" <ma...@gmail.com> wrote:

>Do you have any suggestion or steps or documentation that  can install
>the cloud stack4 with successfully installed system vm.I have followed
>official document and successfully installed every thing without error
>but when system vm coming up give me secondary storage
>exception.Please help me.
>

Have you tried writing a file to the primary/secondary mount points from
the compute host.

-- 
Æ

Re: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Mahfuj Jia <ma...@gmail.com>.

Do you have any suggestion or steps or documentation that  can install
the cloud stack4 with successfully installed system vm.I have followed
official document and successfully installed every thing without error
but when system vm coming up give me secondary storage
exception.Please help me.

On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
> Thanks for your reply
>
> How do I test the storage pool is reachable to the host?Yes I
> manually mount it and verify  the primary storage mount point can be
> mounted on the host and its reachable.In graphical User Interface
> Secondary storage allocation 0%.
>
> Please give me instructions that How can I setup System VM and also
> the primary and secondary storage successfully.
>
> Thanks Please reply
>
>
> On 1/16/13, Rajesh Battala <ra...@citrix.com> wrote:
>> Hi Mahfuj,
>>
>> From the logs it looks like issue while mounting the primary storage
>> mount
>> point on the host.
>> Is the storage pool is reachable to the host?.
>> Can you manually mount it and verify whether the primary storage mount
>> point
>> can be mounted on the host or not and its reachable.
>>
>> Thanks
>> Rajesh Battala
>>
>> -----Original Message-----
>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>> Sent: Wednesday, January 16, 2013 4:13 PM
>> To: cloudstack-users@incubator.apache.org
>> Subject: Re: Host installed ok. Only problem appears to be with the
>> System
>> VMs coming up
>>
>> Hi I am waiting for your reply
>>
>> This is our Management server log
>> 2013-01-15 05:39:55,615 DEBUG [network.guru.PodBasedNetworkGuru]
>> (secstorage-1:null) Released nic: NicProfile[1181-296-null-null-null
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking JuniperSRX to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Netscaler to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking F5BigIP to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VirtualRouter to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Ovs to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking ExternalDhcpServer to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking BareMetal to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking SecurityGroupProvider to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VpcVirtualRouter to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking NiciraNvp to release
>> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,627 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
>> (secstorage-1:null) Releasing ip address for
>> reservationId=a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf, instance=1182
>> 2013-01-15 05:39:55,643 DEBUG
>> [network.router.VirtualNetworkApplianceManagerImpl]
>> (RouterStatusMonitor-1:null) Found 0 routers.
>> 2013-01-15 05:39:55,650 DEBUG [network.guru.PodBasedNetworkGuru]
>> (secstorage-1:null) Released nic: NicProfile[1182-296-null-null-null
>> 2013-01-15 05:39:55,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking JuniperSRX to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Netscaler to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking F5BigIP to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VirtualRouter to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking Ovs to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking ExternalDhcpServer to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking BareMetal to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking SecurityGroupProvider to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking VpcVirtualRouter to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
>> (secstorage-1:null) Asking NiciraNvp to release
>> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (secstorage-1:null) Successfully released network resources for the vm
>> VM[SecondaryStorageVm|s-296-VM]
>> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (secstorage-1:null) Successfully cleanued up resources for the vm
>> VM[SecondaryStorageVm|s-296-VM] in Starting state
>> 2013-01-15 05:39:55,671 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) VM state transitted from :Starting to Stopped with
>> event: OperationFailedvm's original host id: null new host id: null host
>> id
>> before state transition: 1
>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) Hosts's actual total CPU: 8000 and CPU after applying
>> overprovisioning: 8000
>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) release cpu from host: 1, old used: 1000,reserved:
>> 0, actual total: 8000, total with overprovisioning: 8000; new used:
>> 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
>> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (secstorage-1:null) release mem from host: 1, old used:
>> 1342177280,reserved: 0, total: 16726679552; new used:
>> 1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
>> 2013-01-15 05:39:55,678 WARN
>> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
>> Exception while trying to start secondary storage vm
>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>> unreachable: Host 1: Unable to start instance due to
>> com.cloud.agent.api.Answer cannot be cast to
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>         at
>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
>>         at
>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
>>         at
>> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
>>         at
>> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
>>         at
>> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>         at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>         at
>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>         at
>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
>> cannot
>> be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>         at
>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>         at
>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>         at
>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>         ... 20 more
>> 2013-01-15 05:39:55,679 INFO
>> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
>> Unable
>> to start secondary storage vm for standby capacity, secStorageVm vm Id :
>> 296, will recycle it and start a new one
>> 2013-01-15 05:39:55,679 INFO
>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>> (secstorage-1:null) Primary secondary storage is not even started, wait
>> until next turn
>> 2013-01-15 05:40:00,255 DEBUG [cloud.template.TemplateManagerImpl]
>> (consoleproxy-1:null) Downloading 3 via 1
>> 2013-01-15 05:40:00,260 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227198: Sending  { Cmd , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 100111,
>> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/var/lib/libvirt/images/","poolUuid":"9652649a-6c25-403a-88b8-7e609f706e27","poolId":201,"secondaryStorageUrl":"nfs://192.168.71.50/export/secondary","primaryStorageUrl":"nfs://192.168.71.41/var/lib/libvirt/images/","url":"nfs://192.168.71.50/export/secondary/template/tmpl/1/3/","format":"QCOW2","accountId":1,"name":"routing-3","wait":10800}}]
>> }
>> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
>> (AgentManager-Handler-14:null) Seq 1-2027227198: Processing:  { Ans: ,
>> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
>> [{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)\n\tat
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)\n\tat
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)\n\tat
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)\n\tat
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)\n\tat
>> com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\tat
>> com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
>> java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
>> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentAttache]
>> (AgentManager-Handler-14:null) Seq 1-2027227198: No more commands found
>> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227198: Received:  { Ans: , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 110, { Answer } }
>> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentManagerImpl]
>> (consoleproxy-1:null) Details from executing class
>> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
>> java.lang.NullPointerException
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>         at
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>         at
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>>
>> 2013-01-15 05:40:00,342 ERROR [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Failed to start instance VM[ConsoleProxy|v-83-VM]
>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast
>> to
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>         at
>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>         at
>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>         at
>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>         at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>         at
>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>         at
>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> 2013-01-15 05:40:00,349 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Cleaning up resources for the vm
>> VM[ConsoleProxy|v-83-VM] in Starting state
>> 2013-01-15 05:40:00,351 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227199: Sending  { Cmd , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 100111,
>> [{"StopCommand":{"isProxy":false,"vmName":"v-83-VM","wait":0}}] }
>> 2013-01-15 05:40:00,601 DEBUG [agent.transport.Request]
>> (AgentManager-Handler-15:null) Seq 1-2027227199: Processing:  { Ans: ,
>> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
>> [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
>> 2013-01-15 05:40:00,602 DEBUG [agent.manager.AgentAttache]
>> (AgentManager-Handler-15:null) Seq 1-2027227199: No more commands found
>> 2013-01-15 05:40:00,602 DEBUG [agent.transport.Request]
>> (consoleproxy-1:null) Seq 1-2027227199: Received:  { Ans: , MgmtId:
>> 52242164673, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking JuniperSRX to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Netscaler to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking F5BigIP to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VirtualRouter to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Ovs to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking ExternalDhcpServer to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking BareMetal to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking SecurityGroupProvider to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VpcVirtualRouter to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking NiciraNvp to release
>> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
>> 2013-01-15 05:40:00,650 DEBUG [network.guru.ControlNetworkGuru]
>> (consoleproxy-1:null) Released nic: NicProfile[329-83-null-null-null
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking JuniperSRX to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Netscaler to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking F5BigIP to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VirtualRouter to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Ovs to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking ExternalDhcpServer to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking BareMetal to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking SecurityGroupProvider to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VpcVirtualRouter to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking NiciraNvp to release
>> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,662 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
>> (consoleproxy-1:null) Releasing ip address for
>> reservationId=37122d6d-0259-4b1a-8638-6b6148037bd9, instance=330
>> 2013-01-15 05:40:00,666 DEBUG [network.guru.PodBasedNetworkGuru]
>> (consoleproxy-1:null) Released nic: NicProfile[330-83-null-null-null
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking JuniperSRX to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Netscaler to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking F5BigIP to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VirtualRouter to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking Ovs to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking ExternalDhcpServer to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking BareMetal to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking SecurityGroupProvider to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking VpcVirtualRouter to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
>> (consoleproxy-1:null) Asking NiciraNvp to release
>> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Successfully released network resources for the vm
>> VM[ConsoleProxy|v-83-VM]
>> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
>> (consoleproxy-1:null) Successfully cleanued up resources for the vm
>> VM[ConsoleProxy|v-83-VM] in Starting state
>> 2013-01-15 05:40:00,678 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) VM state transitted from :Starting to Stopped with
>> event: OperationFailedvm's original host id: null new host id:
>> null host id before state transition: 1
>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) Hosts's actual total CPU: 8000 and CPU after
>> applying
>> overprovisioning: 8000
>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) release cpu from host: 1, old used:
>> 500,reserved: 0, actual total: 8000, total with overprovisioning:
>> 8000; new used: 0,reserved:0; movedfromreserved:
>> false,moveToReserveredfalse
>> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
>> (consoleproxy-1:null) release mem from host: 1, old used:
>> 1073741824,reserved: 0, total: 16726679552; new used: 0,reserved:0;
>> movedfromreserved: false,moveToReserveredfalse
>> 2013-01-15 05:40:00,685 WARN
>> [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
>> Exception
>> while trying to start console proxy
>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>> unreachable: Host 1: Unable to start instance due to
>> com.cloud.agent.api.Answer cannot be cast to
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>>         at
>> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>>         at
>> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>>         at
>> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>>         at
>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>>         at
>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>>         at
>> java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>>         at
>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
>> cannot
>> be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>         at
>> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>>         at
>> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>>         at
>> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>>         at
>> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>>         at
>> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>>         ... 19 more
>>
>>
>>
>>
>>
>> ---------------------------------------------
>>
>>
>> And this is KVM Agent log
>>
>>
>> [root@kvm01 agent]# tail -f agent.log
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>         at
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>         at
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> 2013-01-16 01:51:18,634 ERROR [kvm.storage.LibvirtStorageAdaptor]
>> (agentRequest-Handler-1:null) org.libvirt.LibvirtException: internal
>> error
>> Child process (/bin/mount
>> 192.168.71.50:/export/secondary/template/tmpl/1/3
>> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit status
>> 32
>> 2013-01-16 01:51:18,640 WARN  [cloud.agent.Agent]
>> (agentRequest-Handler-1:null) Caught:
>> java.lang.NullPointerException
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>>         at
>> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>>         at
>> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>>         at
>> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>>         at
>> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>>         at com.cloud.utils.nio.Task.run(Task.java:83)
>>         at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>>         at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>>         at java.lang.Thread.run(Thread.java:679)
>> 2013-01-16 01:51:18,956 ERROR [kvm.storage.LibvirtStorageAdaptor]
>> (agentRequest-Handler-4:null) org.libvirt.LibvirtException: internal
>> error
>> Child process (/bin/mount
>> 192.168.71.50:/export/secondary/template/tmpl/1/3
>> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit status
>> 32
>> 2013-01-16 01:51:18,961 WARN  [cloud.agent.Agent]
>> (agentRequest-Handler-4:null) Caught:
>>
>>
>>
>> On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
>>> Thanks for your replying
>>>
>>> I have send you Logs.zip file.Please sir give me suggestion.
>>>
>>> On Tue, Jan 15, 2013 at 10:07 PM, Rajesh Battala
>>> <ra...@citrix.com>wrote:
>>>
>>>> Hi Mahfuj,
>>>> Can you post the DEBUG log of MS and kvm agent.
>>>>
>>>> Thanks
>>>> Rajesh Battala
>>>>
>>>> -----Original Message-----
>>>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>>>> Sent: Tuesday, January 15, 2013 8:52 PM
>>>> To: cloudstack-users@incubator.apache.org
>>>> Subject: Host installed ok. Only problem appears to be with the
>>>> System VMs coming up
>>>>
>>>> Hi, I am using CloudStack4 official installation guide and
>>>> successfully installed the following things
>>>>
>>>>
>>>> 1. One Management Server. (Linux Centos x86_64) 2. One KVM host server.
>>>> (Linux Centos x86_64)
>>>>
>>>> Cloudstack 4.0 installation process:
>>>>
>>>> At Management Server:
>>>>
>>>> 1. Install cloud-client. (Successfully) 2. Install Mysql Server.
>>>> (Succesfully) 3. Cloud Database Created. (Successfully) 4. NFS Server
>>>> installed.
>>>> (Successfully).
>>>> 5. NFS Share. (Successfully)
>>>>
>>>>
>>>> At Client Machine:
>>>>
>>>> 1. Install cloud-agent. (Successfully) 2. NFS mount. (Successfully)
>>>>
>>>> The main problem is after successfully adding host from CloudStack
>>>> user interface  when System VM coming up following exceptions has
>>>> thrown
>>>>
>>>>  *Exception while trying to start secondary storage vm*
>>>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>>>> unreachable: Host 1: Unable to start instance due to Unable to get
>>>> answer that is of class com.cloud.agent.api.StartAnswer
>>>>
>>>> 2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
>>>> (secstorage-1:null) Failed to start instance
>>>> VM[SecondaryStorageVm|s-142-VM]
>>>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be
>>>> cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>>
>>>> 2013-01-15 03:05:55,580 INFO
>>>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>>>> (secstorage-1:null)*Primary secondary storage is not even started,
>>>> wait until next turn
>>>> *
>>>>
>>>>
>>>> How I  will solve this problem.Please if you have any recommendation
>>>> tell me.
>>>>
>>>
>>
>

Re: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Mahfuj Jia <ma...@gmail.com>.

Thanks for your reply

How do I test the storage pool is reachable to the host?Yes I
manually mount it and verify  the primary storage mount point can be
mounted on the host and its reachable.In graphical User Interface
Secondary storage allocation 0%.

Please give me instructions that How can I setup System VM and also
the primary and secondary storage successfully.

Thanks Please reply


On 1/16/13, Rajesh Battala <ra...@citrix.com> wrote:
> Hi Mahfuj,
>
> From the logs it looks like issue while mounting the primary storage mount
> point on the host.
> Is the storage pool is reachable to the host?.
> Can you manually mount it and verify whether the primary storage mount point
> can be mounted on the host or not and its reachable.
>
> Thanks
> Rajesh Battala
>
> -----Original Message-----
> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
> Sent: Wednesday, January 16, 2013 4:13 PM
> To: cloudstack-users@incubator.apache.org
> Subject: Re: Host installed ok. Only problem appears to be with the System
> VMs coming up
>
> Hi I am waiting for your reply
>
> This is our Management server log
> 2013-01-15 05:39:55,615 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[1181-296-null-null-null
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking ExternalDhcpServer to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BareMetal to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,627 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> (secstorage-1:null) Releasing ip address for
> reservationId=a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf, instance=1182
> 2013-01-15 05:39:55,643 DEBUG
> [network.router.VirtualNetworkApplianceManagerImpl]
> (RouterStatusMonitor-1:null) Found 0 routers.
> 2013-01-15 05:39:55,650 DEBUG [network.guru.PodBasedNetworkGuru]
> (secstorage-1:null) Released nic: NicProfile[1182-296-null-null-null
> 2013-01-15 05:39:55,655 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking JuniperSRX to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Netscaler to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking F5BigIP to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VirtualRouter to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking Ovs to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking ExternalDhcpServer to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking BareMetal to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking SecurityGroupProvider to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking CiscoNexus1000vVSM to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking VpcVirtualRouter to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
> (secstorage-1:null) Asking NiciraNvp to release
> Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Successfully released network resources for the vm
> VM[SecondaryStorageVm|s-296-VM]
> 2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Successfully cleanued up resources for the vm
> VM[SecondaryStorageVm|s-296-VM] in Starting state
> 2013-01-15 05:39:55,671 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) VM state transitted from :Starting to Stopped with
> event: OperationFailedvm's original host id: null new host id: null host id
> before state transition: 1
> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) Hosts's actual total CPU: 8000 and CPU after applying
> overprovisioning: 8000
> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) release cpu from host: 1, old used: 1000,reserved:
> 0, actual total: 8000, total with overprovisioning: 8000; new used:
> 500,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
> (secstorage-1:null) release mem from host: 1, old used:
> 1342177280,reserved: 0, total: 16726679552; new used:
> 1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
> 2013-01-15 05:39:55,678 WARN
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
> Exception while trying to start secondary storage vm
> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
> unreachable: Host 1: Unable to start instance due to
> com.cloud.agent.api.Answer cannot be cast to
> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>         at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>         at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
>         at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
>         at
> com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
>         at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
>         at
> com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
>         at
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
>         at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>         at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>         at
> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>         at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer cannot
> be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>         at
> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>         at
> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>         at
> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>         at
> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>         ... 20 more
> 2013-01-15 05:39:55,679 INFO
> [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable
> to start secondary storage vm for standby capacity, secStorageVm vm Id :
> 296, will recycle it and start a new one
> 2013-01-15 05:39:55,679 INFO
> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
> (secstorage-1:null) Primary secondary storage is not even started, wait
> until next turn
> 2013-01-15 05:40:00,255 DEBUG [cloud.template.TemplateManagerImpl]
> (consoleproxy-1:null) Downloading 3 via 1
> 2013-01-15 05:40:00,260 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-2027227198: Sending  { Cmd , MgmtId:
> 52242164673, via: 1, Ver: v1, Flags: 100111,
> [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/var/lib/libvirt/images/","poolUuid":"9652649a-6c25-403a-88b8-7e609f706e27","poolId":201,"secondaryStorageUrl":"nfs://192.168.71.50/export/secondary","primaryStorageUrl":"nfs://192.168.71.41/var/lib/libvirt/images/","url":"nfs://192.168.71.50/export/secondary/template/tmpl/1/3/","format":"QCOW2","accountId":1,"name":"routing-3","wait":10800}}]
> }
> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
> (AgentManager-Handler-14:null) Seq 1-2027227198: Processing:  { Ans: ,
> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
> [{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)\n\tat
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)\n\tat
> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)\n\tat
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)\n\tat
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)\n\tat
> com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
> com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\tat
> com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
> java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-14:null) Seq 1-2027227198: No more commands found
> 2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-2027227198: Received:  { Ans: , MgmtId:
> 52242164673, via: 1, Ver: v1, Flags: 110, { Answer } }
> 2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentManagerImpl]
> (consoleproxy-1:null) Details from executing class
> com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
> java.lang.NullPointerException
>         at
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>         at
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>         at
> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>         at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>         at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>         at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>         at com.cloud.utils.nio.Task.run(Task.java:83)
>         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
>
> 2013-01-15 05:40:00,342 ERROR [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Failed to start instance VM[ConsoleProxy|v-83-VM]
> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to
> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>         at
> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>         at
> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>         at
> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>         at
> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>         at
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>         at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>         at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>         at
> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>         at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
> 2013-01-15 05:40:00,349 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Cleaning up resources for the vm
> VM[ConsoleProxy|v-83-VM] in Starting state
> 2013-01-15 05:40:00,351 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-2027227199: Sending  { Cmd , MgmtId:
> 52242164673, via: 1, Ver: v1, Flags: 100111,
> [{"StopCommand":{"isProxy":false,"vmName":"v-83-VM","wait":0}}] }
> 2013-01-15 05:40:00,601 DEBUG [agent.transport.Request]
> (AgentManager-Handler-15:null) Seq 1-2027227199: Processing:  { Ans: ,
> MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
> [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
> 2013-01-15 05:40:00,602 DEBUG [agent.manager.AgentAttache]
> (AgentManager-Handler-15:null) Seq 1-2027227199: No more commands found
> 2013-01-15 05:40:00,602 DEBUG [agent.transport.Request]
> (consoleproxy-1:null) Seq 1-2027227199: Received:  { Ans: , MgmtId:
> 52242164673, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking ExternalDhcpServer to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BareMetal to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to release
> Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
> 2013-01-15 05:40:00,650 DEBUG [network.guru.ControlNetworkGuru]
> (consoleproxy-1:null) Released nic: NicProfile[329-83-null-null-null
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking ExternalDhcpServer to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BareMetal to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to release
> Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,662 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
> (consoleproxy-1:null) Releasing ip address for
> reservationId=37122d6d-0259-4b1a-8638-6b6148037bd9, instance=330
> 2013-01-15 05:40:00,666 DEBUG [network.guru.PodBasedNetworkGuru]
> (consoleproxy-1:null) Released nic: NicProfile[330-83-null-null-null
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking JuniperSRX to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Netscaler to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking F5BigIP to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VirtualRouter to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking Ovs to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking ExternalDhcpServer to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking BareMetal to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking SecurityGroupProvider to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking VpcVirtualRouter to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
> (consoleproxy-1:null) Asking NiciraNvp to release
> Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Successfully released network resources for the vm
> VM[ConsoleProxy|v-83-VM]
> 2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
> (consoleproxy-1:null) Successfully cleanued up resources for the vm
> VM[ConsoleProxy|v-83-VM] in Starting state
> 2013-01-15 05:40:00,678 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) VM state transitted from :Starting to Stopped with
> event: OperationFailedvm's original host id: null new host id:
> null host id before state transition: 1
> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) Hosts's actual total CPU: 8000 and CPU after applying
> overprovisioning: 8000
> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) release cpu from host: 1, old used:
> 500,reserved: 0, actual total: 8000, total with overprovisioning:
> 8000; new used: 0,reserved:0; movedfromreserved:
> false,moveToReserveredfalse
> 2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
> (consoleproxy-1:null) release mem from host: 1, old used:
> 1073741824,reserved: 0, total: 16726679552; new used: 0,reserved:0;
> movedfromreserved: false,moveToReserveredfalse
> 2013-01-15 05:40:00,685 WARN
> [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Exception
> while trying to start console proxy
> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
> unreachable: Host 1: Unable to start instance due to
> com.cloud.agent.api.Answer cannot be cast to
> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>         at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
>         at
> com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
>         at
> com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
>         at
> com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
>         at
> com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
>         at
> com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
>         at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
>         at
> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
>         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
>         at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
>         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
> Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer cannot
> be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>         at
> com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
>         at
> com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
>         at
> com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
>         at
> com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
>         at
> com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
>         ... 19 more
>
>
>
>
>
> ---------------------------------------------
>
>
> And this is KVM Agent log
>
>
> [root@kvm01 agent]# tail -f agent.log
>         at
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>         at
> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>         at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>         at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>         at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>         at com.cloud.utils.nio.Task.run(Task.java:83)
>         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
> 2013-01-16 01:51:18,634 ERROR [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-1:null) org.libvirt.LibvirtException: internal error
> Child process (/bin/mount
> 192.168.71.50:/export/secondary/template/tmpl/1/3
> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit status
> 32
> 2013-01-16 01:51:18,640 WARN  [cloud.agent.Agent]
> (agentRequest-Handler-1:null) Caught:
> java.lang.NullPointerException
>         at
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
>         at
> com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
>         at
> com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
>         at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
>         at
> com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
>         at com.cloud.agent.Agent.processRequest(Agent.java:518)
>         at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
>         at com.cloud.utils.nio.Task.run(Task.java:83)
>         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:679)
> 2013-01-16 01:51:18,956 ERROR [kvm.storage.LibvirtStorageAdaptor]
> (agentRequest-Handler-4:null) org.libvirt.LibvirtException: internal error
> Child process (/bin/mount
> 192.168.71.50:/export/secondary/template/tmpl/1/3
> /mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit status
> 32
> 2013-01-16 01:51:18,961 WARN  [cloud.agent.Agent]
> (agentRequest-Handler-4:null) Caught:
>
>
>
> On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
>> Thanks for your replying
>>
>> I have send you Logs.zip file.Please sir give me suggestion.
>>
>> On Tue, Jan 15, 2013 at 10:07 PM, Rajesh Battala
>> <ra...@citrix.com>wrote:
>>
>>> Hi Mahfuj,
>>> Can you post the DEBUG log of MS and kvm agent.
>>>
>>> Thanks
>>> Rajesh Battala
>>>
>>> -----Original Message-----
>>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>>> Sent: Tuesday, January 15, 2013 8:52 PM
>>> To: cloudstack-users@incubator.apache.org
>>> Subject: Host installed ok. Only problem appears to be with the
>>> System VMs coming up
>>>
>>> Hi, I am using CloudStack4 official installation guide and
>>> successfully installed the following things
>>>
>>>
>>> 1. One Management Server. (Linux Centos x86_64) 2. One KVM host server.
>>> (Linux Centos x86_64)
>>>
>>> Cloudstack 4.0 installation process:
>>>
>>> At Management Server:
>>>
>>> 1. Install cloud-client. (Successfully) 2. Install Mysql Server.
>>> (Succesfully) 3. Cloud Database Created. (Successfully) 4. NFS Server
>>> installed.
>>> (Successfully).
>>> 5. NFS Share. (Successfully)
>>>
>>>
>>> At Client Machine:
>>>
>>> 1. Install cloud-agent. (Successfully) 2. NFS mount. (Successfully)
>>>
>>> The main problem is after successfully adding host from CloudStack
>>> user interface  when System VM coming up following exceptions has
>>> thrown
>>>
>>>  *Exception while trying to start secondary storage vm*
>>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>>> unreachable: Host 1: Unable to start instance due to Unable to get
>>> answer that is of class com.cloud.agent.api.StartAnswer
>>>
>>> 2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
>>> (secstorage-1:null) Failed to start instance
>>> VM[SecondaryStorageVm|s-142-VM]
>>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be
>>> cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>>
>>> 2013-01-15 03:05:55,580 INFO
>>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>>> (secstorage-1:null)*Primary secondary storage is not even started,
>>> wait until next turn
>>> *
>>>
>>>
>>> How I  will solve this problem.Please if you have any recommendation
>>> tell me.
>>>
>>
>

RE: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Rajesh Battala <ra...@citrix.com>.

Hi Mahfuj,

>From the logs it looks like issue while mounting the primary storage mount point on the host.
Is the storage pool is reachable to the host?.
Can you manually mount it and verify whether the primary storage mount point can be mounted on the host or not and its reachable.

Thanks
Rajesh Battala

-----Original Message-----
From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
Sent: Wednesday, January 16, 2013 4:13 PM
To: cloudstack-users@incubator.apache.org
Subject: Re: Host installed ok. Only problem appears to be with the System VMs coming up

Hi I am waiting for your reply

This is our Management server log
2013-01-15 05:39:55,615 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[1181-296-null-null-null
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking ExternalDhcpServer to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BareMetal to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,627 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for reservationId=a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf, instance=1182
2013-01-15 05:39:55,643 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-01-15 05:39:55,650 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[1182-296-null-null-null
2013-01-15 05:39:55,655 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking ExternalDhcpServer to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BareMetal to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully released network resources for the vm VM[SecondaryStorageVm|s-296-VM]
2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully cleanued up resources for the vm VM[SecondaryStorageVm|s-296-VM] in Starting state
2013-01-15 05:39:55,671 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original host id: null new host id: null host id before state transition: 1
2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total CPU: 8000 and CPU after applying overprovisioning: 8000
2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release cpu from host: 1, old used: 1000,reserved:
0, actual total: 8000, total with overprovisioning: 8000; new used:
500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release mem from host: 1, old used:
1342177280,reserved: 0, total: 16726679552; new used:
1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-15 05:39:55,678 WARN
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Exception while trying to start secondary storage vm
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        ... 20 more
2013-01-15 05:39:55,679 INFO
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 296, will recycle it and start a new one
2013-01-15 05:39:55,679 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl]
(secstorage-1:null) Primary secondary storage is not even started, wait until next turn
2013-01-15 05:40:00,255 DEBUG [cloud.template.TemplateManagerImpl]
(consoleproxy-1:null) Downloading 3 via 1
2013-01-15 05:40:00,260 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227198: Sending  { Cmd , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 100111, [{"storage.PrimaryStorageDownloadCommand":{"localPath":"/var/lib/libvirt/images/","poolUuid":"9652649a-6c25-403a-88b8-7e609f706e27","poolId":201,"secondaryStorageUrl":"nfs://192.168.71.50/export/secondary","primaryStorageUrl":"nfs://192.168.71.41/var/lib/libvirt/images/","url":"nfs://192.168.71.50/export/secondary/template/tmpl/1/3/","format":"QCOW2","accountId":1,"name":"routing-3","wait":10800}}]
}
2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
(AgentManager-Handler-14:null) Seq 1-2027227198: Processing:  { Ans: ,
MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110, [{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)\n\tat
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-14:null) Seq 1-2027227198: No more commands found
2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227198: Received:  { Ans: , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 110, { Answer } }
2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentManagerImpl]
(consoleproxy-1:null) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)

2013-01-15 05:40:00,342 ERROR [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Failed to start instance VM[ConsoleProxy|v-83-VM]
java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-15 05:40:00,349 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Cleaning up resources for the vm VM[ConsoleProxy|v-83-VM] in Starting state
2013-01-15 05:40:00,351 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227199: Sending  { Cmd , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 100111, [{"StopCommand":{"isProxy":false,"vmName":"v-83-VM","wait":0}}] }
2013-01-15 05:40:00,601 DEBUG [agent.transport.Request]
(AgentManager-Handler-15:null) Seq 1-2027227199: Processing:  { Ans: ,
MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110, [{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2013-01-15 05:40:00,602 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-15:null) Seq 1-2027227199: No more commands found
2013-01-15 05:40:00,602 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227199: Received:  { Ans: , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,650 DEBUG [network.guru.ControlNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[329-83-null-null-null
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,662 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(consoleproxy-1:null) Releasing ip address for reservationId=37122d6d-0259-4b1a-8638-6b6148037bd9, instance=330
2013-01-15 05:40:00,666 DEBUG [network.guru.PodBasedNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[330-83-null-null-null
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully released network resources for the vm VM[ConsoleProxy|v-83-VM]
2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully cleanued up resources for the vm VM[ConsoleProxy|v-83-VM] in Starting state
2013-01-15 05:40:00,678 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Starting to Stopped with event: OperationFailedvm's original host id: null new host id:
null host id before state transition: 1
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total CPU: 8000 and CPU after applying overprovisioning: 8000
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release cpu from host: 1, old used:
500,reserved: 0, actual total: 8000, total with overprovisioning:
8000; new used: 0,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release mem from host: 1, old used:
1073741824,reserved: 0, total: 16726679552; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-01-15 05:40:00,685 WARN
[cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Exception while trying to start console proxy
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        ... 19 more





---------------------------------------------


And this is KVM Agent log


[root@kvm01 agent]# tail -f agent.log
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-16 01:51:18,634 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-1:null) org.libvirt.LibvirtException: internal error Child process (/bin/mount
192.168.71.50:/export/secondary/template/tmpl/1/3
/mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit status 32
2013-01-16 01:51:18,640 WARN  [cloud.agent.Agent]
(agentRequest-Handler-1:null) Caught:
java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-16 01:51:18,956 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-4:null) org.libvirt.LibvirtException: internal error Child process (/bin/mount
192.168.71.50:/export/secondary/template/tmpl/1/3
/mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit status 32
2013-01-16 01:51:18,961 WARN  [cloud.agent.Agent]
(agentRequest-Handler-4:null) Caught:



On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
> Thanks for your replying
>
> I have send you Logs.zip file.Please sir give me suggestion.
>
> On Tue, Jan 15, 2013 at 10:07 PM, Rajesh Battala
> <ra...@citrix.com>wrote:
>
>> Hi Mahfuj,
>> Can you post the DEBUG log of MS and kvm agent.
>>
>> Thanks
>> Rajesh Battala
>>
>> -----Original Message-----
>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>> Sent: Tuesday, January 15, 2013 8:52 PM
>> To: cloudstack-users@incubator.apache.org
>> Subject: Host installed ok. Only problem appears to be with the
>> System VMs coming up
>>
>> Hi, I am using CloudStack4 official installation guide and
>> successfully installed the following things
>>
>>
>> 1. One Management Server. (Linux Centos x86_64) 2. One KVM host server.
>> (Linux Centos x86_64)
>>
>> Cloudstack 4.0 installation process:
>>
>> At Management Server:
>>
>> 1. Install cloud-client. (Successfully) 2. Install Mysql Server.
>> (Succesfully) 3. Cloud Database Created. (Successfully) 4. NFS Server
>> installed.
>> (Successfully).
>> 5. NFS Share. (Successfully)
>>
>>
>> At Client Machine:
>>
>> 1. Install cloud-agent. (Successfully) 2. NFS mount. (Successfully)
>>
>> The main problem is after successfully adding host from CloudStack
>> user interface  when System VM coming up following exceptions has
>> thrown
>>
>>  *Exception while trying to start secondary storage vm*
>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>> unreachable: Host 1: Unable to start instance due to Unable to get
>> answer that is of class com.cloud.agent.api.StartAnswer
>>
>> 2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
>> (secstorage-1:null) Failed to start instance
>> VM[SecondaryStorageVm|s-142-VM]
>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be
>> cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>
>> 2013-01-15 03:05:55,580 INFO
>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>> (secstorage-1:null)*Primary secondary storage is not even started,
>> wait until next turn
>> *
>>
>>
>> How I  will solve this problem.Please if you have any recommendation
>> tell me.
>>
>

Re: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Mahfuj Jia <ma...@gmail.com>.

Hi I am waiting for your reply

This is our Management server log
2013-01-15 05:39:55,615 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[1181-296-null-null-null
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking ExternalDhcpServer to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BareMetal to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,619 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[1181-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,627 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for
reservationId=a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf, instance=1182
2013-01-15 05:39:55,643 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers.
2013-01-15 05:39:55,650 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[1182-296-null-null-null
2013-01-15 05:39:55,655 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking ExternalDhcpServer to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BareMetal to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[1182-296-a47e227a-1c5c-4a5e-8e26-3dd9a81e81cf-null]
2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully released network resources for the vm
VM[SecondaryStorageVm|s-296-VM]
2013-01-15 05:39:55,656 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully cleanued up resources for the vm
VM[SecondaryStorageVm|s-296-VM] in Starting state
2013-01-15 05:39:55,671 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original host id: null new host id: null
host id before state transition: 1
2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total CPU: 8000 and CPU after
applying overprovisioning: 8000
2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release cpu from host: 1, old used: 1000,reserved:
0, actual total: 8000, total with overprovisioning: 8000; new used:
500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-15 05:39:55,674 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release mem from host: 1, old used:
1342177280,reserved: 0, total: 16726679552; new used:
1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
2013-01-15 05:39:55,678 WARN
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Exception while trying to start secondary storage vm
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to
com.cloud.agent.api.Answer cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:257)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:684)
        at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1310)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:119)
        at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:106)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        ... 20 more
2013-01-15 05:39:55,679 INFO
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Unable to start secondary storage vm for standby capacity,
secStorageVm vm Id : 296, will recycle it and start a new one
2013-01-15 05:39:55,679 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl]
(secstorage-1:null) Primary secondary storage is not even started,
wait until next turn
2013-01-15 05:40:00,255 DEBUG [cloud.template.TemplateManagerImpl]
(consoleproxy-1:null) Downloading 3 via 1
2013-01-15 05:40:00,260 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227198: Sending  { Cmd , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 100111,
[{"storage.PrimaryStorageDownloadCommand":{"localPath":"/var/lib/libvirt/images/","poolUuid":"9652649a-6c25-403a-88b8-7e609f706e27","poolId":201,"secondaryStorageUrl":"nfs://192.168.71.50/export/secondary","primaryStorageUrl":"nfs://192.168.71.41/var/lib/libvirt/images/","url":"nfs://192.168.71.50/export/secondary/template/tmpl/1/3/","format":"QCOW2","accountId":1,"name":"routing-3","wait":10800}}]
}
2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
(AgentManager-Handler-14:null) Seq 1-2027227198: Processing:  { Ans: ,
MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
[{"Answer":{"result":false,"details":"java.lang.NullPointerException\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)\n\tat
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:518)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)\n\tat
java.lang.Thread.run(Thread.java:679)\n","wait":0}}] }
2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-14:null) Seq 1-2027227198: No more commands
found
2013-01-15 05:40:00,340 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227198: Received:  { Ans: , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 110, { Answer } }
2013-01-15 05:40:00,340 DEBUG [agent.manager.AgentManagerImpl]
(consoleproxy-1:null) Details from executing class
com.cloud.agent.api.storage.PrimaryStorageDownloadCommand:
java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)

2013-01-15 05:40:00,342 ERROR [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Failed to start instance
VM[ConsoleProxy|v-83-VM]
java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be
cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-15 05:40:00,349 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Cleaning up resources for the vm
VM[ConsoleProxy|v-83-VM] in Starting state
2013-01-15 05:40:00,351 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227199: Sending  { Cmd , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 100111,
[{"StopCommand":{"isProxy":false,"vmName":"v-83-VM","wait":0}}] }
2013-01-15 05:40:00,601 DEBUG [agent.transport.Request]
(AgentManager-Handler-15:null) Seq 1-2027227199: Processing:  { Ans: ,
MgmtId: 52242164673, via: 1, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2013-01-15 05:40:00,602 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-15:null) Seq 1-2027227199: No more commands
found
2013-01-15 05:40:00,602 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-2027227199: Received:  { Ans: , MgmtId:
52242164673, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,638 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[328-83-37122d6d-0259-4b1a-8638-6b6148037bd9-192.168.71.71]
2013-01-15 05:40:00,650 DEBUG [network.guru.ControlNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[329-83-null-null-null
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,655 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[329-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,662 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(consoleproxy-1:null) Releasing ip address for
reservationId=37122d6d-0259-4b1a-8638-6b6148037bd9, instance=330
2013-01-15 05:40:00,666 DEBUG [network.guru.PodBasedNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[330-83-null-null-null
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking ExternalDhcpServer to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BareMetal to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[330-83-37122d6d-0259-4b1a-8638-6b6148037bd9-null]
2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully released network resources for the
vm VM[ConsoleProxy|v-83-VM]
2013-01-15 05:40:00,670 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully cleanued up resources for the vm
VM[ConsoleProxy|v-83-VM] in Starting state
2013-01-15 05:40:00,678 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Starting to Stopped
with event: OperationFailedvm's original host id: null new host id:
null host id before state transition: 1
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total CPU: 8000 and CPU after
applying overprovisioning: 8000
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release cpu from host: 1, old used:
500,reserved: 0, actual total: 8000, total with overprovisioning:
8000; new used: 0,reserved:0; movedfromreserved:
false,moveToReserveredfalse
2013-01-15 05:40:00,681 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release mem from host: 1, old used:
1073741824,reserved: 0, total: 16726679552; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2013-01-15 05:40:00,685 WARN
[cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null)
Exception while trying to start console proxy
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to
com.cloud.agent.api.Answer cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:847)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:472)
        at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:465)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:627)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1164)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1981)
        at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:173)
        at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:113)
        at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:34)
        at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:83)
        at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:73)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer
cannot be cast to
com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
        at com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateManagerImpl.java:663)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.storage.StorageManagerImpl.createVolume(StorageManagerImpl.java:3442)
        at com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3351)
        at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:754)
        ... 19 more





---------------------------------------------


And this is KVM Agent log


[root@kvm01 agent]# tail -f agent.log
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-16 01:51:18,634 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-1:null) org.libvirt.LibvirtException: internal
error Child process (/bin/mount
192.168.71.50:/export/secondary/template/tmpl/1/3
/mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit
status 32
2013-01-16 01:51:18,640 WARN  [cloud.agent.Agent]
(agentRequest-Handler-1:null) Caught:
java.lang.NullPointerException
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:462)
        at com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByURI(LibvirtStorageAdaptor.java:745)
        at com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByURI(KVMStoragePoolManager.java:52)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:2017)
        at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1009)
        at com.cloud.agent.Agent.processRequest(Agent.java:518)
        at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:831)
        at com.cloud.utils.nio.Task.run(Task.java:83)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
2013-01-16 01:51:18,956 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-4:null) org.libvirt.LibvirtException: internal
error Child process (/bin/mount
192.168.71.50:/export/secondary/template/tmpl/1/3
/mnt/ba4c9106-f7f9-3d6e-a87f-97544149b33b) status unexpected: exit
status 32
2013-01-16 01:51:18,961 WARN  [cloud.agent.Agent]
(agentRequest-Handler-4:null) Caught:



On 1/16/13, Mahfuj Jia <ma...@gmail.com> wrote:
> Thanks for your replying
>
> I have send you Logs.zip file.Please sir give me suggestion.
>
> On Tue, Jan 15, 2013 at 10:07 PM, Rajesh Battala
> <ra...@citrix.com>wrote:
>
>> Hi Mahfuj,
>> Can you post the DEBUG log of MS and kvm agent.
>>
>> Thanks
>> Rajesh Battala
>>
>> -----Original Message-----
>> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
>> Sent: Tuesday, January 15, 2013 8:52 PM
>> To: cloudstack-users@incubator.apache.org
>> Subject: Host installed ok. Only problem appears to be with the System
>> VMs
>> coming up
>>
>> Hi, I am using CloudStack4 official installation guide and successfully
>> installed the following things
>>
>>
>> 1. One Management Server. (Linux Centos x86_64) 2. One KVM host server.
>> (Linux Centos x86_64)
>>
>> Cloudstack 4.0 installation process:
>>
>> At Management Server:
>>
>> 1. Install cloud-client. (Successfully)
>> 2. Install Mysql Server. (Succesfully)
>> 3. Cloud Database Created. (Successfully) 4. NFS Server installed.
>> (Successfully).
>> 5. NFS Share. (Successfully)
>>
>>
>> At Client Machine:
>>
>> 1. Install cloud-agent. (Successfully)
>> 2. NFS mount. (Successfully)
>>
>> The main problem is after successfully adding host from CloudStack user
>> interface  when System VM coming up following exceptions has thrown
>>
>>  *Exception while trying to start secondary storage vm*
>> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
>> unreachable: Host 1: Unable to start instance due to Unable to get answer
>> that is of class com.cloud.agent.api.StartAnswer
>>
>> 2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
>> (secstorage-1:null) Failed to start instance
>> VM[SecondaryStorageVm|s-142-VM]
>> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast
>> to
>> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>>
>> 2013-01-15 03:05:55,580 INFO
>> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
>> (secstorage-1:null)*Primary secondary storage is not even started, wait
>> until next turn
>> *
>>
>>
>> How I  will solve this problem.Please if you have any recommendation tell
>> me.
>>
>

Re: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Mahfuj Jia <ma...@gmail.com>.

Thanks for your replying

I have send you Logs.zip file.Please sir give me suggestion.

On Tue, Jan 15, 2013 at 10:07 PM, Rajesh Battala
<ra...@citrix.com>wrote:

> Hi Mahfuj,
> Can you post the DEBUG log of MS and kvm agent.
>
> Thanks
> Rajesh Battala
>
> -----Original Message-----
> From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com]
> Sent: Tuesday, January 15, 2013 8:52 PM
> To: cloudstack-users@incubator.apache.org
> Subject: Host installed ok. Only problem appears to be with the System VMs
> coming up
>
> Hi, I am using CloudStack4 official installation guide and successfully
> installed the following things
>
>
> 1. One Management Server. (Linux Centos x86_64) 2. One KVM host server.
> (Linux Centos x86_64)
>
> Cloudstack 4.0 installation process:
>
> At Management Server:
>
> 1. Install cloud-client. (Successfully)
> 2. Install Mysql Server. (Succesfully)
> 3. Cloud Database Created. (Successfully) 4. NFS Server installed.
> (Successfully).
> 5. NFS Share. (Successfully)
>
>
> At Client Machine:
>
> 1. Install cloud-agent. (Successfully)
> 2. NFS mount. (Successfully)
>
> The main problem is after successfully adding host from CloudStack user
> interface  when System VM coming up following exceptions has thrown
>
>  *Exception while trying to start secondary storage vm*
> com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
> unreachable: Host 1: Unable to start instance due to Unable to get answer
> that is of class com.cloud.agent.api.StartAnswer
>
> 2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
> (secstorage-1:null) Failed to start instance
> VM[SecondaryStorageVm|s-142-VM]
> java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to
> com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer
>
> 2013-01-15 03:05:55,580 INFO
> [cloud.secstorage.PremiumSecondaryStorageManagerImpl]
> (secstorage-1:null)*Primary secondary storage is not even started, wait
> until next turn
> *
>
>
> How I  will solve this problem.Please if you have any recommendation tell
> me.
>

RE: Host installed ok. Only problem appears to be with the System VMs coming up

Posted by Rajesh Battala <ra...@citrix.com>.

Hi Mahfuj,
Can you post the DEBUG log of MS and kvm agent. 

Thanks
Rajesh Battala

-----Original Message-----
From: Mahfuj Jia [mailto:mahfuj8114562@gmail.com] 
Sent: Tuesday, January 15, 2013 8:52 PM
To: cloudstack-users@incubator.apache.org
Subject: Host installed ok. Only problem appears to be with the System VMs coming up

Hi, I am using CloudStack4 official installation guide and successfully installed the following things

1. One Management Server. (Linux Centos x86_64) 2. One KVM host server. (Linux Centos x86_64)

Cloudstack 4.0 installation process:

At Management Server:

1. Install cloud-client. (Successfully)
2. Install Mysql Server. (Succesfully)
3. Cloud Database Created. (Successfully) 4. NFS Server installed. (Successfully).
5. NFS Share. (Successfully)

At Client Machine:

1. Install cloud-agent. (Successfully)
2. NFS mount. (Successfully)

The main problem is after successfully adding host from CloudStack user interface  when System VM coming up following exceptions has thrown

 *Exception while trying to start secondary storage vm*
com.cloud.exception.AgentUnavailableException: Resource [Host:1] is
unreachable: Host 1: Unable to start instance due to Unable to get answer that is of class com.cloud.agent.api.StartAnswer

2013-01-15 03:05:55,238 ERROR [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Failed to start instance VM[SecondaryStorageVm|s-142-VM]
java.lang.ClassCastException: com.cloud.agent.api.Answer cannot be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer

2013-01-15 03:05:55,580 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl]
(secstorage-1:null)*Primary secondary storage is not even started, wait until next turn
*

How I  will solve this problem.Please if you have any recommendation tell me.