[ 
https://issues.apache.org/jira/browse/QPID-8274?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Alex Rudyy updated QPID-8274:
-----------------------------
    Environment: 
[Broker-Config] (q.m.b.platform) - [Broker] BRK-1010 : Platform : JVM : Oracle 
Corporation version: 1.8.0_161-b12 OS : Linux version: 
3.10.0-514.6.1.el7.x86_64 arch: amd64 cores: 40


> [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: Bug
>          Components: Broker-J
>    Affects Versions: qpid-java-6.1.6, qpid-java-broker-7.0.3, 
> qpid-java-broker-7.0.2, qpid-java-6.0, qpid-java-6.0.1, qpid-java-6.0.2, 
> qpid-java-6.0.3, qpid-java-6.0.4, qpid-java-6.0.5, qpid-java-6.1, 
> qpid-java-6.0.6, qpid-java-6.1.1, qpid-java-6.1.2, qpid-java-6.0.7, 
> qpid-java-6.1.3, qpid-java-6.0.8, qpid-java-6.1.4, qpid-java-broker-7.0.0, 
> qpid-java-6.1.5, qpid-java-broker-7.0.1, qpid-java-6.1.7, 
> qpid-java-broker-7.1.0, qpid-java-broker-7.0.4, qpid-java-broker-7.0.5, 
> qpid-java-broker-7.0.6
>         Environment: [Broker-Config] (q.m.b.platform) - [Broker] BRK-1010 : 
> Platform : JVM : Oracle Corporation version: 1.8.0_161-b12 OS : Linux 
> version: 3.10.0-514.6.1.el7.x86_64 arch: amd64 cores: 40
>            Reporter: Alex Rudyy
>            Priority: Major
>             Fix For: qpid-java-broker-7.0.7, qpid-java-broker-7.1.1
>
>         Attachments: thread-dump.txt
>
>
> 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 
> (transition 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. 
> The broker state does not change and remains to be UNINITIALIZED. As result, 
> some operations on Broker might fail due to underlying objects not being 
> created or broker state not being ACTIVE. 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-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org

Reply via email to