You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Alex Rudyy (JIRA)" <ji...@apache.org> on 2019/01/21 14:39:00 UTC
[jira] [Created] (QPID-8274) [Broker-J][BDB HA] Broker can fail to
become active when BDB HA virtual host times out to join the group
Alex Rudyy created QPID-8274:
--------------------------------
Summary: [Broker-J][BDB HA] Broker can fail to become active when BDB HA virtual host times out to join the group
Key: QPID-8274
URL: https://issues.apache.org/jira/browse/QPID-8274
Project: Qpid
Issue Type: Task
Components: Broker-J
Affects Versions: qpid-java-broker-7.0.6, qpid-java-6.1.7
Reporter: Alex Rudyy
Fix For: qpid-java-broker-7.0.7
Broker containing a BDB HA Virtual Host node (belonging to the cluster consisting of several nodes) can fail to start when BDB HA Virtual Host node times out to join the group. The broker cannot complete activation and transit into an ACTIVE state.
The stack traces like bellow are reported on BDB HA VHN timeout:
{noformat}
ERROR [Broker-Config] (o.a.q.s.m.AbstractConfiguredObject) - Failed to open object with name 'node2'. Object will be put into ERROR state.
java.lang.RuntimeException: JE replicated environment creation took too long (permitted time 180000ms)
at org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.createEnvironmentInSeparateThread(ReplicatedEnvironmentFacade.java:1577)
at org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.createEnvironment(ReplicatedEnvironmentFacade.java:1521)
at org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.<init>(ReplicatedEnvironmentFacade.java:287)
at org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacadeFactory.createEnvironmentFacade(ReplicatedEnvironmentFacadeFactory.java:130)
at org.apache.qpid.server.store.berkeleydb.BDBConfigurationStore.init(BDBConfigurationStore.java:122)
at org.apache.qpid.server.virtualhostnode.berkeleydb.BDBHAVirtualHostNodeImpl.activate(BDBHAVirtualHostNodeImpl.java:338)
at org.apache.qpid.server.virtualhostnode.AbstractVirtualHostNode.doActivate(AbstractVirtualHostNode.java:162)
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 org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1524)
at org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1503)
at org.apache.qpid.server.model.AbstractConfiguredObject$8.onSuccess(AbstractConfiguredObject.java:1070)
at org.apache.qpid.server.model.AbstractConfiguredObject$8.onSuccess(AbstractConfiguredObject.java:1064)
at org.apache.qpid.server.model.AbstractConfiguredObject$22$1.run(AbstractConfiguredObject.java:2639)
at org.apache.qpid.server.model.AbstractConfiguredObject$22$1.run(AbstractConfiguredObject.java:2635)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:360)
at org.apache.qpid.server.model.AbstractConfiguredObject$22.onSuccess(AbstractConfiguredObject.java:2634)
at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1237)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$ImmediateIfSameThreadExecutor.execute(TaskExecutorImpl.java:400)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.execute(TaskExecutorImpl.java:183)
at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:911)
at com.google.common.util.concurrent.AbstractFuture.addListener(AbstractFuture.java:645)
at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.addListener(AbstractFuture.java:101)
at com.google.common.util.concurrent.Futures.addCallback(Futures.java:1209)
at org.apache.qpid.server.model.AbstractConfiguredObject.addFutureCallback(AbstractConfiguredObject.java:2629)
at org.apache.qpid.server.model.AbstractConfiguredObject.doAttainState(AbstractConfiguredObject.java:1063)
at org.apache.qpid.server.model.AbstractConfiguredObject.access$600(AbstractConfiguredObject.java:95)
at org.apache.qpid.server.model.AbstractConfiguredObject$7.performAction(AbstractConfiguredObject.java:1048)
at org.apache.qpid.server.model.AbstractConfiguredObject$7.performAction(AbstractConfiguredObject.java:1038)
at org.apache.qpid.server.model.AbstractConfiguredObject.applyToChildren(AbstractConfiguredObject.java:1311)
at org.apache.qpid.server.model.AbstractConfiguredObject.doAttainState(AbstractConfiguredObject.java:1037)
at org.apache.qpid.server.model.AbstractConfiguredObject.access$600(AbstractConfiguredObject.java:95)
at org.apache.qpid.server.model.AbstractConfiguredObject$1.execute(AbstractConfiguredObject.java:589)
at org.apache.qpid.server.model.AbstractConfiguredObject$1.execute(AbstractConfiguredObject.java:576)
at org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:637)
at org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:630)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$TaskLoggingWrapper.execute(TaskExecutorImpl.java:248)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.submitWrappedTask(TaskExecutorImpl.java:165)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.submit(TaskExecutorImpl.java:153)
at org.apache.qpid.server.model.AbstractConfiguredObject.doOnConfigThread(AbstractConfiguredObject.java:629)
at org.apache.qpid.server.model.AbstractConfiguredObject.openAsync(AbstractConfiguredObject.java:575)
at org.apache.qpid.server.model.AbstractSystemConfig.makeActive(AbstractSystemConfig.java:304)
at org.apache.qpid.server.model.AbstractSystemConfig.activate(AbstractSystemConfig.java:280)
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 org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1524)
at org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1503)
at org.apache.qpid.server.model.AbstractConfiguredObject$8.onSuccess(AbstractConfiguredObject.java:1070)
at org.apache.qpid.server.model.AbstractConfiguredObject$8.onSuccess(AbstractConfiguredObject.java:1064)
at org.apache.qpid.server.model.AbstractConfiguredObject$22$1.run(AbstractConfiguredObject.java:2639)
at org.apache.qpid.server.model.AbstractConfiguredObject$22$1.run(AbstractConfiguredObject.java:2635)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:360)
at org.apache.qpid.server.model.AbstractConfiguredObject$22.onSuccess(AbstractConfiguredObject.java:2634)
at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1237)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$ImmediateIfSameThreadExecutor.execute(TaskExecutorImpl.java:400)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl.execute(TaskExecutorImpl.java:183)
at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:911)
at com.google.common.util.concurrent.AbstractFuture.addListener(AbstractFuture.java:645)
at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.addListener(AbstractFuture.java:101)
at com.google.common.util.concurrent.Futures.addCallback(Futures.java:1209)
at org.apache.qpid.server.model.AbstractConfiguredObject.addFutureCallback(AbstractConfiguredObject.java:2629)
at org.apache.qpid.server.model.AbstractConfiguredObject.doAttainState(AbstractConfiguredObject.java:1063)
at org.apache.qpid.server.model.AbstractConfiguredObject.access$600(AbstractConfiguredObject.java:95)
at org.apache.qpid.server.model.AbstractConfiguredObject$1.execute(AbstractConfiguredObject.java:589)
at org.apache.qpid.server.model.AbstractConfiguredObject$1.execute(AbstractConfiguredObject.java:576)
at org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:637)
at org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:630)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$TaskLoggingWrapper.execute(TaskExecutorImpl.java:248)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper$1.run(TaskExecutorImpl.java:320)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:360)
at org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper.call(TaskExecutorImpl.java:313)
at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:111)
at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:58)
at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:75)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
at java.lang.Thread.run(Thread.java:748)
{noformat}
The VHN configuration store is closed
{noformat}
2019-01-14 03:21:29,882 INFO [Broker-Config] (q.m.c.close) - [Broker] [vh(/group)/ms(BDBConfigurationStore)] CFG-1003 : Closed
{noformat}
The VHN transits into ERRORed state but broker activation does not finish. As result, some operations on Broker might fail due to underlying objects not being created. For example, user management login can fail with NPE as below:
{noformat}
ERROR [qtp2099124276-161] (o.a.q.s.m.p.f.ExceptionHandlingFilter) - Unexpected exception in servlet '/service/sasl':
java.lang.NullPointerException: null
at org.apache.qpid.server.model.AbstractContainer.scheduleTask(AbstractContainer.java:490)
at org.apache.qpid.server.management.plugin.HttpManagementUtil.scheduleAbsoluteSessionTimeout(HttpManagementUtil.java:179)
at org.apache.qpid.server.management.plugin.HttpManagementUtil.saveAuthorisedSubject(HttpManagementUtil.java:171)
at org.apache.qpid.server.management.plugin.servlet.rest.SaslServlet.evaluateSaslResponse(SaslServlet.java:254)
at org.apache.qpid.server.management.plugin.servlet.rest.SaslServlet.doPost(SaslServlet.java:179)
at org.apache.qpid.server.management.plugin.servlet.rest.AbstractServlet.doPost(AbstractServlet.java:146)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:841)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1634)
at org.apache.qpid.server.management.plugin.filter.AuthenticationCheckFilter$1.run(AuthenticationCheckFilter.java:157)
at org.apache.qpid.server.management.plugin.filter.AuthenticationCheckFilter$1.run(AuthenticationCheckFilter.java:153)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at org.apache.qpid.server.management.plugin.filter.AuthenticationCheckFilter.doFilterChainAs(AuthenticationCheckFilter.java:152)
at org.apache.qpid.server.management.plugin.filter.AuthenticationCheckFilter.doFilter(AuthenticationCheckFilter.java:122)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
at org.apache.qpid.server.management.plugin.filter.LoggingFilter.doFilter(LoggingFilter.java:63)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
at org.apache.qpid.server.management.plugin.filter.ForbiddingTraceFilter.doFilter(ForbiddingTraceFilter.java:65)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
at org.eclipse.jetty.servlets.CrossOriginFilter.handle(CrossOriginFilter.java:308)
at org.eclipse.jetty.servlets.CrossOriginFilter.doFilter(CrossOriginFilter.java:262)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
at org.apache.qpid.server.management.plugin.filter.ExceptionHandlingFilter.doFilter(ExceptionHandlingFilter.java:59)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1621)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:541)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1593)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1239)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:481)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1562)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1141)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.eclipse.jetty.server.Server.handle(Server.java:564)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:258)
at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:147)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:672)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:590)
at org.apache.qpid.server.bytebuffer.QpidByteBufferFactory.lambda$null$0(QpidByteBufferFactory.java:464)
at java.lang.Thread.run(Thread.java:748)
{noformat}
It is unclear why BDB JE node fails to join the group in timely manner, but, the Broker activation should not be affected by BDB JE node failures: the broker should transit either into ACTIVE or ERRORED state (with JVM exit for the latter).
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org