Uploaded image for project: 'Qpid'
  1. Qpid
  2. QPID-8252

[Broker-J][BDB HA] Start-up of BDB HA Virtual Host Node can hang sporadically

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Duplicate
    • Affects Version/s: qpid-java-broker-7.0.3, qpid-java-broker-7.0.2, qpid-java-broker-7.0.0, 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
    • Component/s: Broker-J
    • Labels:
      None

      Description

      Start-up of BDB HA Virtual Host Node can hang sporadically with issuing the following entries into broker logs:

      2018-08-24 19:02:16,249 WARN  [Broker-Config] (o.a.q.s.s.b.r.ReplicatedEnvironmentFacade) - Slow replicated environment creation for tdome_prod:qpid1_B. Will continue to wait for further 135000ms. for environment creation to complete.
      2018-08-24 19:04:31,265 ERROR [Broker-Config] (o.a.q.s.m.AbstractConfiguredObject) - Failed to open object with name 'qpid1_B'.  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)
      

      Subsequent bounce solves the problem.

        Attachments

        1. qpid-broker.log.txt
          27 kB
          Alex Rudyy

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                orudyy Alex Rudyy
              • Votes:
                0 Vote for this issue
                Watchers:
                1 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: