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 <[email protected]> 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 <[email protected] > >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? > > > > > > > > > > > > > > >
