cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Carlos Reategui <car...@reategui.com>
Subject Re: Management Server won't connect after cluster shutdown and restart
Date Fri, 29 Aug 2014 19:54:38 GMT
Hi Ian,

So the root of the problem was that the machines where not started up in
the correct order.

My plan had been to stop all VMs from CS, then stop CS, then shutdown the
VM hosts.  On the other end the hosts needed to be brought up first and
once they are ok then bring up the CS machine and make sure everything was
in the same state it thought things were when it was shutdown.
 Unfortunately CS came up before everything else was the way it expected it
to be and I did not realize that at the time.

To resolve I went back to my CS db backup from right after I shut it down
the MS, made sure the VM hosts were all as expected and then started the
MS.






On Fri, Aug 29, 2014 at 8:02 AM, Ian Duffy <ian@ianduffy.ie> wrote:

> Hi carlos,
>
> Did you ever find a fix for this?
>
> I'm seeing a same issue on 4.1.1 with Vmware ESXi.
>
>
> On 29 October 2013 04:54, Carlos Reategui <creategui@gmail.com> wrote:
>
> > Update.  I cleared out the async_job table and also reset the system vms
> it
> > thought where in starting mode from my previous attempts by setting them
> to
> > Stopped from starting.  I also re-set the XS pool master to be the one XS
> > thinks it is.
> >
> > Now when I start the CS MS here are the logs leading up to the first
> > exception about the Unable to reach the pool:
> >
> > 2013-10-28 21:27:11,040 DEBUG [cloud.alert.ClusterAlertAdapter]
> > (Cluster-Notification-1:null) Management server node 172.30.45.2 is up,
> > send alert
> >
> > 2013-10-28 21:27:11,045 WARN  [cloud.cluster.ClusterManagerImpl]
> > (Cluster-Notification-1:null) Notifying management server join event
> took 9
> > ms
> >
> > 2013-10-28 21:27:23,236 DEBUG [cloud.server.StatsCollector]
> > (StatsCollector-2:null) HostStatsCollector is running...
> >
> > 2013-10-28 21:27:23,243 DEBUG [cloud.server.StatsCollector]
> > (StatsCollector-3:null) VmStatsCollector is running...
> >
> > 2013-10-28 21:27:23,247 DEBUG [cloud.server.StatsCollector]
> > (StatsCollector-1:null) StorageCollector is running...
> >
> > 2013-10-28 21:27:23,255 DEBUG [cloud.server.StatsCollector]
> > (StatsCollector-1:null) There is no secondary storage VM for secondary
> > storage host nfs://172.30.45.2/store/secondary
> >
> > 2013-10-28 21:27:23,273 DEBUG [agent.manager.ClusteredAgentAttache]
> > (StatsCollector-2:null) Seq 1-201916421: Forwarding null to
> 233845174730255
> >
> > 2013-10-28 21:27:23,274 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-9:null) Seq 1-201916421: Routing from
> 233845174730253
> >
> > 2013-10-28 21:27:23,275 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-9:null) Seq 1-201916421: Link is closed
> >
> > 2013-10-28 21:27:23,275 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-9:null) Seq 1-201916421: MgmtId 233845174730253:
> Req:
> > Resource [Host:1] is unreachable: Host 1: Link is c
> >
> > losed
> >
> > 2013-10-28 21:27:23,275 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-9:null) Seq 1--1: MgmtId 233845174730253: Req:
> > Routing to peer
> >
> > 2013-10-28 21:27:23,277 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-11:null) Seq 1--1: MgmtId 233845174730253: Req:
> > Cancel request received
> >
> > 2013-10-28 21:27:23,277 DEBUG [agent.manager.AgentAttache]
> > (AgentManager-Handler-11:null) Seq 1-201916421: Cancelling.
> >
> > 2013-10-28 21:27:23,277 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 1-201916421: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,277 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 1-201916421: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,277 INFO  [utils.exception.CSExceptionErrorCode]
> > (StatsCollector-2:null) Could not find exception:
> > com.cloud.exception.OperationTimedoutException in error code list for
> > exceptions
> >
> > 2013-10-28 21:27:23,277 WARN  [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 1-201916421: Timed out on null
> >
> > 2013-10-28 21:27:23,278 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 1-201916421: Cancelling.
> >
> > 2013-10-28 21:27:23,278 WARN  [agent.manager.AgentManagerImpl]
> > (StatsCollector-2:null) Operation timed out: Commands 201916421 to Host 1
> > timed out after 3600
> >
> > 2013-10-28 21:27:23,278 WARN  [cloud.resource.ResourceManagerImpl]
> > (StatsCollector-2:null) Unable to obtain host 1 statistics.
> >
> > 2013-10-28 21:27:23,278 WARN  [cloud.server.StatsCollector]
> > (StatsCollector-2:null) Received invalid host stats for host: 1
> >
> > 2013-10-28 21:27:23,281 DEBUG [agent.manager.ClusteredAgentAttache]
> > (StatsCollector-1:null) Seq 1-201916422: Forwarding null to
> 233845174730255
> >
> > 2013-10-28 21:27:23,283 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-12:null) Seq 1-201916422: Routing from
> > 233845174730253
> >
> > 2013-10-28 21:27:23,283 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-12:null) Seq 1-201916422: Link is closed
> >
> > 2013-10-28 21:27:23,283 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-12:null) Seq 1-201916422: MgmtId 233845174730253:
> > Req: Resource [Host:1] is unreachable: Host 1: Link is
> >
> > closed
> >
> > 2013-10-28 21:27:23,284 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-12:null) Seq 1--1: MgmtId 233845174730253: Req:
> > Routing to peer
> >
> > 2013-10-28 21:27:23,286 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-13:null) Seq 1--1: MgmtId 233845174730253: Req:
> > Cancel request received
> >
> > 2013-10-28 21:27:23,286 DEBUG [agent.manager.AgentAttache]
> > (AgentManager-Handler-13:null) Seq 1-201916422: Cancelling.
> >
> > 2013-10-28 21:27:23,286 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 1-201916422: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,286 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 1-201916422: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,286 INFO  [utils.exception.CSExceptionErrorCode]
> > (StatsCollector-1:null) Could not find exception:
> > com.cloud.exception.OperationTimedoutException in error code list for
> > exceptions
> >
> > 2013-10-28 21:27:23,286 WARN  [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 1-201916422: Timed out on null
> >
> > 2013-10-28 21:27:23,286 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 1-201916422: Cancelling.
> >
> > 2013-10-28 21:27:23,288 DEBUG [cloud.storage.StorageManagerImpl]
> > (StatsCollector-1:null) Unable to send storage pool command to
> > Pool[200|LVM] via 1
> >
> > com.cloud.exception.OperationTimedoutException: Commands 201916422 to
> Host
> > 1 timed out after 3600
> >
> >         at
> com.cloud.agent.manager.AgentAttache.send(AgentAttache.java:429)
> >
> >         at
> > com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:511)
> >
> >         at
> > com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:464)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2347)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:422)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:436)
> >
> >         at
> >
> >
> com.cloud.server.StatsCollector$StorageCollector.run(StatsCollector.java:316)
> >
> >         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:1146)
> >
> >         at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> >
> >         at java.lang.Thread.run(Thread.java:679)
> >
> > 2013-10-28 21:27:23,289 INFO  [cloud.server.StatsCollector]
> > (StatsCollector-1:null) Unable to reach Pool[200|LVM]
> >
> > com.cloud.exception.StorageUnavailableException: Resource
> [StoragePool:200]
> > is unreachable: Unable to send command to the pool
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2357)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:422)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:436)
> >
> >         at
> >
> >
> com.cloud.server.StatsCollector$StorageCollector.run(StatsCollector.java:316)
> >
> >         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:1146)
> >
> >         at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> >
> >         at java.lang.Thread.run(Thread.java:679)
> >
> > 2013-10-28 21:27:23,300 DEBUG [agent.manager.ClusteredAgentAttache]
> > (StatsCollector-2:null) Seq 2-1168703496: Forwarding null to
> > 233845174730255
> >
> > 2013-10-28 21:27:23,301 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-14:null) Seq 2-1168703496: Routing from
> > 233845174730253
> >
> > 2013-10-28 21:27:23,301 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-14:null) Seq 2-1168703496: Link is closed
> >
> > 2013-10-28 21:27:23,302 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-14:null) Seq 2-1168703496: MgmtId 233845174730253:
> > Req: Resource [Host:2] is unreachable: Host 2: Link is closed
> >
> > 2013-10-28 21:27:23,302 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-14:null) Seq 2--1: MgmtId 233845174730253: Req:
> > Routing to peer
> >
> > 2013-10-28 21:27:23,303 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-15:null) Seq 2--1: MgmtId 233845174730253: Req:
> > Cancel request received
> >
> > 2013-10-28 21:27:23,303 DEBUG [agent.manager.AgentAttache]
> > (AgentManager-Handler-15:null) Seq 2-1168703496: Cancelling.
> >
> > 2013-10-28 21:27:23,303 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 2-1168703496: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,304 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 2-1168703496: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,304 INFO  [utils.exception.CSExceptionErrorCode]
> > (StatsCollector-2:null) Could not find exception:
> > com.cloud.exception.OperationTimedoutException in error code list for
> > exceptions
> >
> > 2013-10-28 21:27:23,304 WARN  [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 2-1168703496: Timed out on null
> >
> > 2013-10-28 21:27:23,304 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-2:null) Seq 2-1168703496: Cancelling.
> >
> > 2013-10-28 21:27:23,304 WARN  [agent.manager.AgentManagerImpl]
> > (StatsCollector-2:null) Operation timed out: Commands 1168703496 to Host
> 2
> > timed out after 3600
> >
> > 2013-10-28 21:27:23,304 WARN  [cloud.resource.ResourceManagerImpl]
> > (StatsCollector-2:null) Unable to obtain host 2 statistics.
> >
> > 2013-10-28 21:27:23,304 WARN  [cloud.server.StatsCollector]
> > (StatsCollector-2:null) Received invalid host stats for host: 2
> >
> > 2013-10-28 21:27:23,307 DEBUG [agent.manager.ClusteredAgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703497: Forwarding null to
> > 233845174730255
> >
> > 2013-10-28 21:27:23,308 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-1:null) Seq 2-1168703497: Routing from
> > 233845174730253
> >
> > 2013-10-28 21:27:23,308 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-1:null) Seq 2-1168703497: Link is closed
> >
> > 2013-10-28 21:27:23,308 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-1:null) Seq 2-1168703497: MgmtId 233845174730253:
> > Req: Resource [Host:2] is unreachable: Host 2: Link is closed
> >
> > 2013-10-28 21:27:23,308 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-1:null) Seq 2--1: MgmtId 233845174730253: Req:
> > Routing to peer
> >
> > 2013-10-28 21:27:23,310 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-5:null) Seq 2--1: MgmtId 233845174730253: Req:
> Cancel
> > request received
> >
> > 2013-10-28 21:27:23,310 DEBUG [agent.manager.AgentAttache]
> > (AgentManager-Handler-5:null) Seq 2-1168703497: Cancelling.
> >
> > 2013-10-28 21:27:23,310 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703497: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,310 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703497: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,310 INFO  [utils.exception.CSExceptionErrorCode]
> > (StatsCollector-1:null) Could not find exception:
> > com.cloud.exception.OperationTimedoutException in error code list for
> > exceptions
> >
> > 2013-10-28 21:27:23,310 WARN  [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703497: Timed out on null
> >
> > 2013-10-28 21:27:23,310 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703497: Cancelling.
> >
> > 2013-10-28 21:27:23,310 DEBUG [cloud.storage.StorageManagerImpl]
> > (StatsCollector-1:null) Unable to send storage pool command to
> > Pool[201|LVM] via 2
> >
> > com.cloud.exception.OperationTimedoutException: Commands 1168703497 to
> Host
> > 2 timed out after 3600
> >
> >         at
> com.cloud.agent.manager.AgentAttache.send(AgentAttache.java:429)
> >
> >         at
> > com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:511)
> >
> >         at
> > com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:464)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2347)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:422)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:436)
> >
> >         at
> >
> >
> com.cloud.server.StatsCollector$StorageCollector.run(StatsCollector.java:316)
> >
> >         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:1146)
> >
> >         at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> >
> >         at java.lang.Thread.run(Thread.java:679)
> >
> > 2013-10-28 21:27:23,311 INFO  [cloud.server.StatsCollector]
> > (StatsCollector-1:null) Unable to reach Pool[201|LVM]
> >
> > com.cloud.exception.StorageUnavailableException: Resource
> [StoragePool:201]
> > is unreachable: Unable to send command to the pool
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2357)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:422)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:436)
> >
> >         at
> >
> >
> com.cloud.server.StatsCollector$StorageCollector.run(StatsCollector.java:316)
> >
> >         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:1146)
> >
> >         at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> >
> >         at java.lang.Thread.run(Thread.java:679)
> >
> > 2013-10-28 21:27:23,328 DEBUG [agent.manager.ClusteredAgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703498: Forwarding null to
> > 233845174730255
> >
> > 2013-10-28 21:27:23,329 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-3:null) Seq 2-1168703498: Routing from
> > 233845174730253
> >
> > 2013-10-28 21:27:23,329 DEBUG [agent.manager.ClusteredAgentAttache]
> > (AgentManager-Handler-3:null) Seq 2-1168703498: Link is closed
> >
> > 2013-10-28 21:27:23,329 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-3:null) Seq 2-1168703498: MgmtId 233845174730253:
> > Req: Resource [Host:2] is unreachable: Host 2: Link is closed
> >
> > 2013-10-28 21:27:23,330 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-3:null) Seq 2--1: MgmtId 233845174730253: Req:
> > Routing to peer
> >
> > 2013-10-28 21:27:23,331 DEBUG [agent.manager.ClusteredAgentManagerImpl]
> > (AgentManager-Handler-4:null) Seq 2--1: MgmtId 233845174730253: Req:
> Cancel
> > request received
> >
> > 2013-10-28 21:27:23,331 DEBUG [agent.manager.AgentAttache]
> > (AgentManager-Handler-4:null) Seq 2-1168703498: Cancelling.
> >
> > 2013-10-28 21:27:23,331 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703498: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,331 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703498: Waiting some more time because
> > this is the current command
> >
> > 2013-10-28 21:27:23,331 INFO  [utils.exception.CSExceptionErrorCode]
> > (StatsCollector-1:null) Could not find exception:
> > com.cloud.exception.OperationTimedoutException in error code list for
> > exceptions
> >
> > 2013-10-28 21:27:23,332 WARN  [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703498: Timed out on null
> >
> > 2013-10-28 21:27:23,332 DEBUG [agent.manager.AgentAttache]
> > (StatsCollector-1:null) Seq 2-1168703498: Cancelling.
> >
> > 2013-10-28 21:27:23,332 DEBUG [cloud.storage.StorageManagerImpl]
> > (StatsCollector-1:null) Unable to send storage pool command to
> > Pool[202|NetworkFilesystem] via 2
> >
> > com.cloud.exception.OperationTimedoutException: Commands 1168703498 to
> Host
> > 2 timed out after 3600
> >
> >         at
> com.cloud.agent.manager.AgentAttache.send(AgentAttache.java:429)
> >
> >         at
> > com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:511)
> >
> >         at
> > com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:464)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2347)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:422)
> >
> >         at
> >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:436)
> >
> >         at
> >
> >
> com.cloud.server.StatsCollector$StorageCollector.run(StatsCollector.java:316)
> >
> >         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:1146)
> >
> >         at
> >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> >
> >         at java.lang.Thread.run(Thread.java:679)
> >
> > IP tables is disable on the XS hosts so the connection prob is not a
> > firewall issue.
> >
> > If I do an xe se-list I see all 3 of the above SRs and the hosts have
> > mounted the NFS SR and can access it.
> >
> >
> >
> >
> > On Mon, Oct 28, 2013 at 9:05 PM, Carlos Reategui <carlos@reategui.com
> > >wrote:
> >
> > > Using CS 4.1.1 with 2 hosts running XS 6.0.2
> > >
> > > Had to shut everything down and now I am having problems bringing
> things
> > > up.
> > >
> > > As suggested I used CS to stop all my instances as well as the system
> VMs
> > > and the SR. Then I shutdown the XS 6.02 servers after enabling
> > maintenance
> > > mode from the CS console.
> > >
> > > After bringing things up, my XS servers had the infamous
> interface-rename
> > > issue which I resolved by editing the udev rules file manually.
> > >
> > > Now I have my XS servers up but for some reason my pool master got
> > changed
> > > so I used xe pool-designate-new-master to switch it back.
> > >
> > > I did not notice that this designation change had been picked up by CS
> > and
> > > when starting it up it keeps trying to connect to the wrong pool
> master.
> > >  Should I switch XS to match CS or what do I need to change in CS to
> tell
> > > it what the pool master is?
> > >
> > > I tried putting the server that CS thinks is the master in maintenance
> > > mode from CS but that just ends up in an apparent infinite cycle
> spitting
> > > out endless lines like these:
> > >
> > > 2013-10-28 20:39:02,059 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-1:null) Seq 2-855048230: Forwarding Seq
> > 2-855048230:
> > > { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flags
> > >
> > > : 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > 2013-10-28 20:39:02,060 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-11:null) Seq 2-855048230: Forwarding Seq
> > > 2-855048230:  { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flag
> > >
> > > s: 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > 2013-10-28 20:39:02,062 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-13:null) Seq 2-855048230: Forwarding Seq
> > > 2-855048230:  { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flag
> > >
> > > s: 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > 2013-10-28 20:39:02,063 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-7:null) Seq 2-855048230: Forwarding Seq
> > 2-855048230:
> > > { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flags
> > >
> > > : 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > 2013-10-28 20:39:02,064 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-15:null) Seq 2-855048230: Forwarding Seq
> > > 2-855048230:  { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flag
> > >
> > > s: 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > 2013-10-28 20:39:02,066 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-14:null) Seq 2-855048230: Forwarding Seq
> > > 2-855048230:  { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flag
> > >
> > > s: 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > 2013-10-28 20:39:02,067 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-2:null) Seq 2-855048230: Forwarding Seq
> > 2-855048230:
> > > { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flags
> > >
> > > : 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > 2013-10-28 20:39:02,068 DEBUG [agent.manager.ClusteredAgentAttache]
> > > (AgentManager-Handler-12:null) Seq 2-855048230: Forwarding Seq
> > > 2-855048230:  { Cmd , MgmtId: 233845174730253, via: 2, Ver: v1, Flag
> > >
> > > s: 100111, [{"MaintainCommand":{"wait":0}}] } to 233845174730255
> > >
> > > After stopping and restarting the MS, the first error I see is:
> > >
> > > 2013-10-28 20:41:53,749 DEBUG [cloud.api.ApiServlet]
> > > (catalina-exec-1:null) ===START===  10.110.3.70 -- GET
> > >
> >
> command=queryAsyncJobResult&jobId=d695b8ba-53b5-4e22-8e97-54e5ed236f88&response=json&sessi
> > >
> > > onkey=r4nsNGoidS8enQWHRKbV2AUNeac%3D&_=1383018110624
> > >
> > > 2013-10-28 20:41:53,756 ERROR [cloud.api.ApiServlet]
> > > (catalina-exec-1:null) unknown exception writing api response
> > >
> > > java.lang.NullPointerException
> > >
> > >         at
> > >
> >
> com.cloud.user.AccountManagerImpl.getSystemUser(AccountManagerImpl.java:280)
> > >
> > >         at
> > >
> >
> com.cloud.user.AccountManagerImpl.getSystemUser(AccountManagerImpl.java:143)
> > >
> > >         at com.cloud.api.ApiServlet.processRequest(ApiServlet.java:238)
> > >
> > >         at com.cloud.api.ApiServlet.doGet(ApiServlet.java:66)
> > >
> > >         at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
> > >
> > >         at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> > >
> > >         at
> > >
> >
> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> > >
> > >         at
> > >
> >
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> > >
> > >         at
> > >
> >
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
> > >
> > >         at
> > >
> >
> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
> > >
> > >         at
> > >
> >
> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
> > >
> > >         at
> > >
> >
> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
> > >
> > >         at
> > >
> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
> > >
> > >         at
> > >
> >
> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
> > >
> > >         at
> > >
> >
> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
> > >
> > >         at
> > >
> >
> org.apache.coyote.http11.Http11NioProcessor.process(Http11NioProcessor.java:889)
> > >
> > >         at
> > >
> >
> org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:744)
> > >
> > >         at
> > >
> >
> org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:2282)
> > >
> > >         at
> > >
> >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> > >
> > >         at
> > >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> > >
> > >         at java.lang.Thread.run(Thread.java:679)
> > >
> > > 2013-10-28 20:41:53,761 DEBUG [cloud.api.ApiServlet]
> > > (catalina-exec-1:null) ===END===  10.110.3.70 -- GET
> > >
> >
> command=queryAsyncJobResult&jobId=d695b8ba-53b5-4e22-8e97-54e5ed236f88&response=json&session
> > >
> > > key=r4nsNGoidS8enQWHRKbV2AUNeac%3D&_=1383018110624
> > >
> > > Then I see a few of these:
> > >
> > > 2013-10-28 20:42:01,464 WARN  [agent.manager.ClusteredAgentManagerImpl]
> > > (HA-Worker-4:work-10) Unable to connect to peer management server:
> > > 233845174730255, ip: 172.30.45.2 due to Connection refused
> > >
> > > java.net.ConnectException: Connection refused
> > >
> > >         at sun.nio.ch.Net.connect(Native Method)
> > >
> > >         at
> > sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:530)
> > >
> > >         at java.nio.channels.SocketChannel.open(SocketChannel.java:164)
> > >
> > >         at
> > >
> >
> com.cloud.agent.manager.ClusteredAgentManagerImpl.connectToPeer(ClusteredAgentManagerImpl.java:477)
> > >
> > >         at
> > >
> >
> com.cloud.agent.manager.ClusteredAgentAttache.send(ClusteredAgentAttache.java:172)
> > >
> > >         at
> > com.cloud.agent.manager.AgentAttache.send(AgentAttache.java:388)
> > >
> > >         at
> > >
> com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:511)
> > >
> > >         at
> > >
> com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:464)
> > >
> > >         at
> > >
> >
> com.cloud.ha.CheckOnAgentInvestigator.isVmAlive(CheckOnAgentInvestigator.java:53)
> > >
> > >         at
> > >
> >
> com.cloud.ha.HighAvailabilityManagerImpl.restart(HighAvailabilityManagerImpl.java:434)
> > >
> > >         at
> > >
> >
> com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:829)
> > >
> > > 2013-10-28 20:42:01,468 WARN  [agent.manager.ClusteredAgentManagerImpl]
> > > (HA-Worker-2:work-11) Unable to connect to peer management server:
> > > 233845174730255, ip: 172.30.45.2 due to Connection refused
> > >
> > > java.net.ConnectException: Connection refused
> > >
> > >         at sun.nio.ch.Net.connect(Native Method)
> > >
> > >         at
> > sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:530)
> > >
> > >         at java.nio.channels.SocketChannel.open(SocketChannel.java:164)
> > >
> > >         at
> > >
> >
> com.cloud.agent.manager.ClusteredAgentManagerImpl.connectToPeer(ClusteredAgentManagerImpl.java:477)
> > >
> > >         at
> > >
> >
> com.cloud.agent.manager.ClusteredAgentAttache.send(ClusteredAgentAttache.java:172)
> > >
> > >         at
> > com.cloud.agent.manager.AgentAttache.send(AgentAttache.java:388)
> > >
> > >         at
> > >
> com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:511)
> > >
> > >         at
> > >
> com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:464)
> > >
> > >         at
> > >
> >
> com.cloud.ha.CheckOnAgentInvestigator.isVmAlive(CheckOnAgentInvestigator.java:53)
> > >
> > >         at
> > >
> >
> com.cloud.ha.HighAvailabilityManagerImpl.restart(HighAvailabilityManagerImpl.java:434)
> > >
> > >         at
> > >
> >
> com.cloud.ha.HighAvailabilityManagerImpl$WorkerThread.run(HighAvailabilityManagerImpl.java:829)
> > >
> > >
> > > The next error is:
> > >
> > > 2013-10-28 20:42:01,845 WARN  [utils.nio.Task]
> > > (AgentManager-Handler-6:null) Caught the following exception but
> pushing
> > on
> > >
> > > java.lang.NullPointerException
> > >
> > >         at
> > >
> >
> com.google.gson.FieldAttributes.getAnnotationFromArray(FieldAttributes.java:231)
> > >
> > >         at
> > > com.google.gson.FieldAttributes.getAnnotation(FieldAttributes.java:150)
> > >
> > >         at
> > >
> >
> com.google.gson.VersionExclusionStrategy.shouldSkipField(VersionExclusionStrategy.java:38)
> > >
> > >         at
> > >
> >
> com.google.gson.DisjunctionExclusionStrategy.shouldSkipField(DisjunctionExclusionStrategy.java:38)
> > >
> > >         at
> > >
> >
> com.google.gson.ReflectingFieldNavigator.visitFieldsReflectively(ReflectingFieldNavigator.java:58)
> > >
> > >         at
> > com.google.gson.ObjectNavigator.accept(ObjectNavigator.java:120)
> > >
> > >         at
> > >
> >
> com.google.gson.JsonSerializationContextDefault.serialize(JsonSerializationContextDefault.java:62)
> > >
> > >         at
> > >
> >
> com.google.gson.JsonSerializationContextDefault.serialize(JsonSerializationContextDefault.java:53)
> > >
> > >         at com.google.gson.Gson.toJsonTree(Gson.java:220)
> > >
> > >         at com.google.gson.Gson.toJsonTree(Gson.java:197)
> > >
> > >         at
> > >
> >
> com.cloud.agent.transport.ArrayTypeAdaptor.serialize(ArrayTypeAdaptor.java:56)
> > >
> > >         at
> > >
> >
> com.cloud.agent.transport.ArrayTypeAdaptor.serialize(ArrayTypeAdaptor.java:37)
> > >
> > >         at
> > >
> >
> com.google.gson.JsonSerializationVisitor.findAndInvokeCustomSerializer(JsonSerializationVisitor.java:184)
> > >
> > >         at
> > >
> >
> com.google.gson.JsonSerializationVisitor.visitUsingCustomHandler(JsonSerializationVisitor.java:160)
> > >
> > >         at
> > com.google.gson.ObjectNavigator.accept(ObjectNavigator.java:101)
> > >
> > >         at
> > >
> >
> com.google.gson.JsonSerializationContextDefault.serialize(JsonSerializationContextDefault.java:62)
> > >
> > >         at
> > >
> >
> com.google.gson.JsonSerializationContextDefault.serialize(JsonSerializationContextDefault.java:53)
> > >
> > >         at com.google.gson.Gson.toJsonTree(Gson.java:220)
> > >
> > >         at com.google.gson.Gson.toJson(Gson.java:260)
> > >
> > >         at com.cloud.agent.transport.Request.toBytes(Request.java:316)
> > >
> > >         at com.cloud.agent.transport.Request.getBytes(Request.java:332)
> > >
> > >         at
> > >
> >
> com.cloud.agent.manager.ClusteredAgentManagerImpl.cancel(ClusteredAgentManagerImpl.java:435)
> > >
> > >         at
> > >
> >
> com.cloud.agent.manager.ClusteredAgentManagerImpl$ClusteredAgentHandler.doTask(ClusteredAgentManagerImpl.java:641)
> > >
> > >         at com.cloud.utils.nio.Task.run(Task.java:83)
> > >
> > >         at
> > >
> >
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
> > >
> > >         at
> > >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> > >
> > >         at java.lang.Thread.run(Thread.java:679)
> > >
> > > and then the next set of errors I see over and over are:
> > >
> > > 2013-10-28 20:42:16,433 DEBUG [cloud.storage.StorageManagerImpl]
> > > (StatsCollector-2:null) Unable to send storage pool command to
> > > Pool[200|LVM] via 1
> > >
> > > com.cloud.exception.OperationTimedoutException: Commands 1112277002 to
> > > Host 1 timed out after 3600
> > >
> > >         at
> > com.cloud.agent.manager.AgentAttache.send(AgentAttache.java:429)
> > >
> > >         at
> > >
> com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:511)
> > >
> > >         at
> > >
> com.cloud.agent.manager.AgentManagerImpl.send(AgentManagerImpl.java:464)
> > >
> > >         at
> > >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2347)
> > >
> > >         at
> > >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:422)
> > >
> > >         at
> > >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:436)
> > >
> > >         at
> > >
> >
> com.cloud.server.StatsCollector$StorageCollector.run(StatsCollector.java:316)
> > >
> > >         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:1146)
> > >
> > >         at
> > >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> > >
> > >         at java.lang.Thread.run(Thread.java:679)
> > >
> > > 2013-10-28 20:42:16,434 INFO  [cloud.server.StatsCollector]
> > > (StatsCollector-2:null) Unable to reach Pool[200|LVM]
> > >
> > > com.cloud.exception.StorageUnavailableException: Resource
> > > [StoragePool:200] is unreachable: Unable to send command to the pool
> > >
> > >         at
> > >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:2357)
> > >
> > >         at
> > >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:422)
> > >
> > >         at
> > >
> >
> com.cloud.storage.StorageManagerImpl.sendToPool(StorageManagerImpl.java:436)
> > >
> > >         at
> > >
> >
> com.cloud.server.StatsCollector$StorageCollector.run(StatsCollector.java:316)
> > >
> > >         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:1146)
> > >
> > >         at
> > >
> >
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
> > >
> > >         at java.lang.Thread.run(Thread.java:679)
> > >
> > > I have tried to force reconnect to both hosts but that ends up maxing
> out
> > > a CPU core and filling up the log file with endless log lines.
> > >
> > > Any thoughts on how to recover my system?
> > >
> > >
> > >
> > >
> > >
> > >
> > >
> >
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message