[CONTROLLER-799] Clustering : Exception seen at clustering startup in karaf distribution Created: 10/Sep/14  Updated: 28/Oct/14  Resolved: 28/Oct/14

Status: Resolved
Project: controller
Component/s: mdsal
Affects Version/s: Helium
Fix Version/s: None

Type: Bug
Reporter: Jan Medved Assignee: Harman Singh
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: Mac OS
Platform: PC


Issue Links:
Blocks
is blocked by CONTROLLER-704 Clustering : Running a basic mininet ... Resolved
External issue ID: 1780
Priority: Low

 Description   

The following exception is seen when clustering is started up (after being installed).

Exception in thread "pool-37-thread-4" org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.cluster.datastore.messages.RegisterChangeListener to actor Actorakka://opendaylight-cluster-data/user/shardmanager-config/member-1-shard-inventory-config#-2143120719 failed
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeLocalOperation(ActorContext.java:166)
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeLocalShardOperation(ActorContext.java:254)
at org.opendaylight.controller.cluster.datastore.DistributedDataStore.registerChangeListener(DistributedDataStore.java:85)
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataBrokerImpl.registerDataChangeListener(DOMDataBrokerImpl.java:84)
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataBrokerImpl.registerDataChangeListener(DOMDataBrokerImpl.java:36)
at org.opendaylight.controller.sal.dom.broker.osgi.DOMDataBrokerProxy.registerDataChangeListener(DOMDataBrokerProxy.java:40)
at org.opendaylight.controller.sal.dom.broker.osgi.DOMDataBrokerProxy.registerDataChangeListener(DOMDataBrokerProxy.java:15)
at org.opendaylight.controller.md.sal.binding.impl.AbstractForwardedDataBroker.registerDataChangeListener(AbstractForwardedDataBroker.java:81)
at org.opendaylight.controller.md.sal.binding.impl.ForwardedBackwardsCompatibleDataBroker.registerDataChangeListener(ForwardedBackwardsCompatibleDataBroker.java:116)
at org.opendaylight.controller.md.sal.binding.util.AbstractBindingSalConsumerInstance.registerDataChangeListener(AbstractBindingSalConsumerInstance.java:105)
at org.opendaylight.controller.md.statistics.manager.StatisticsProvider.start(StatisticsProvider.java:100)
at org.opendaylight.controller.md.statistics.manager.StatisticsManagerActivator.onSessionInitiated(StatisticsManagerActivator.java:26)
at org.opendaylight.controller.md.sal.binding.util.BindingContextUtils.createProviderContextAndInitialize(BindingContextUtils.java:57)
at org.opendaylight.controller.sal.binding.impl.RootBindingAwareBroker.registerProvider(RootBindingAwareBroker.java:146)
at org.opendaylight.controller.sal.binding.api.AbstractBindingAwareProvider.onBrokerAvailable(AbstractBindingAwareProvider.java:22)
at org.opendaylight.controller.sal.binding.api.AbstractBrokerAwareActivator$1$1.run(AbstractBrokerAwareActivator.java:34)
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:745)
Caused by: java.util.concurrent.TimeoutException: Futures timed out after [5 seconds]
at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:219)
at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:223)
at scala.concurrent.Await$$anonfun$result$1.apply(package.scala:107)
at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:53)
at scala.concurrent.Await$.result(package.scala:107)
at scala.concurrent.Await.result(package.scala)
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeLocalOperation(ActorContext.java:164)



 Comments   
Comment by Jan Medved [ 10/Sep/14 ]

And the following exceptions are being seen when the controller exits:Exception in thread "pool-37-thread-4" org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.cluster.datastore.messages.RegisterChangeListener to actor Actorakka://opendaylight-cluster-data/user/shardmanager-config/member-1-shard-inventory-config#-2143120719 failed
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeLocalOperation(ActorContext.java:166)
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeLocalShardOperation(ActorContext.java:254)
at org.opendaylight.controller.cluster.datastore.DistributedDataStore.registerChangeListener(DistributedDataStore.java:85)
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataBrokerImpl.registerDataChangeListener(DOMDataBrokerImpl.java:84)
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataBrokerImpl.registerDataChangeListener(DOMDataBrokerImpl.java:36)
at org.opendaylight.controller.sal.dom.broker.osgi.DOMDataBrokerProxy.registerDataChangeListener(DOMDataBrokerProxy.java:40)
at org.opendaylight.controller.sal.dom.broker.osgi.DOMDataBrokerProxy.registerDataChangeListener(DOMDataBrokerProxy.java:15)
at org.opendaylight.controller.md.sal.binding.impl.AbstractForwardedDataBroker.registerDataChangeListener(AbstractForwardedDataBroker.java:81)
at org.opendaylight.controller.md.sal.binding.impl.ForwardedBackwardsCompatibleDataBroker.registerDataChangeListener(ForwardedBackwardsCompatibleDataBroker.java:116)
at org.opendaylight.controller.md.sal.binding.util.AbstractBindingSalConsumerInstance.registerDataChangeListener(AbstractBindingSalConsumerInstance.java:105)
at org.opendaylight.controller.md.statistics.manager.StatisticsProvider.start(StatisticsProvider.java:100)
at org.opendaylight.controller.md.statistics.manager.StatisticsManagerActivator.onSessionInitiated(StatisticsManagerActivator.java:26)
at org.opendaylight.controller.md.sal.binding.util.BindingContextUtils.createProviderContextAndInitialize(BindingContextUtils.java:57)
at org.opendaylight.controller.sal.binding.impl.RootBindingAwareBroker.registerProvider(RootBindingAwareBroker.java:146)
at org.opendaylight.controller.sal.binding.api.AbstractBindingAwareProvider.onBrokerAvailable(AbstractBindingAwareProvider.java:22)
at org.opendaylight.controller.sal.binding.api.AbstractBrokerAwareActivator$1$1.run(AbstractBrokerAwareActivator.java:34)
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:745)
Caused by: java.util.concurrent.TimeoutException: Futures timed out after [5 seconds]
at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:219)
at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:223)
at scala.concurrent.Await$$anonfun$result$1.apply(package.scala:107)
at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:53)
at scala.concurrent.Await$.result(package.scala:107)
at scala.concurrent.Await.result(package.scala)
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeLocalOperation(ActorContext.java:164)

Comment by Jan Medved [ 10/Sep/14 ]

Trying to get the inventory nodes via Restconf from config space results in the following error:

errors: [error-type: application, error-tag: operation-failed, error-message: Problem to get data from transaction.error-info: ReadFailedException

{message=Error reading data for path /(urn:opendaylight:inventory?revision=2013-08-19)nodes, errorList=[RpcError [message=Error reading data for path /(urn:opendaylight:inventory?revision=2013-08-19)nodes, severity=ERROR, errorType=APPLICATION, tag=operation-failed, applicationTag=null, info=null, cause=org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.protobuff.messages.transaction.ShardTransactionMessages$CreateTransaction to actor ActorSelection[Anchor(akka://opendaylight-cluster-data/), Path(/user/shardmanager-config/member-1-shard-inventory-config)] failed]]}

at org.opendaylight.controller.cluster.datastore.TransactionProxy$NoOpTransactionContext.readData(TransactionProxy.java:762) at org.opendaylight.controller.cluster.datastore.TransactionProxy.read(TransactionProxy.java:232) at org.opendaylight.controller.md.sal.dom.broker.impl.DOMForwardedReadOnlyTransaction.read(DOMForwardedReadOnlyTransaction.java:40) at org.opendaylight.controller.sal.restconf.impl.BrokerFacade.readDataViaTransaction(BrokerFacade.java:181) at org.opendaylight.controller.sal.restconf.impl.BrokerFacade.readConfigurationData(BrokerFacade.java:77) at org.opendaylight.controller.sal.restconf.impl.RestconfImpl.readConfigurationData(RestconfImpl.java:631) at org.opendaylight.controller.sal.restconf.impl.StatisticsRestconfServiceWrapper.readConfigurationData(StatisticsRestconfServiceWrapper.java:84) 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 com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185) at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302) at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) at com.sun.jersey.server.impl.uri.rules.ResourceObjectRule.accept(ResourceObjectRule.java:100) at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1511) at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1442) at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1391) at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1381) at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416) at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:538) at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:716) at javax.servlet.http.HttpServlet.service(HttpServlet.java:668) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:684) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:501) at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:69) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086) at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:240) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:428) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135) at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:77) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) at org.eclipse.jetty.server.Server.handle(Server.java:370) at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:494) at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:971) at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1033) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:644) at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82) at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:667) at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) at java.lang.Thread.run(Thread.java:745) Caused by: org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.protobuff.messages.transaction.ShardTransactionMessages$CreateTransaction to actor ActorSelection[Anchor(akka://opendaylight-cluster-data/), Path(/user/shardmanager-config/member-1-shard-inventory-config)] failed at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeRemoteOperation(ActorContext.java:186) at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeShardOperation(ActorContext.java:232) at org.opendaylight.controller.cluster.datastore.TransactionProxy.createTransactionIfMissing(TransactionProxy.java:355) at org.opendaylight.controller.cluster.datastore.TransactionProxy.read(TransactionProxy.java:230) ... 51 more Caused by: akka.pattern.AskTimeoutException: Ask timed out on [ActorSelection[Anchor(akka://opendaylight-cluster-data/), Path(/user/shardmanager-config/member-1-shard-inventory-config)]] after [5000 ms] at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:333) at akka.actor.Scheduler$$anon$7.run(Scheduler.scala:117) at scala.concurrent.Future$InternalCallbackExecutor$.scala$concurrent$Future$InternalCallbackExecutor$$unbatchedExecute(Future.scala:694) at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:691) at akka.actor.LightArrayRevolverScheduler$TaskHolder.executeTask(Scheduler.scala:467) at akka.actor.LightArrayRevolverScheduler$$anon$8.executeBucket$1(Scheduler.scala:419) at akka.actor.LightArrayRevolverScheduler$$anon$8.nextTick(Scheduler.scala:423) at akka.actor.LightArrayRevolverScheduler$$anon$8.run(Scheduler.scala:375) ... 1 more , ]]

Comment by Moiz Raja [ 16/Sep/14 ]

The RegisterDataChangeListener exception and the CreateTransaction exceptions both happen because the Shard is not ready for business. On startup this typically happens because the Shard is recovering.

Comment by Naresh kumar [ 21/Oct/14 ]

Hi Medved,
I didn't get any exception while running controller in cluster.
I followed this link to enable clustering,
https://wiki.opendaylight.org/view/Running_and_testing_an_OpenDaylight_Cluster
I downloaded helium binary from this link,
http://www.opendaylight.org/software/downloads
Is there is anyother steps to run the cluster? Am I having the right controller? Where am I missing?

Comment by Tom Pantelis [ 28/Oct/14 ]

The exceptions on startup due to the shard not ready have been alleviated with recent patches. The registerChangeListener and createTransaction operations now wait a period of time for the shard to recover and for shard leader election to complete. The exceptions were most likely caused by shard persistence recovery taking a long time. Recovery time has also been improved since.

I think we can close this bug.

Comment by Moiz Raja [ 28/Oct/14 ]

Not reproducible any more

Generated at Wed Feb 07 19:53:54 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.