[ https://issues.apache.org/jira/browse/QPID-8274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16768808#comment-16768808 ]
Alex Rudyy commented on QPID-8274: ---------------------------------- Whilst creation of environment for a replica node hang on loading of class {{TupleBinding}} on attempt to , a creation of another non-HA virtual host hang at the same time on invocation of BDB JE method {{IntegerBinding.entryToInt(key)}}. Here is the stack trace: {noformat} at org.apache.qpid.server.store.berkeleydb.upgrade.Upgrader.getSourceVersion(Upgrader.java:119) at org.apache.qpid.server.store.berkeleydb.upgrade.Upgrader.upgradeIfNecessary(Upgrader.java:81) at org.apache.qpid.server.store.berkeleydb.StandardEnvironmentFacade.upgradeIfNecessary(StandardEnvironmentFacade.java:413) at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.upgradeStoreStructure(AbstractBDBMessageStore.java:113) at org.apache.qpid.server.virtualhost.AbstractVirtualHost.onActivate(AbstractVirtualHost.java:2588) 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 org.apache.qpid.server.bytebuffer.QpidByteBufferFactory$$Lambda$3/1748876332.run(Unknown Source) at java.lang.Thread.run(Thread.java:748) {noformat} What is interesting that creation BDB JE HA environment hang on invocation of static initializer where an instance of {{IntegerBining}} was put into the {{HashMap}}: {code} addPrimitive(Integer.class, Integer.TYPE, new IntegerBinding()); {code} It looks like a weird class loading issue... > [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 > Reporter: Alex Rudyy > Priority: Major > Fix For: qpid-java-broker-7.0.7, qpid-java-broker-7.1.1 > > > 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