Return-Path: X-Original-To: apmail-cloudstack-issues-archive@www.apache.org Delivered-To: apmail-cloudstack-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 4B24017C94 for ; Thu, 19 Feb 2015 05:51:12 +0000 (UTC) Received: (qmail 84097 invoked by uid 500); 19 Feb 2015 05:51:11 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 84063 invoked by uid 500); 19 Feb 2015 05:51:11 -0000 Mailing-List: contact issues-help@cloudstack.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cloudstack.apache.org Delivered-To: mailing list issues@cloudstack.apache.org Received: (qmail 84053 invoked by uid 500); 19 Feb 2015 05:51:11 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 84050 invoked by uid 99); 19 Feb 2015 05:51:11 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 19 Feb 2015 05:51:11 +0000 Date: Thu, 19 Feb 2015 05:51:11 +0000 (UTC) From: "Rajani Karuturi (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (CLOUDSTACK-4496) [VMWARE]System VM's are failed to start with NPE when host is maitanance state MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-4496?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ] Rajani Karuturi updated CLOUDSTACK-4496: ---------------------------------------- Fix Version/s: (was: 4.3.2) 4.5.0 > [VMWARE]System VM's are failed to start with NPE when host is maitanance state > ------------------------------------------------------------------------------ > > Key: CLOUDSTACK-4496 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-4496 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the default.) > Affects Versions: 4.2.1 > Reporter: Sailaja Mada > Assignee: Sateesh Chodapuneedi > Fix For: 4.5.0 > > Attachments: errorlogs.rar > > > Steps: > 1. Configure Adv Zone with VMWARE using standard vSwitch (All the traffics are with single with Physical Network) > 2. From vCenter, ESXi host is in Maintenance state . > 3. System VM's failed to start with NPE when host is maitanance state > 2013-08-26 12:40:10,132 DEBUG [cloud.capacity.CapacityManagerImpl] (secstorage-1:null) release mem from host: 1, old used: 268435456,reserved: 0, total: 17166258176; new used: 0,reserved:0; movedfromreserved: false,moveToReserveredfalse > 2013-08-26 12:40:10,139 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 null > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:981) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:568) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:267) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696) > at com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1300) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:123) > at com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:50) > at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104) > at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33) > at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81) > at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72) > 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.NullPointerException > at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:421) > at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:543) > at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2526) > at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2582) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:885) > ... 20 more > 2013-08-26 12:40:10,142 INFO [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable to start secondary storage vm for standby capacity, secStorageVm vm Id : 1, will recycle it and start a new one > 2013-08-26 12:40:10,143 INFO [cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null) Primary secondary storage is not even started, wait until next turn > 2013-08-26 12:40:34,135 DEBUG [storage.image.TemplateDataFactoryImpl] (consoleproxy-1:null) template 8 is already in store:1, type:Primary > 2013-08-26 12:40:34,140 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Found template routing-8 in storage pool 1 with VMTemplateStoragePool id: 2 > 2013-08-26 12:40:34,156 DEBUG [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Acquire lock on VMTemplateStoragePool 2 with timeout 3600 seconds > 2013-08-26 12:40:34,201 ERROR [storage.resource.VmwareStorageProcessor] (DirectAgent-6:10.102.192.13) Unable to copy template to primary storage due to exception:Exception: com.vmware.vim25.InvalidState > message: [] > com.vmware.vim25.InvalidStateFaultMsg: The operation is not allowed in the current state. > at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) > at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) > at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) > at java.lang.reflect.Constructor.newInstance(Constructor.java:532) > at com.sun.xml.internal.ws.fault.SOAPFaultBuilder.createException(SOAPFaultBuilder.java:130) > at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:108) > at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:78) > at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:107) > at $Proxy90.httpNfcLeaseComplete(Unknown Source) > at com.cloud.hypervisor.vmware.mo.HttpNfcLeaseMO.completeLease(HttpNfcLeaseMO.java:91) > at com.cloud.hypervisor.vmware.mo.HypervisorHostHelper.importVmFromOVF(HypervisorHostHelper.java:1381) > at com.cloud.hypervisor.vmware.mo.HostMO.importVmFromOVF(HostMO.java:736) > at com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateFromSecondaryToPrimary(VmwareStorageProcessor.java:162) > at com.cloud.storage.resource.VmwareStorageProcessor.copyTemplateToPrimaryStorage(VmwareStorageProcessor.java:221) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.execute(StorageSubsystemCommandHandlerBase.java:70) > at com.cloud.storage.resource.VmwareStorageSubsystemCommandHandler.execute(VmwareStorageSubsystemCommandHandler.java:147) > at com.cloud.storage.resource.StorageSubsystemCommandHandlerBase.handleStorageCommands(StorageSubsystemCommandHandlerBase.java:49) > at com.cloud.hypervisor.vmware.resource.VmwareResource.executeRequest(VmwareResource.java:560) > at com.cloud.agent.manager.DirectAgentAttache$Task.run(DirectAgentAttache.java:186) > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) > at java.util.concurrent.FutureTask.run(FutureTask.java:166) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165) > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266) > 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-08-26 12:40:34,202 DEBUG [agent.manager.DirectAgentAttache] (DirectAgent-6:null) Seq 1-503316490: Response Received: > 2013-08-26 12:40:34,203 DEBUG [agent.transport.Request] (DirectAgent-6:null) Seq 1-503316490: Processing: { Ans: , MgmtId: 94838926819810, via: 1, Ver: v1, Flags: 10, [{"org.apache.cloudstack.storage.command.CopyCmdAnswer":{"result":false,"details":"Unable to copy template to primary storage due to exception:Exception: com.vmware.vim25.InvalidState\nmessage: []\n","wait":0}}] } > 2013-08-26 12:40:34,203 DEBUG [agent.transport.Request] (secstorage-1:null) Seq 1-503316490: Received: { Ans: , MgmtId: 94838926819810, via: 1, Ver: v1, Flags: 10, { CopyCmdAnswer } } > 2013-08-26 12:40:34,222 INFO [storage.volume.VolumeServiceImpl] (secstorage-1:null) releasing lock for VMTemplateStoragePool 2 > 2013-08-26 12:40:34,835 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 routers to update status. > 2013-08-26 12:40:34,837 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0 networks to update RvR status. > 2013-08-26 12:40:39,159 INFO [storage.volume.VolumeServiceImpl] (consoleproxy-1:null) Unable to acquire lock on VMTemplateStoragePool 2 > 2013-08-26 12:40:39,161 ERROR [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Failed to start instance VM[ConsoleProxy|v-2-VM] > java.lang.NullPointerException > at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createBaseImageAsync(VolumeServiceImpl.java:421) > at org.apache.cloudstack.storage.volume.VolumeServiceImpl.createVolumeFromTemplateAsync(VolumeServiceImpl.java:543) > at com.cloud.storage.VolumeManagerImpl.recreateVolume(VolumeManagerImpl.java:2526) > at com.cloud.storage.VolumeManagerImpl.prepare(VolumeManagerImpl.java:2582) > at com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:885) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:575) > at com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:568) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:556) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:928) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1672) > at com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:157) > at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111) > at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33) > at com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81) > at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72) > 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-08-26 12:40:39,168 DEBUG [cloud.vm.VirtualMachineManagerImpl] (consoleproxy-1:null) Cleaning up resources for the vm VM[ConsoleProxy|v-2-VM] in Starting state > 2013-08-26 12:40:39,172 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-503316492: Sending { Cmd , MgmtId: 94838926819810, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-2-VM","wait":0}}] } > 2013-08-26 12:40:39,172 DEBUG [agent.transport.Request] (consoleproxy-1:null) Seq 1-503316492: Executing: { Cmd , MgmtId: 94838926819810, via: 1, Ver: v1, Flags: 100011, [{"com.cloud.agent.api.StopCommand":{"isProxy":false,"executeInSequence":false,"vmName":"v-2-VM","wait":0}}] } -- This message was sent by Atlassian JIRA (v6.3.4#6332)