[QPID-8070] [Broker-J][JDBC Store] Instantiate asynchronous commits executor on open of JDBC message store

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: qpid-java-6.1.4, qpid-java-6.1.5
• Fix Version/s: qpid-java-6.1.6, qpid-java-broker-7.0.1
• Component/s: Broker-J
• Assignee: Alex Rudyy
• Reporter: Rabih Mourad
• Created: 05/Jan/18 17:01
• Updated: 02/Oct/19 19:20
• Resolved: 16/Jan/18 17:48

Description

Hello,

We are using Qpid java broker version 6.1.4.

Our test case:
We have a JMS client sending messages continuously in autoAck mode to a messaging cluster. The cluster is composed of 1 dispatch router and 2 java brokers which are connected to an Oracle Db.
At some point, the test kills a broker using kill -9 and then attempts to restart it.
Randomly, we have a NullPointerException while the broker is restarting and connecting to the virtual host node (the full error stack is at the end of the email).

Do you have any idea why this is happening? is there a chance that a kill
-9 on a broker leaves the Db in an unstable state?

Best regards,
Rabih

2018-01-03 17:16:45,930 INFO [VirtualHostNode-default-Config]
(q.m.t.recovery_start) - [Broker]
[vh(/default)/ms(GenericJDBCMessageStore)] TXN-1004 : Recovery Start
2018-01-03 17:16:45,938 WARN [VirtualHostNode-default-Config]
(o.a.q.s.v.SynchronousMessageStoreRecoverer) - Message id 1 in log references queue with id 0b2a06aa-6d46-49aa-885f-63f3cd73108d which is not in the configuration, entry will be discarded
2018-01-03 17:16:45,946 ERROR [VirtualHostNode-default-Config]
(o.a.q.s.m.AbstractConfiguredObject) - Failed to open object with name 'default'. Object will be put into ERROR state.
java.lang.NullPointerException: null
at
org.apache.qpid.server.store.AbstractJDBCMessageStore.commitTranAsync(AbstractJDBCMessageStore.java:826)
at
org.apache.qpid.server.store.AbstractJDBCMessageStore.access$600(AbstractJDBCMessageStore.java:59)
at
org.apache.qpid.server.store.AbstractJDBCMessageStore$JDBCTransaction.commitTranAsync(AbstractJDBCMessageStore.java:1205)
at
org.apache.qpid.server.store.jdbc.GenericAbstractJDBCMessageStore$RecordedJDBCTransaction.commitTranAsync(GenericAbstractJDBCMessageStore.java:142)
at
org.apache.qpid.server.virtualhost.SynchronousMessageStoreRecoverer$MessageInstanceVisitor.handle(SynchronousMessageStoreRecoverer.java:219)
at
org.apache.qpid.server.store.AbstractJDBCMessageStore$JDBCMessageStoreReader.visitMessageInstances(AbstractJDBCMessageStore.java:1911)
at
org.apache.qpid.server.virtualhost.SynchronousMessageStoreRecoverer.recover(SynchronousMessageStoreRecoverer.java:82)
at
org.apache.qpid.server.virtualhost.AbstractVirtualHost.postCreateDefaultExchangeTasks(AbstractVirtualHost.java:2581)
at
org.apache.qpid.server.virtualhost.AbstractVirtualHost.onActivate(AbstractVirtualHost.java:2563)
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:1482)
at
org.apache.qpid.server.model.AbstractConfiguredObject.attainState(AbstractConfiguredObject.java:1461)
at
org.apache.qpid.server.model.AbstractConfiguredObject$8.onSuccess(AbstractConfiguredObject.java:1035)
at
org.apache.qpid.server.model.AbstractConfiguredObject$8.onSuccess(AbstractConfiguredObject.java:1029)
at
org.apache.qpid.server.model.AbstractConfiguredObject$22$1.run(AbstractConfiguredObject.java:2609)
at
org.apache.qpid.server.model.AbstractConfiguredObject$22$1.run(AbstractConfiguredObject.java:2605)
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:2604)
at
com.google.common.util.concurrent.Futures$6.run(Futures.java:1319)
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl$ImmediateIfSameThreadExecutor.execute(TaskExecutorImpl.java:404)
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl.execute(TaskExecutorImpl.java:187)
at
com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156)
at
com.google.common.util.concurrent.ExecutionList.add(ExecutionList.java:101)
at
com.google.common.util.concurrent.AbstractFuture.addListener(AbstractFuture.java:170)
at
com.google.common.util.concurrent.Futures.addCallback(Futures.java:1322)
at
org.apache.qpid.server.model.AbstractConfiguredObject.addFutureCallback(AbstractConfiguredObject.java:2599)
at
org.apache.qpid.server.model.AbstractConfiguredObject.doAttainState(AbstractConfiguredObject.java:1028)
at
org.apache.qpid.server.model.AbstractConfiguredObject.access$300(AbstractConfiguredObject.java:91)
at
org.apache.qpid.server.model.AbstractConfiguredObject$1.execute(AbstractConfiguredObject.java:584)
at
org.apache.qpid.server.model.AbstractConfiguredObject$1.execute(AbstractConfiguredObject.java:571)
at
org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:632)
at
org.apache.qpid.server.model.AbstractConfiguredObject$2.execute(AbstractConfiguredObject.java:625)
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl$TaskLoggingWrapper.execute(TaskExecutorImpl.java:252)
at
org.apache.qpid.server.configuration.updater.TaskExecutorImpl$CallableWrapper$1.run(TaskExecutorImpl.java:324)
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:317)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)