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
