You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by Sonali Jadhav <so...@servercentralen.se> on 2015/07/06 10:08:03 UTC
NPE while adding host into maintenance in ACS 4.5.1
Hi,
In order to update xenserver from 6.2 to 6.5, I added pool master in maintenance mode from ACS. In ACS it said successful , and it started to move vms to another host in cluster, except few since xenserver tool was not installed on them. So I shut those vms down from acs. But host was not sent to maintenance in xencenter. My host went to "alert" state. And now I can't do any operations since it's in alert state.
I am seeing this error in logs,
015-07-06 09:54:02,400 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-a4685473) Seq 1-1601874092460343301: Received: { Ans: , MgmtId: 59778234354585, via: 1, Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } }
2015-07-06 09:54:02,415 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-165:ctx-fe175294) Seq 5-8999880905346524321: Executing request
2015-07-06 09:54:02,437 INFO [o.a.c.s.d.p.DefaultHostListener] (AgentTaskPool-1:ctx-a4685473) Connection established between storage pool org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@74be27a7 and host 1
2015-07-06 09:54:02,444 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Found storage pool PrimStore of type NetworkFilesystem with overprovisioning factor 2
2015-07-06 09:54:02,445 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Total over provisioned capacity calculated is 2 * 11579495022592
2015-07-06 09:54:02,445 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Total over provisioned capacity of the pool PrimStore id: 1 is 23158990045184
2015-07-06 09:54:02,446 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Successfully set Capacity - 23158990045184 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 1, PodId 1
2015-07-06 09:54:02,446 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Connect to listener: DeploymentPlanningManagerImpl
2015-07-06 09:54:02,446 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Connect to listener: StorageCapacityListener
2015-07-06 09:54:02,447 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Connect to listener: ComputeCapacityListener
2015-07-06 09:54:02,451 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-a4685473) Found 0 VMs on host 1
2015-07-06 09:54:02,458 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-a4685473) Found 4 VM, not running on host 1
2015-07-06 09:54:02,459 ERROR [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Monitor ComputeCapacityListener says there is an error in the connect process for 1 due to null
java.lang.NullPointerException
at com.cloud.capacity.CapacityManagerImpl.updateCapacityForHost(CapacityManagerImpl.java:648)
at com.cloud.capacity.ComputeCapacityListener.processConnect(ComputeCapacityListener.java:66)
at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:539)
at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1447)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1794)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1920)
at sun.reflect.GeneratedMethodAccessor263.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.createHostAndAgent(Unknown Source)
at com.cloud.agent.manager.AgentManagerImpl$SimulateStartTask.runInContext(AgentManagerImpl.java:1078)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-07-06 09:54:02,460 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Host 1 is disconnecting with event AgentDisconnected
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) The next status of agent 1is Alert, current status is Connecting
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Deregistering link for 1 with state Alert
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Remove Agent : 1
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.DirectAgentAttache] (AgentTaskPool-1:ctx-a4685473) Processing disconnect 1(SeSolXS01)
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.hypervisor.vmware.manager.VmwareManagerImpl
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.capacity.StorageCapacityListener
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.capacity.ComputeCapacityListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.LocalStoragePoolListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener
2015-07-06 09:54:02,463 DEBUG [c.c.n.NetworkUsageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Disconnected called on 1 with status Alert
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.upload.UploadListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.download.DownloadListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener
2015-07-06 09:54:02,464 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2015-07-06 09:54:02,464 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl
2015-07-06 09:54:02,464 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener
2015-07-06 09:54:02,465 DEBUG [c.c.h.Status] (AgentTaskPool-1:ctx-a4685473) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 1, name = SeSolXS01]
2015-07-06 09:54:02,486 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-165:ctx-fe175294) Seq 5-8999880905346524321: Response Received:
2015-07-06 09:54:02,486 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (DirectAgent-165:ctx-fe175294) Seq 5-8999880905346524321: MgmtId 249373720971888: Resp: Routing to peer
2015-07-06 09:54:02,505 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-42:ctx-4b3b996b) Seq 6-1232297448039261404: Executing request
2015-07-06 09:54:02,507 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Notifying other nodes of to disconnect
2015-07-06 09:54:02,519 DEBUG [c.c.c.ClusterManagerImpl] (AgentTaskPool-1:ctx-a4685473) Forwarding [{"com.cloud.agent.api.ChangeAgentCommand":{"agentId":1,"event":"AgentDisconnected","contextMap":{},"wait":0}}] to 249373720971888
2015-07-06 09:54:02,520 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-3:ctx-0a51ef05) Cluster PDU 59778234354585 -> 249373720971888. agent: 1, pdu seq: 25, pdu ack seq: 0, json: [{"com.cloud.agent.api.ChangeAgentCommand":{"agentId":1,"event":"AgentDisconnected","contextMap":{},"wait":0}}]
2015-07-06 09:54:02,520 WARN [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-a4685473) Unable to connect due to
com.cloud.utils.exception.CloudRuntimeException: Unable to connect 1
at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:561)
at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1447)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1794)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1920)
at sun.reflect.GeneratedMethodAccessor263.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.createHostAndAgent(Unknown Source)
at com.cloud.agent.manager.AgentManagerImpl$SimulateStartTask.runInContext(AgentManagerImpl.java:1078)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.NullPointerException
at com.cloud.capacity.CapacityManagerImpl.updateCapacityForHost(CapacityManagerImpl.java:648)
at com.cloud.capacity.ComputeCapacityListener.processConnect(ComputeCapacityListener.java:66)
at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:539)
... 22 more
2015-07-06 09:54:02,522 DEBUG [c.c.h.Status] (AgentTaskPool-1:ctx-a4685473) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 1, name = SeSolXS01]
2015-07-06 09:54:02,523 DEBUG [c.c.c.ClusterServiceServletImpl] (Cluster-Worker-3:ctx-0a51ef05) POST http://172.16.5.190:9090/clusterservice response :true, responding time: 3 ms
2015-07-06 09:54:02,523 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-3:ctx-0a51ef05) Cluster PDU 59778234354585 -> 249373720971888 completed. time: 3ms. agent: 1, pdu seq: 25, pdu ack seq: 0, json: [{"com.cloud.agent.api.ChangeAgentCommand":{"agentId":1,"event":"AgentDisconnected","contextMap":{},"wait":0}}]
2015-07-06 09:54:02,561 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-42:ctx-4b3b996b) Seq 6-1232297448039261404: Response Received:
2015-07-06 09:54:02,561 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (DirectAgent-42:ctx-4b3b996b) Seq 6-1232297448039261404: MgmtId 249373720971888: Resp: Routing to peer
2015-07-06 09:54:02,572 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Completed creating agent for host 1
2015-07-06 09:54:02,722 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgentCronJob-236:ctx-79815165) Seq 5-6790865288121286660: Executing request
I tried to give maintenance cmd again but failed,
2015-07-06 09:40:01,441 DEBUG [c.c.a.m.AgentManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786 ctx-c88bc8f8) Can not send command com.cloud.agent.api.MaintainCommand due to Host 1 is not up
2015-07-06 09:40:01,441 WARN [c.c.r.ResourceManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786 ctx-c88bc8f8) Unable to send MaintainCommand to host: 1
2015-07-06 09:40:01,441 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Unexpected exception while executing org.apache.cloudstack.api.command.admin.host.PrepareForMaintenanceCmd
com.cloud.utils.exception.CloudRuntimeException: Unable to prepare for maintenance host 1
at com.cloud.resource.ResourceManagerImpl.maintain(ResourceManagerImpl.java:1251)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.maintain(Unknown Source)
at org.apache.cloudstack.api.command.admin.host.PrepareForMaintenanceCmd.execute(PrepareForMaintenanceCmd.java:102)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:537)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:494)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-07-06 09:40:01,443 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Complete async job-3786, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable to prepare for maintenance host 1"}
2015-07-06 09:40:01,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Publish async job-3786 complete on message bus
2015-07-06 09:40:01,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Wake up jobs related to job-3786
/sonali
RE: NPE while adding host into maintenance in ACS 4.5.1
Posted by Koushik Das <ko...@citrix.com>.
This should fix the problem https://issues.apache.org/jira/browse/CLOUDSTACK-8570. Check if the fix is present in the build you are using.
-----Original Message-----
From: Sonali Jadhav [mailto:sonali@servercentralen.se]
Sent: Monday, 6 July 2015 13:38
To: users@cloudstack.apache.org
Subject: NPE while adding host into maintenance in ACS 4.5.1
Hi,
In order to update xenserver from 6.2 to 6.5, I added pool master in maintenance mode from ACS. In ACS it said successful , and it started to move vms to another host in cluster, except few since xenserver tool was not installed on them. So I shut those vms down from acs. But host was not sent to maintenance in xencenter. My host went to "alert" state. And now I can't do any operations since it's in alert state.
I am seeing this error in logs,
015-07-06 09:54:02,400 DEBUG [c.c.a.t.Request] (AgentTaskPool-1:ctx-a4685473) Seq 1-1601874092460343301: Received: { Ans: , MgmtId: 59778234354585, via: 1, Ver: v1, Flags: 10, { ModifyStoragePoolAnswer } }
2015-07-06 09:54:02,415 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-165:ctx-fe175294) Seq 5-8999880905346524321: Executing request
2015-07-06 09:54:02,437 INFO [o.a.c.s.d.p.DefaultHostListener] (AgentTaskPool-1:ctx-a4685473) Connection established between storage pool org.apache.cloudstack.storage.datastore.PrimaryDataStoreImpl@74be27a7 and host 1
2015-07-06 09:54:02,444 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Found storage pool PrimStore of type NetworkFilesystem with overprovisioning factor 2
2015-07-06 09:54:02,445 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Total over provisioned capacity calculated is 2 * 11579495022592
2015-07-06 09:54:02,445 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Total over provisioned capacity of the pool PrimStore id: 1 is 23158990045184
2015-07-06 09:54:02,446 DEBUG [c.c.s.StorageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Successfully set Capacity - 23158990045184 for capacity type - 3 , DataCenterId - 1, HostOrPoolId - 1, PodId 1
2015-07-06 09:54:02,446 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Connect to listener: DeploymentPlanningManagerImpl
2015-07-06 09:54:02,446 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Connect to listener: StorageCapacityListener
2015-07-06 09:54:02,447 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Connect to listener: ComputeCapacityListener
2015-07-06 09:54:02,451 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-a4685473) Found 0 VMs on host 1
2015-07-06 09:54:02,458 DEBUG [c.c.c.CapacityManagerImpl] (AgentTaskPool-1:ctx-a4685473) Found 4 VM, not running on host 1
2015-07-06 09:54:02,459 ERROR [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Monitor ComputeCapacityListener says there is an error in the connect process for 1 due to null java.lang.NullPointerException
at com.cloud.capacity.CapacityManagerImpl.updateCapacityForHost(CapacityManagerImpl.java:648)
at com.cloud.capacity.ComputeCapacityListener.processConnect(ComputeCapacityListener.java:66)
at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:539)
at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1447)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1794)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1920)
at sun.reflect.GeneratedMethodAccessor263.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.createHostAndAgent(Unknown Source)
at com.cloud.agent.manager.AgentManagerImpl$SimulateStartTask.runInContext(AgentManagerImpl.java:1078)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-07-06 09:54:02,460 INFO [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Host 1 is disconnecting with event AgentDisconnected
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) The next status of agent 1is Alert, current status is Connecting
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Deregistering link for 1 with state Alert
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Remove Agent : 1
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.DirectAgentAttache] (AgentTaskPool-1:ctx-a4685473) Processing disconnect 1(SeSolXS01)
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.hypervisor.xenserver.discoverer.XcpServerDiscoverer
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.hypervisor.hyperv.discoverer.HypervServerDiscoverer
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: org.apache.cloudstack.engine.orchestration.NetworkOrchestrator
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.hypervisor.vmware.manager.VmwareManagerImpl
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.security.SecurityGroupListener
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.vm.ClusteredVirtualMachineManagerImpl
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.secondary.SecondaryStorageListener
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.listener.StoragePoolMonitor
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.deploy.DeploymentPlanningManagerImpl
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.capacity.StorageCapacityListener
2015-07-06 09:54:02,462 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.capacity.ComputeCapacityListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.LocalStoragePoolListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.NetworkUsageManagerImpl$DirectNetworkStatsListener
2015-07-06 09:54:02,463 DEBUG [c.c.n.NetworkUsageManagerImpl] (AgentTaskPool-1:ctx-a4685473) Disconnected called on 1 with status Alert
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.router.VirtualNetworkApplianceManagerImpl
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.upload.UploadListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.storage.download.DownloadListener
2015-07-06 09:54:02,463 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.consoleproxy.ConsoleProxyListener
2015-07-06 09:54:02,464 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.SshKeysDistriMonitor
2015-07-06 09:54:02,464 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.network.router.VpcVirtualNetworkApplianceManagerImpl
2015-07-06 09:54:02,464 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Sending Disconnect to listener: com.cloud.agent.manager.AgentManagerImpl$BehindOnPingListener
2015-07-06 09:54:02,465 DEBUG [c.c.h.Status] (AgentTaskPool-1:ctx-a4685473) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 1, name = SeSolXS01]
2015-07-06 09:54:02,486 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-165:ctx-fe175294) Seq 5-8999880905346524321: Response Received:
2015-07-06 09:54:02,486 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (DirectAgent-165:ctx-fe175294) Seq 5-8999880905346524321: MgmtId 249373720971888: Resp: Routing to peer
2015-07-06 09:54:02,505 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-42:ctx-4b3b996b) Seq 6-1232297448039261404: Executing request
2015-07-06 09:54:02,507 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Notifying other nodes of to disconnect
2015-07-06 09:54:02,519 DEBUG [c.c.c.ClusterManagerImpl] (AgentTaskPool-1:ctx-a4685473) Forwarding [{"com.cloud.agent.api.ChangeAgentCommand":{"agentId":1,"event":"AgentDisconnected","contextMap":{},"wait":0}}] to 249373720971888
2015-07-06 09:54:02,520 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-3:ctx-0a51ef05) Cluster PDU 59778234354585 -> 249373720971888. agent: 1, pdu seq: 25, pdu ack seq: 0, json: [{"com.cloud.agent.api.ChangeAgentCommand":{"agentId":1,"event":"AgentDisconnected","contextMap":{},"wait":0}}]
2015-07-06 09:54:02,520 WARN [c.c.r.ResourceManagerImpl] (AgentTaskPool-1:ctx-a4685473) Unable to connect due to
com.cloud.utils.exception.CloudRuntimeException: Unable to connect 1
at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:561)
at com.cloud.agent.manager.AgentManagerImpl.handleDirectConnectAgent(AgentManagerImpl.java:1447)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1794)
at com.cloud.resource.ResourceManagerImpl.createHostAndAgent(ResourceManagerImpl.java:1920)
at sun.reflect.GeneratedMethodAccessor263.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.createHostAndAgent(Unknown Source)
at com.cloud.agent.manager.AgentManagerImpl$SimulateStartTask.runInContext(AgentManagerImpl.java:1078)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.lang.NullPointerException
at com.cloud.capacity.CapacityManagerImpl.updateCapacityForHost(CapacityManagerImpl.java:648)
at com.cloud.capacity.ComputeCapacityListener.processConnect(ComputeCapacityListener.java:66)
at com.cloud.agent.manager.AgentManagerImpl.notifyMonitorsOfConnection(AgentManagerImpl.java:539)
... 22 more
2015-07-06 09:54:02,522 DEBUG [c.c.h.Status] (AgentTaskPool-1:ctx-a4685473) Transition:[Resource state = Enabled, Agent event = AgentDisconnected, Host id = 1, name = SeSolXS01]
2015-07-06 09:54:02,523 DEBUG [c.c.c.ClusterServiceServletImpl] (Cluster-Worker-3:ctx-0a51ef05) POST http://secure-web.cisco.com/1X7Zx_tVBp5zkXnhtf7v8RCPEQEVEsCFOQSFwQyocn8nUTksj4DwmCCPBsV8a5mG3gbmJMuMhsKacEuS1du4t4i5GobdHtgTq67qdDuBAXsJy83xynT3YB99lhxZtmeQH5HRYf0VQtb-kbqjmEcIGacVMcuDCNb-Mc3vGRlmiayTizV5K0UQpHoNTOvV4OFKB/http%3A%2F%2F172.16.5.190%3A9090%2Fclusterservice response :true, responding time: 3 ms
2015-07-06 09:54:02,523 DEBUG [c.c.c.ClusterManagerImpl] (Cluster-Worker-3:ctx-0a51ef05) Cluster PDU 59778234354585 -> 249373720971888 completed. time: 3ms. agent: 1, pdu seq: 25, pdu ack seq: 0, json: [{"com.cloud.agent.api.ChangeAgentCommand":{"agentId":1,"event":"AgentDisconnected","contextMap":{},"wait":0}}]
2015-07-06 09:54:02,561 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgent-42:ctx-4b3b996b) Seq 6-1232297448039261404: Response Received:
2015-07-06 09:54:02,561 DEBUG [c.c.a.m.ClusteredAgentManagerImpl] (DirectAgent-42:ctx-4b3b996b) Seq 6-1232297448039261404: MgmtId 249373720971888: Resp: Routing to peer
2015-07-06 09:54:02,572 DEBUG [c.c.a.m.AgentManagerImpl] (AgentTaskPool-1:ctx-a4685473) Completed creating agent for host 1
2015-07-06 09:54:02,722 DEBUG [c.c.a.m.DirectAgentAttache] (DirectAgentCronJob-236:ctx-79815165) Seq 5-6790865288121286660: Executing request
I tried to give maintenance cmd again but failed,
2015-07-06 09:40:01,441 DEBUG [c.c.a.m.AgentManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786 ctx-c88bc8f8) Can not send command com.cloud.agent.api.MaintainCommand due to Host 1 is not up
2015-07-06 09:40:01,441 WARN [c.c.r.ResourceManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786 ctx-c88bc8f8) Unable to send MaintainCommand to host: 1
2015-07-06 09:40:01,441 ERROR [c.c.a.ApiAsyncJobDispatcher] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Unexpected exception while executing org.apache.cloudstack.api.command.admin.host.PrepareForMaintenanceCmd
com.cloud.utils.exception.CloudRuntimeException: Unable to prepare for maintenance host 1
at com.cloud.resource.ResourceManagerImpl.maintain(ResourceManagerImpl.java:1251)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
at com.sun.proxy.$Proxy149.maintain(Unknown Source)
at org.apache.cloudstack.api.command.admin.host.PrepareForMaintenanceCmd.execute(PrepareForMaintenanceCmd.java:102)
at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:141)
at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:537)
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:494)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
2015-07-06 09:40:01,443 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Complete async job-3786, jobStatus: FAILED, resultCode: 530, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":530,"errortext":"Unable to prepare for maintenance host 1"}
2015-07-06 09:40:01,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Publish async job-3786 complete on message bus
2015-07-06 09:40:01,445 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-38:ctx-9c1f1f6b job-3786) Wake up jobs related to job-3786
/sonali