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 E0A9D10353 for ; Mon, 6 Jan 2014 08:54:35 +0000 (UTC) Received: (qmail 15703 invoked by uid 500); 6 Jan 2014 08:54:07 -0000 Delivered-To: apmail-cloudstack-issues-archive@cloudstack.apache.org Received: (qmail 15651 invoked by uid 500); 6 Jan 2014 08:54:05 -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 15636 invoked by uid 500); 6 Jan 2014 08:54:03 -0000 Delivered-To: apmail-incubator-cloudstack-issues@incubator.apache.org Received: (qmail 15624 invoked by uid 99); 6 Jan 2014 08:54:01 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 06 Jan 2014 08:54:01 +0000 Date: Mon, 6 Jan 2014 08:54:01 +0000 (UTC) From: "Abhinandan Prateek (JIRA)" To: cloudstack-issues@incubator.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Updated] (CLOUDSTACK-5706) Multiple NPEs when host is put in maintenance after upgrading from 4.2.1 to 4.3 MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/CLOUDSTACK-5706?page=3Dcom.atl= assian.jira.plugin.system.issuetabpanels:all-tabpanel ] Abhinandan Prateek updated CLOUDSTACK-5706: ------------------------------------------- Assignee: Bharat Kumar > Multiple NPEs when host is put in maintenance after upgrading from 4.2.1 = to 4.3 > -------------------------------------------------------------------------= ------ > > Key: CLOUDSTACK-5706 > URL: https://issues.apache.org/jira/browse/CLOUDSTACK-570= 6 > Project: CloudStack > Issue Type: Bug > Security Level: Public(Anyone can view this level - this is the defa= ult.)=20 > Components: Upgrade > Affects Versions: 4.3.0 > Environment: upgraded the CS from 4.2.1 to 4.3 > Reporter: manasaveloori > Assignee: Bharat Kumar > Priority: Critical > Fix For: 4.3.0 > > Attachments: management-server.rar, management-server.rar > > > Steps: > 1.=09Deployed CS 4.2.1 GA build with ESXi5.1(using Vsphere 5.1 client) > 2.=09Deployed some VMs. > 3.=09Upgraded the CS to 4.3. > 4. Put the host into maintenance---- which will be successful. > Observed the following NPEs in MSlogs. > 2014-01-01 20:17:11,749 DEBUG [c.c.a.ApiServlet] (catalina-exec-15:ctx-e3= 555589 ctx-1ab4f80c) =3D=3D=3DEND=3D=3D=3D 10.252.192.34 -- GET command= =3DprepareHostForMaintenance&id=3Ddbd66102-e51e-4014-be75-e7ac8ccb81f1&resp= onse=3Djson&sessionkey=3Dble18kT0VfY%2BEPq8V8DzAZsM8L0%3D&_=3D1388568267594 > 2014-01-01 20:17:11,752 INFO [o.a.c.f.j.i.AsyncJobMonitor] (Job-Executor= -118:ctx-e4cb1a1d) Add job-166 into job monitoring > 2014-01-01 20:17:11,752 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Exec= utor-118:ctx-e4cb1a1d) Executing AsyncJobVO {id:166, userId: 2, accountId: = 2, instanceType: Host, instanceId: 4, cmd: org.apache.cloudstack.api.comman= d.admin.host.PrepareForMaintenanceCmd, cmdInfo: {"response":"json","id":"db= d66102-e51e-4014-be75-e7ac8ccb81f1","sessionkey":"ble18kT0VfY+EPq8V8DzAZsM8= L0\u003d","cmdEventType":"MAINT.PREPARE","ctxUserId":"2","httpmethod":"GET"= ,"_":"1388568267594","ctxAccountId":"2","ctxStartEventId":"758"}, cmdVersio= n: 0, status: IN_PROGRESS, processStatus: 0, resultCode: 0, result: null, i= nitMsid: 6758231703598, completeMsid: null, lastUpdated: null, lastPolled: = null, created: null} > 2014-01-01 20:17:11,782 DEBUG [c.c.a.t.Request] (Job-Executor-118:ctx-e4c= b1a1d ctx-1ab4f80c) Seq 4-1399914503: Sending { Cmd , MgmtId: 675823170359= 8, via: 4(10.147.40.28), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.Mai= ntainCommand":{"wait":0}}] } > 2014-01-01 20:17:11,782 DEBUG [c.c.a.t.Request] (Job-Executor-118:ctx-e4c= b1a1d ctx-1ab4f80c) Seq 4-1399914503: Executing: { Cmd , MgmtId: 675823170= 3598, via: 4(10.147.40.28), Ver: v1, Flags: 100111, [{"com.cloud.agent.api.= MaintainCommand":{"wait":0}}] } > 2014-01-01 20:17:11,806 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4= 10:ctx-32cc846b) Seq 4-1399914503: Executing request > 2014-01-01 20:17:11,807 INFO [c.c.h.v.r.VmwareResource] (DirectAgent-410= :ctx-32cc846b 10.147.40.28) Executing resource MaintainCommand: {"wait":0} > 2014-01-01 20:17:11,814 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-4= 10:ctx-32cc846b) Seq 4-1399914503: Response Received: > 2014-01-01 20:17:11,814 DEBUG [c.c.a.t.Request] (DirectAgent-410:ctx-32cc= 846b) Seq 4-1399914503: Processing: { Ans: , MgmtId: 6758231703598, via: 4= , Ver: v1, Flags: 110, [{"com.cloud.agent.api.MaintainAnswer":{"willMigrate= ":true,"result":true,"details":"Put host in maintaince","wait":0}}] } > 2014-01-01 20:17:11,815 DEBUG [c.c.a.t.Request] (Job-Executor-118:ctx-e4c= b1a1d ctx-1ab4f80c) Seq 4-1399914503: Received: { Ans: , MgmtId: 675823170= 3598, via: 4, Ver: v1, Flags: 110, { MaintainAnswer } } > 2014-01-01 20:17:11,815 DEBUG [c.c.a.m.AgentManagerImpl] (Job-Executor-11= 8:ctx-e4cb1a1d ctx-1ab4f80c) Details from executing class com.cloud.agent.a= pi.MaintainCommand: Put host in maintaince > 2014-01-01 20:17:11,817 DEBUG [c.c.a.m.AgentAttache] (DirectAgent-410:ctx= -32cc846b) Seq 4-1399914503: No more commands found > 2014-01-01 20:17:11,834 DEBUG [c.c.r.ResourceState] (Job-Executor-118:ctx= -e4cb1a1d ctx-1ab4f80c) Resource state update: [id =3D 4; name =3D 10.147.4= 0.28; old state =3D Enabled; event =3D AdminAskMaintenace; new state =3D Pr= epareForMaintenance] > 2014-01-01 20:17:11,834 DEBUG [c.c.a.m.AgentAttache] (Job-Executor-118:ct= x-e4cb1a1d ctx-1ab4f80c) Seq 4-1399914499: Sending disconnect to class com.= cloud.network.security.SecurityGroupListener > 2014-01-01 20:17:11,888 DEBUG [c.c.h.HighAvailabilityManagerImpl] (Job-Ex= ecutor-118:ctx-e4cb1a1d ctx-1ab4f80c) Scheduled HAWork[44-ForceStop-9-Runni= ng-Scheduled] > 2014-01-01 20:17:11,910 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-07bb080c work-44) Processing HAWork[44-ForceStop-9-Running-Schedu= led] > 2014-01-01 20:17:11,917 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-07bb080c work-44) Stopping VM[DomainRouter|r-9-VM] > 2014-01-01 20:17:11,920 ERROR [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-07bb080c work-44) Terminating HAWork[44-ForceStop-9-Running-Sched= uled] > java.lang.NullPointerException > at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMach= ineManagerImpl.java:1264) > at com.cloud.ha.HighAvailabilityManagerImpl.stopVM(HighAvailabili= tyManagerImpl.java:692) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithC= ontext(HighAvailabilityManagerImpl.java:869) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$0= 00(HighAvailabilityManagerImpl.java:822) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(Hi= ghAvailabilityManagerImpl.java:834) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.runWithContext(DefaultManagedContext.java:53) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(High= AvailabilityManagerImpl.java:831) > 2014-01-01 20:17:11,919 DEBUG [c.c.h.HighAvailabilityManagerImpl] (Job-Ex= ecutor-118:ctx-e4cb1a1d ctx-1ab4f80c) Scheduled HAWork[45-ForceStop-10-Runn= ing-Scheduled] > 2014-01-01 20:17:11,926 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-1:ctx-ccc388fe work-45) Processing HAWork[45-ForceStop-10-Running-Sched= uled] > 2014-01-01 20:17:11,944 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-1:ctx-ccc388fe work-45) Stopping VM[User|tiervmBU] > 2014-01-01 20:17:11,949 ERROR [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-1:ctx-ccc388fe work-45) Terminating HAWork[45-ForceStop-10-Running-Sche= duled] > java.lang.NullPointerException > at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMach= ineManagerImpl.java:1264) > at com.cloud.ha.HighAvailabilityManagerImpl.stopVM(HighAvailabili= tyManagerImpl.java:692) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithC= ontext(HighAvailabilityManagerImpl.java:869) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$0= 00(HighAvailabilityManagerImpl.java:822) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(Hi= ghAvailabilityManagerImpl.java:834) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.runWithContext(DefaultManagedContext.java:53) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(High= AvailabilityManagerImpl.java:831) > 2014-01-01 20:17:11,957 DEBUG [c.c.h.HighAvailabilityManagerImpl] (Job-Ex= ecutor-118:ctx-e4cb1a1d ctx-1ab4f80c) Scheduled HAWork[46-ForceStop-13-Runn= ing-Scheduled] > 2014-01-01 20:17:11,975 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-c4ef9c26 work-46) Processing HAWork[46-ForceStop-13-Running-Sched= uled] > 2014-01-01 20:17:11,985 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-c4ef9c26 work-46) Stopping VM[ConsoleProxy|v-13-VM] > 2014-01-01 20:17:11,985 ERROR [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-c4ef9c26 work-46) Terminating HAWork[46-ForceStop-13-Running-Sche= duled] > java.lang.NullPointerException > at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMach= ineManagerImpl.java:1264) > at com.cloud.ha.HighAvailabilityManagerImpl.stopVM(HighAvailabili= tyManagerImpl.java:692) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithC= ontext(HighAvailabilityManagerImpl.java:869) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$0= 00(HighAvailabilityManagerImpl.java:822) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(Hi= ghAvailabilityManagerImpl.java:834) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.runWithContext(DefaultManagedContext.java:53) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(High= AvailabilityManagerImpl.java:831) > 2014-01-01 20:17:11,989 DEBUG [c.c.h.HighAvailabilityManagerImpl] (Job-Ex= ecutor-118:ctx-e4cb1a1d ctx-1ab4f80c) Scheduled HAWork[47-ForceStop-14-Runn= ing-Scheduled] > 2014-01-01 20:17:12,008 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-1:ctx-6541a513 work-47) Processing HAWork[47-ForceStop-14-Running-Sched= uled] > 2014-01-01 20:17:12,011 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-1:ctx-6541a513 work-47) Stopping VM[SecondaryStorageVm|s-14-VM] > 2014-01-01 20:17:12,012 ERROR [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-1:ctx-6541a513 work-47) Terminating HAWork[47-ForceStop-14-Running-Sche= duled] > java.lang.NullPointerException > at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMach= ineManagerImpl.java:1264) > at com.cloud.ha.HighAvailabilityManagerImpl.stopVM(HighAvailabili= tyManagerImpl.java:692) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithC= ontext(HighAvailabilityManagerImpl.java:869) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$0= 00(HighAvailabilityManagerImpl.java:822) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(Hi= ghAvailabilityManagerImpl.java:834) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.runWithContext(DefaultManagedContext.java:53) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(High= AvailabilityManagerImpl.java:831) > 2014-01-01 20:17:12,020 DEBUG [c.c.h.HighAvailabilityManagerImpl] (Job-Ex= ecutor-118:ctx-e4cb1a1d ctx-1ab4f80c) Scheduled HAWork[48-ForceStop-15-Runn= ing-Scheduled] > 2014-01-01 20:17:12,038 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-b75f1173 work-48) Processing HAWork[48-ForceStop-15-Running-Sched= uled] > 2014-01-01 20:17:12,045 INFO [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-b75f1173 work-48) Stopping VM[User|VM-8d5bebec-4c34-4b74-aeca-9b2= 41e82f08a] > 2014-01-01 20:17:12,047 ERROR [c.c.h.HighAvailabilityManagerImpl] (HA-Wor= ker-0:ctx-b75f1173 work-48) Terminating HAWork[48-ForceStop-15-Running-Sche= duled] > java.lang.NullPointerException > at com.cloud.vm.VirtualMachineManagerImpl.advanceStop(VirtualMach= ineManagerImpl.java:1264) > at com.cloud.ha.HighAvailabilityManagerImpl.stopVM(HighAvailabili= tyManagerImpl.java:692) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.runWithC= ontext(HighAvailabilityManagerImpl.java:869) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.access$0= 00(HighAvailabilityManagerImpl.java:822) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread$1.run(Hi= ghAvailabilityManagerImpl.java:834) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt$1.call(DefaultManagedContext.java:56) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.callWithContext(DefaultManagedContext.java:103) > at org.apache.cloudstack.managed.context.impl.DefaultManagedConte= xt.runWithContext(DefaultManagedContext.java:53) > at com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(High= AvailabilityManagerImpl.java:831) > 2014-01-01 20:17:12,073 DEBUG [c.c.r.ResourceManagerImpl] (Job-Executor-1= 18:ctx-e4cb1a1d ctx-1ab4f80c) Sent resource event EVENT_PREPARE_MAINTENANCE= _AFTER to listener CapacityManagerImpl > 2014-01-01 20:17:12,088 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Exec= utor-118:ctx-e4cb1a1d ctx-1ab4f80c) Complete async job-166, jobStatus: SUCC= EEDED, resultCode: 0, result: org.apache.cloudstack.api.response.HostRespon= se/host/{"id":"dbd66102-e51e-4014-be75-e7ac8ccb81f1","name":"10.147.40.28",= "state":"Up","disconnected":"2013-12-31T17:12:03+0530","type":"Routing","ip= address":"10.147.40.28","zoneid":"4daf5bda-ff3e-42b2-97e3-936d25ba57ef","zo= nename":"manasa","podid":"b0e11a62-bc03-4a5f-9056-34f7da627b28","podname":"= podVMw","version":"4.3.0-SNAPSHOT","hypervisor":"VMware","cpusockets":1,"cp= unumber":4,"cpuspeed":2394,"cpuallocated":"0%","cpuused":"0%","cpuwithoverp= rovisioning":"9576.0","networkkbsread":0,"networkkbswrite":0,"memorytotal":= 17169539072,"memoryallocated":0,"memoryused":0,"capabilities":"hvm","lastpi= nged":"1970-01-16T22:10:42+0530","managementserverid":6758231703598,"cluste= rid":"16b91cfa-6ba3-485d-b2d6-bfc9153cd4dc","clustername":"10.147.60.9/mana= sa/clusterVMw","clustertype":"ExternalManaged","islocalstorageactive":false= ,"created":"2013-12-30T22:52:13+0530","events":"AgentConnected; StartAgentR= ebalance; Ping; AgentDisconnected; HostDown; PingTimeout; ShutdownRequested= ; ManagementServerDown; Remove","resourcestate":"PrepareForMaintenance","hy= pervisorversion":"5.1","hahost":false,"jobid":"60fed810-c048-4759-9ae2-9e82= 27bc4583","jobstatus":0} > 2014-01-01 20:17:12,102 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (Job-Exec= utor-118:ctx-e4cb1a1d) Done executing org.apache.cloudstack.api.command.adm= in.host.PrepareForMaintenanceCmd for job-166. > Attaching the Ms logs: -- This message was sent by Atlassian JIRA (v6.1.5#6160)