Uploaded image for project: 'netconf'
  1. netconf
  2. NETCONF-582

become-prefix-leader can run into Futures timed out after [5000 milliseconds]

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Cannot Reproduce
    • Icon: Medium Medium
    • None
    • Oxygen
    • restconf-nb
    • None
    • Operating System: All
      Platform: All

    • 8604

      This has been seen only in Sandbox [0] so far, so it might be related to CONTROLLER-1703. This happened in a test case where the leader is moving away from the member with transaction producer, but not in the other two cases.

      The corresponding karaf.log [1] segment is between 06:39:53,057 and 06:40:26,075

      Copy of the Restconf response is below.
      It seems PrefixLeaderHandler.makeLeaderLocal is calling createProducer, but its response ProducerCreated is not delivered.
      It is not clear whether the reason is slow election, or something else.

      <h2>HTTP ERROR 500</h2>
      <p>Problem accessing /restconf/operations/odl-mdsal-lowlevel-control:become-prefix-leader. Reason:
      <pre> Server Error</pre></p><h3>Caused by:</h3><pre>org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.cluster.sharding.messages.ProducerCreated to actor Actorakka://opendaylight-cluster-data/user/ShardedDOMDataTreeFrontend#476358683 failed. Try again later.
      at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeOperation(ActorContext.java:318)
      at org.opendaylight.controller.cluster.sharding.DistributedShardedDOMDataTree.createProducer(DistributedShardedDOMDataTree.java:305)
      at Proxyf6a29036_2c37_4cbb_8a31_448722858c49.createProducer(Unknown Source)
      at Proxy4bd2f29d_cae8_4f00_85e6_ff95bec0a8ea.createProducer(Unknown Source)
      at org.opendaylight.controller.clustering.it.provider.impl.PrefixLeaderHandler.makeLeaderLocal(PrefixLeaderHandler.java:48)
      at org.opendaylight.controller.clustering.it.provider.MdsalLowLevelTestProvider.becomePrefixLeader(MdsalLowLevelTestProvider.java:293)
      at org.opendaylight.yangtools.yang.binding.util.RpcMethodInvokerWithInput.invokeOn(RpcMethodInvokerWithInput.java:31)
      at org.opendaylight.yangtools.yang.binding.util.AbstractMappedRpcInvoker.invokeRpc(AbstractMappedRpcInvoker.java:52)
      at org.opendaylight.controller.md.sal.binding.impl.BindingDOMRpcImplementationAdapter.invoke(BindingDOMRpcImplementationAdapter.java:83)
      at org.opendaylight.controller.md.sal.binding.impl.BindingDOMRpcImplementationAdapter.invokeRpc(BindingDOMRpcImplementationAdapter.java:70)
      at org.opendaylight.controller.md.sal.dom.broker.impl.GlobalDOMRpcRoutingTableEntry.invokeRpc(GlobalDOMRpcRoutingTableEntry.java:39)
      at org.opendaylight.controller.md.sal.dom.broker.impl.DOMRpcRoutingTable.invokeRpc(DOMRpcRoutingTable.java:177)
      at org.opendaylight.controller.md.sal.dom.broker.impl.DOMRpcRouter.invokeRpc(DOMRpcRouter.java:102)
      at Proxy17715c5f_8020_47e9_bf35_f61c2e28595c.invokeRpc(Unknown Source)
      at org.opendaylight.netconf.sal.restconf.impl.BrokerFacade.invokeRpc(BrokerFacade.java:508)
      at org.opendaylight.netconf.sal.restconf.impl.RestconfImpl.invokeRpc(RestconfImpl.java:467)
      at org.opendaylight.netconf.sal.restconf.impl.StatisticsRestconfServiceWrapper.invokeRpc(StatisticsRestconfServiceWrapper.java:83)
      at org.opendaylight.netconf.sal.rest.impl.RestconfCompositeWrapper.invokeRpc(RestconfCompositeWrapper.java:64)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      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$CachedChain.doFilter(ServletHandler.java:1507)
      at org.eclipse.jetty.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:247)
      at org.eclipse.jetty.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:210)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:82)
      at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:256)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.opendaylight.aaa.filterchain.filters.CustomFilterAdapter.doFilter(CustomFilterAdapter.java:83)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:499)
      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:427)
      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:75)
      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.content(AbstractHttpConnection.java:984)
      at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1045)
      at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:861)
      at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:236)
      at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
      at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:696)
      at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:53)
      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: java.util.concurrent.TimeoutException: Futures timed out after [5000 milliseconds]
      at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:223)
      at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:227)
      at scala.concurrent.Await$$anonfun$result$1.apply(package.scala:190)
      at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:53)
      at scala.concurrent.Await$.result(package.scala:190)
      at scala.concurrent.Await.result(package.scala)
      at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeOperation(ActorContext.java:315)
      ... 74 more
      </pre>
      <h3>Caused by:</h3><pre>java.util.concurrent.TimeoutException: Futures timed out after [5000 milliseconds]
      at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:223)
      at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:227)
      at scala.concurrent.Await$$anonfun$result$1.apply(package.scala:190)
      at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:53)
      at scala.concurrent.Await$.result(package.scala:190)
      at scala.concurrent.Await.result(package.scala)
      at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeOperation(ActorContext.java:315)
      at org.opendaylight.controller.cluster.sharding.DistributedShardedDOMDataTree.createProducer(DistributedShardedDOMDataTree.java:305)
      at Proxyf6a29036_2c37_4cbb_8a31_448722858c49.createProducer(Unknown Source)
      at Proxy4bd2f29d_cae8_4f00_85e6_ff95bec0a8ea.createProducer(Unknown Source)
      at org.opendaylight.controller.clustering.it.provider.impl.PrefixLeaderHandler.makeLeaderLocal(PrefixLeaderHandler.java:48)
      at org.opendaylight.controller.clustering.it.provider.MdsalLowLevelTestProvider.becomePrefixLeader(MdsalLowLevelTestProvider.java:293)
      at org.opendaylight.yangtools.yang.binding.util.RpcMethodInvokerWithInput.invokeOn(RpcMethodInvokerWithInput.java:31)
      at org.opendaylight.yangtools.yang.binding.util.AbstractMappedRpcInvoker.invokeRpc(AbstractMappedRpcInvoker.java:52)
      at org.opendaylight.controller.md.sal.binding.impl.BindingDOMRpcImplementationAdapter.invoke(BindingDOMRpcImplementationAdapter.java:83)
      at org.opendaylight.controller.md.sal.binding.impl.BindingDOMRpcImplementationAdapter.invokeRpc(BindingDOMRpcImplementationAdapter.java:70)
      at org.opendaylight.controller.md.sal.dom.broker.impl.GlobalDOMRpcRoutingTableEntry.invokeRpc(GlobalDOMRpcRoutingTableEntry.java:39)
      at org.opendaylight.controller.md.sal.dom.broker.impl.DOMRpcRoutingTable.invokeRpc(DOMRpcRoutingTable.java:177)
      at org.opendaylight.controller.md.sal.dom.broker.impl.DOMRpcRouter.invokeRpc(DOMRpcRouter.java:102)
      at Proxy17715c5f_8020_47e9_bf35_f61c2e28595c.invokeRpc(Unknown Source)
      at org.opendaylight.netconf.sal.restconf.impl.BrokerFacade.invokeRpc(BrokerFacade.java:508)
      at org.opendaylight.netconf.sal.restconf.impl.RestconfImpl.invokeRpc(RestconfImpl.java:467)
      at org.opendaylight.netconf.sal.restconf.impl.StatisticsRestconfServiceWrapper.invokeRpc(StatisticsRestconfServiceWrapper.java:83)
      at org.opendaylight.netconf.sal.rest.impl.RestconfCompositeWrapper.invokeRpc(RestconfCompositeWrapper.java:64)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      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$CachedChain.doFilter(ServletHandler.java:1507)
      at org.eclipse.jetty.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:247)
      at org.eclipse.jetty.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:210)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:82)
      at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:256)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.opendaylight.aaa.filterchain.filters.CustomFilterAdapter.doFilter(CustomFilterAdapter.java:83)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.apache.shiro.web.servlet.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:118)
      at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1478)
      at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:499)
      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:427)
      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:75)
      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.content(AbstractHttpConnection.java:984)
      at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1045)
      at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:861)
      at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:236)
      at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
      at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:696)
      at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:53)
      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)
      </pre>

      [0] https://logs.opendaylight.org/sandbox/jenkins091/controller-csit-3node-clustering-only-carbon/4/log.html.gz#s1-s8-t1-k2-k6-k3-k1-k4-k7-k1
      [1] https://logs.opendaylight.org/sandbox/jenkins091/controller-csit-3node-clustering-only-carbon/4/odl2_karaf.log.gz

            ivanm1996 Ivan Martiniak
            vrpolak Vratko Polak
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: