Return-Path: X-Original-To: apmail-incubator-cloudstack-users-archive@minotaur.apache.org Delivered-To: apmail-incubator-cloudstack-users-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id EAA67E8F8 for ; Wed, 16 Jan 2013 14:36:09 +0000 (UTC) Received: (qmail 7684 invoked by uid 500); 16 Jan 2013 14:36:09 -0000 Delivered-To: apmail-incubator-cloudstack-users-archive@incubator.apache.org Received: (qmail 7531 invoked by uid 500); 16 Jan 2013 14:36:09 -0000 Mailing-List: contact cloudstack-users-help@incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: cloudstack-users@incubator.apache.org Delivered-To: mailing list cloudstack-users@incubator.apache.org Received: (qmail 7520 invoked by uid 99); 16 Jan 2013 14:36:09 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 16 Jan 2013 14:36:09 +0000 X-ASF-Spam-Status: No, hits=-0.5 required=5.0 tests=FREEMAIL_ENVFROM_END_DIGIT,RCVD_IN_DNSWL_LOW,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of mahfuj8114562@gmail.com designates 209.85.220.45 as permitted sender) Received: from [209.85.220.45] (HELO mail-pa0-f45.google.com) (209.85.220.45) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 16 Jan 2013 14:36:04 +0000 Received: by mail-pa0-f45.google.com with SMTP id bg2so818467pad.32 for ; Wed, 16 Jan 2013 06:35:43 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:x-received:in-reply-to:references:date:message-id :subject:from:to:content-type:content-transfer-encoding; bh=gNtjDg2XFcC613sfTHfuu5jfk7VJwC1CRGkRMPi70qU=; b=Q4LHXYfNrAeyEtcMiIxNlOmqLGuiqTQD6WFy9FBRz3xbI62PjL1xOpRJXF/hIHiCnO o/oXDhrM9xEVD/tEdoc+jjSUhmvihjeoBtk8zPjsPvElNshXx1+mKvI3qfBKOZi0hjW6 xdwlzI8/kc/n+u9qcvcpK8IKmT7ELFI+4cYsyoOzRUbIetUfxvo1vWe1P+OM6NxQEJXP 8EtFjW4TOcE53oUH0cEEk7GnEAoK4qR6oV8ocQnPW2vrWswgbpvez0D62Fw7cyr/Pdf8 mJKEod1u8/He+bbI1GVFMNDshrd9xcbi0fVL5oLvpf4moc4x1KfjcI5b5g8cSEaCSknq wtlg== MIME-Version: 1.0 X-Received: by 10.66.72.226 with SMTP id g2mr4066409pav.67.1358346943897; Wed, 16 Jan 2013 06:35:43 -0800 (PST) Received: by 10.68.200.99 with HTTP; Wed, 16 Jan 2013 06:35:43 -0800 (PST) In-Reply-To: <97F4356AEA71904482CD192135C038F901185E673C02@BANPMAILBOX01.citrite.net> References: <97F4356AEA71904482CD192135C038F901185E673AB1@BANPMAILBOX01.citrite.net> <97F4356AEA71904482CD192135C038F901185E673C02@BANPMAILBOX01.citrite.net> Date: Wed, 16 Jan 2013 20:35:43 +0600 Message-ID: Subject: Re: Host installed ok. Only problem appears to be with the System VMs coming up From: Mahfuj Jia To: cloudstack-users@incubator.apache.org Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable X-Virus-Checked: Checked by ClamAV on apache.org 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 wrote: > Hi Mahfuj, > > From the logs it looks like issue while mounting the primary storage moun= t > 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 po= int > 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 Syste= m > 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=3Da47e227a-1c5c-4a5e-8e26-3dd9a81e81cf, instance=3D1182 > 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(VirtualMachineManager= Impl.java:847) > at > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.ja= va:472) > at > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.ja= va:465) > at > com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm= (SecondaryStorageManagerImpl.java:257) > at > com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(Sec= ondaryStorageManagerImpl.java:684) > at > com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(Second= aryStorageManagerImpl.java:1310) > at > com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumS= econdaryStorageManagerImpl.java:119) > at > com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumS= econdaryStorageManagerImpl.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:17= 8) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.acce= ss$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.jav= a:603) > at java.lang.Thread.run(Thread.java:679) > Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer canno= t > be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer > at > com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateM= anagerImpl.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(VirtualMachineManager= Impl.java:754) > ... 20 more > 2013-01-15 05:39:55,679 INFO > [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unabl= e > 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,"se= condaryStorageUrl":"nfs://192.168.71.50/export/secondary","primaryStorageUr= l":"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\ta= t > com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(= LibvirtStorageAdaptor.java:462)\n\tat > com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByUR= I(LibvirtStorageAdaptor.java:745)\n\tat > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByUR= I(KVMStoragePoolManager.java:52)\n\tat > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(Libvir= tComputingResource.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.jav= a: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.getStoragePoolByUR= I(LibvirtStorageAdaptor.java:745) > at > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByUR= I(KVMStoragePoolManager.java:52) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(Libvir= tComputingResource.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:83= 1) > 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.jav= a: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 t= o > com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer > at > com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateM= anagerImpl.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(VirtualMachineManager= Impl.java:754) > at > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.ja= va:472) > at > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.ja= va:465) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyMan= agerImpl.java:627) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxy= ManagerImpl.java:1164) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyMan= agerImpl.java:1981) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyMan= agerImpl.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:17= 8) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.acce= ss$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.jav= a: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=3D37122d6d-0259-4b1a-8638-6b6148037bd9, instance=3D330 > 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 applyi= ng > 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) Except= ion > 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(VirtualMachineManager= Impl.java:847) > at > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.ja= va:472) > at > com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.ja= va:465) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyMan= agerImpl.java:627) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxy= ManagerImpl.java:1164) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyMan= agerImpl.java:1981) > at > com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyMan= agerImpl.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:17= 8) > at > java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.acce= ss$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.jav= a:603) > at java.lang.Thread.run(Thread.java:679) > Caused by: java.lang.ClassCastException: com.cloud.agent.api.Answer canno= t > be cast to com.cloud.agent.api.storage.PrimaryStorageDownloadAnswer > at > com.cloud.template.TemplateManagerImpl.prepareTemplateForCreate(TemplateM= anagerImpl.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(VirtualMachineManager= Impl.java:754) > ... 19 more > > > > > > --------------------------------------------- > > > And this is KVM Agent log > > > [root@kvm01 agent]# tail -f agent.log > at > com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getStoragePoolByUR= I(LibvirtStorageAdaptor.java:745) > at > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByUR= I(KVMStoragePoolManager.java:52) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(Libvir= tComputingResource.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:83= 1) > 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.jav= a: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 erro= r > 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.getStoragePoolByUR= I(LibvirtStorageAdaptor.java:745) > at > com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.getStoragePoolByUR= I(KVMStoragePoolManager.java:52) > at > com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(Libvir= tComputingResource.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:83= 1) > 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.jav= a: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 erro= r > 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 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 >> 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. >>> >> >