[jboss-user] [JBoss Messaging] - Unique-Constraint »jbm_msg_pkey« exceptions in a clustered

mzeijen do-not-reply at jboss.com
Wed Jun 10 03:36:29 EDT 2009 

Yesterday I put a new system in production that uses a JBoss Messaging cluster. This is the first time that I put a JBoss Messaging cluster in production and now I am running into some exceptions that I am worry about. These messages didn't result in message loss until know but I don't know if it could result to message loss in the future.

First the platform description:

ESB Servers (2 nodes):
Windows
JBoss ESB server 4.5.GA (using JBoss 4.2.3.GA)
JBoss Messaging 1.4.2.GA-SP1

Database:
Postgres 8.3.6

First I get these warnings at one of the nodes:

  | 2009-06-10 09:21:11,712 WARN  [org.jboss.messaging.core.impl.JDBCSupport] SQLException caught, SQLState 23505 code:0- assuming deadlock detected, try:1
  | org.postgresql.util.PSQLException: FEHLER: doppelter Schlüsselwert verletzt Unique-Constraint »jbm_msg_pkey«
  | 	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:1592)
  | 	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1327)
  | 	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:192)
  | 	at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:451)
  | 	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:350)
  | 	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:304)
  | 	at org.jboss.resource.adapter.jdbc.CachedPreparedStatement.executeUpdate(CachedPreparedStatement.java:95)
  | 	at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:365)
  | 	at org.jboss.messaging.core.impl.JDBCPersistenceManager$1HandleBeforePrepareRunner.doTransaction(JDBCPersistenceManager.java:1992)
  | 	at org.jboss.messaging.core.impl.JDBCSupport$JDBCTxRunner2.execute(JDBCSupport.java:474)
  | 	at org.jboss.messaging.core.impl.JDBCSupport$JDBCTxRunner2.executeWithRetry(JDBCSupport.java:512)
  | 	at org.jboss.messaging.core.impl.JDBCPersistenceManager.handleBeforePrepare(JDBCPersistenceManager.java:2063)
  | 	at org.jboss.messaging.core.impl.JDBCPersistenceManager$TransactionCallback.beforePrepare(JDBCPersistenceManager.java:2984)
  | 	at org.jboss.messaging.core.impl.tx.Transaction.prepare(Transaction.java:265)
  | 	at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:498)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$sendTransaction$aop(ConnectionAdvised.java:101)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeNext(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.server.container.SecurityAspect.handleSendTransaction(SecurityAspect.java:195)
  | 	at sun.reflect.GeneratedMethodAccessor198.invoke(Unknown Source)
  | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
  | 	at java.lang.reflect.Method.invoke(Method.java:585)
  | 	at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:121)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeNext(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeNext(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.sendTransaction(ConnectionAdvised.java)
  | 	at org.jboss.jms.wireformat.ConnectionSendTransactionRequest.serverInvoke(ConnectionSendTransactionRequest.java:82)
  | 	at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
  | 	at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:866)
  | 	at org.jboss.remoting.transport.local.LocalClientInvoker.invoke(LocalClientInvoker.java:101)
  | 	at org.jboss.remoting.Client.invoke(Client.java:1634)
  | 	at org.jboss.remoting.Client.invoke(Client.java:548)
  | 	at org.jboss.remoting.Client.invoke(Client.java:536)
  | 	at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
  | 	at org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:160)
  | 	at org.jboss.jms.client.delegate.ClientConnectionDelegate.org$jboss$jms$client$delegate$ClientConnectionDelegate$sendTransaction$aop(ClientConnectionDelegate.java:221)
  | 	at org.jboss.jms.client.delegate.ClientConnectionDelegate$sendTransaction_N3268650789275322226.invokeNext(ClientConnectionDelegate$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
  | 	at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
  | 	at org.jboss.jms.client.delegate.ClientConnectionDelegate$sendTransaction_N3268650789275322226.invokeNext(ClientConnectionDelegate$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
  | 	at org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
  | 	at org.jboss.jms.client.delegate.ClientConnectionDelegate$sendTransaction_N3268650789275322226.invokeNext(ClientConnectionDelegate$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.client.delegate.ClientConnectionDelegate.sendTransaction(ClientConnectionDelegate.java)
  | 	at org.jboss.jms.tx.ResourceManager.sendTransactionXA(ResourceManager.java:662)
  | 	at org.jboss.jms.tx.ResourceManager.prepare(ResourceManager.java:337)
  | 	at org.jboss.jms.tx.MessagingXAResource.prepare(MessagingXAResource.java:240)
  | 	at org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper.prepare(JcaXAResourceWrapper.java:93)
  | 	at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:264)
  | 	at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2871)
  | 	at com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2828)
  | 	at com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2382)
  | 	at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1783)
  | 	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:88)
  | 	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
  | 	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1389)
  | 	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
  | 	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
  | 	at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:494)
  | 	at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:248)
  | 	at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204)
  | 	at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:275)
  | 	at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761)
  | 	at java.lang.Thread.run(Thread.java:595)
  | 
  | 

The german exception (why localized exception messages... :( ) "doppelter Schlüsselwert verletzt Unique-Constraint" translates to "double keyvalue violates Unique-Constraint".

After 25 of these messages I get the following error on the same node:


  | 2009-06-10 09:00:17,838 ERROR [org.jboss.messaging.core.impl.JDBCSupport] Retried 25 times, now giving up
  | 2009-06-10 09:00:17,838 ERROR [org.jboss.messaging.util.ExceptionUtil] ConnectionEndpoint[ai-p42wkrvf-1-76iy9rvf-8gbfr5-2aaa] sendTransaction [a68-ijfyorvf-1-76iy9rvf-8gbfr5-2aaa]
  | java.lang.IllegalStateException: Failed to execute transaction
  | 	at org.jboss.messaging.core.impl.JDBCSupport$JDBCTxRunner2.executeWithRetry(JDBCSupport.java:544)
  | 	at org.jboss.messaging.core.impl.JDBCPersistenceManager.handleBeforePrepare(JDBCPersistenceManager.java:2063)
  | 	at org.jboss.messaging.core.impl.JDBCPersistenceManager$TransactionCallback.beforePrepare(JDBCPersistenceManager.java:2984)
  | 	at org.jboss.messaging.core.impl.tx.Transaction.prepare(Transaction.java:265)
  | 	at org.jboss.jms.server.endpoint.ServerConnectionEndpoint.sendTransaction(ServerConnectionEndpoint.java:498)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.org$jboss$jms$server$endpoint$advised$ConnectionAdvised$sendTransaction$aop(ConnectionAdvised.java:101)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeNext(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.server.container.SecurityAspect.handleSendTransaction(SecurityAspect.java:195)
  | 	at sun.reflect.GeneratedMethodAccessor198.invoke(Unknown Source)
  | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
  | 	at java.lang.reflect.Method.invoke(Method.java:585)
  | 	at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:121)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeNext(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.server.container.ServerLogInterceptor.invoke(ServerLogInterceptor.java:105)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised$sendTransaction_N3268650789275322226.invokeNext(ConnectionAdvised$sendTransaction_N3268650789275322226.java)
  | 	at org.jboss.jms.server.endpoint.advised.ConnectionAdvised.sendTransaction(ConnectionAdvised.java)
  | 	at org.jboss.jms.wireformat.ConnectionSendTransactionRequest.serverInvoke(ConnectionSendTransactionRequest.java:82)
  | 	at org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
  | 	at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:866)
  | 	at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:608)
  | 	at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:420)
  | 	at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:173)
  | 

On the other node I get this message around the same time and I guess that they are related to each other:


  | 2009-06-10 09:00:17,307 WARN  [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] XAResourceRecord.prepare - prepare failed with exception XAException.XA_RETRY
  | 2009-06-10 09:00:17,307 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id a0a0a01:420:4a2f0671:b60c failed.
  | 2009-06-10 09:00:17,307 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
  | 2009-06-10 09:00:17,307 ERROR [org.jboss.resource.adapter.jms.inflow.JmsServerSession] org.jboss.resource.adapter.jms.inflow.JmsServerSession at 61befe failed to commit/rollback
  | javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Can't commit because the transaction is in aborted state
  | 	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1401)
  | 	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
  | 	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
  | 	at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:494)
  | 	at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:248)
  | 	at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204)
  | 	at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:275)
  | 	at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761)
  | 	at java.lang.Thread.run(Thread.java:595)
  | 2009-06-10 09:00:17,885 WARN  [com.arjuna.ats.jta.logging.loggerI18N] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] [com.arjuna.ats.internal.jta.resources.arjunacore.preparefailed] XAResourceRecord.prepare - prepare failed with exception XAException.XA_RETRY
  | 2009-06-10 09:00:17,885 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id a0a0a01:420:4a2f0671:b5f9 failed.
  | 2009-06-10 09:00:17,885 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
  | 2009-06-10 09:00:17,900 ERROR [org.jboss.resource.adapter.jms.inflow.JmsServerSession] org.jboss.resource.adapter.jms.inflow.JmsServerSession at 11608a4 failed to commit/rollback
  | javax.transaction.RollbackException: [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] [com.arjuna.ats.internal.jta.transaction.arjunacore.commitwhenaborted] Can't commit because the transaction is in aborted state
  | 	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1401)
  | 	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
  | 	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
  | 	at org.jboss.resource.adapter.jms.inflow.JmsServerSession$XATransactionDemarcationStrategy.end(JmsServerSession.java:494)
  | 	at org.jboss.resource.adapter.jms.inflow.JmsServerSession.run(JmsServerSession.java:248)
  | 	at org.jboss.resource.work.WorkWrapper.execute(WorkWrapper.java:204)
  | 	at org.jboss.util.threadpool.BasicTaskWrapper.run(BasicTaskWrapper.java:275)
  | 	at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:761)
  | 	at java.lang.Thread.run(Thread.java:595)
  | 

Do I need to worry about these log messages? And if I do then what can I do about it?

Thanks for your help.

View the original post : http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4236571#4236571

Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=4236571

More information about the jboss-user mailing list