Sporadic failure to commit

[ydzsidemiik]

Hi,

In the last couple of months, we've started seeing some strange sporadic exceptions coming from JBoss Messaging, or seemingly related to it. The load on our system has been steadily creeping upwards, and these seem to have started happening once some threshold was reached. Some of these look like configuration errors on the surface of it, but they occur largely randomly, affecting only a tiny percentage of large volumes of transactions.

We are running JBoss AS 4.2.2.GA with JBM 1.4.0.SP3 with JBMESSAGING-1221 fix applied.

I'm going to throw out some examples with hopes of getting some insight into how to proceed. They're not reproducible test cases, but any insight at all would really help me out.

2008-07-11 15:32:26,139 ERROR [WorkManager(2)-11530~org.jboss.security.auth.spi.UsersRolesLoginModule] Failed to load users/passwords/role files
java.io.IOException: No properties file: props/messaging-users.properties or defaults: defaultUsers.properties found
at org.jboss.security.auth.spi.Util.loadProperties(Util.java:315)
at org.jboss.security.auth.spi.UsersRolesLoginModule.loadUsers(UsersRolesLoginModule.java:186)
at org.jboss.security.auth.spi.UsersRolesLoginModule.createUsers(UsersRolesLoginModule.java:200)
at org.jboss.security.auth.spi.UsersRolesLoginModule.initialize(UsersRolesLoginModule.java:127)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:756)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
at org.jboss.security.plugins.JaasSecurityManager.defaultLogin(JaasSecurityManager.java:603)
at org.jboss.security.plugins.JaasSecurityManager.authenticate(JaasSecurityManager.java:537)
at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:344)
at org.jboss.jms.server.security.SecurityMetadataStore.authenticate(SecurityMetadataStore.java:190)
at org.jboss.jms.server.container.SecurityAspect.check(SecurityAspect.java:296)
at org.jboss.jms.server.container.SecurityAspect.handleSendTransaction(SecurityAspect.java:190)
at sun.reflect.GeneratedMethodAccessor136.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:795)
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.commit(ResourceManager.java:367)
at org.jboss.jms.tx.MessagingXAResource.commit(MessagingXAResource.java:254)
at org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper.commit(JcaXAResourceWrapper.java:53)
at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:636)
at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2619)
at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1779)
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.ejb3.mdb.inflow.MessageInflowLocalProxy.endTransaction(MessageInflowLocalProxy.java:433)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:290)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
at $Proxy197.onDeliver(Unknown Source)
at sun.reflect.GeneratedMethodAccessor162.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at com.acme.gateway.smppra.spi.BaseManagedConnection.dispatch(BaseManagedConnection.java:752)
at com.acme.gateway.smppra.spi.BaseManagedConnection.messageReceived(BaseManagedConnection.java:786)
at org.apache.mina.handler.multiton.SingleSessionIoHandlerDelegate.messageReceived(SingleSessionIoHandlerDelegate.java:132)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:570)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.common.IoFilterAdapter.messageReceived(IoFilterAdapter.java:80)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$EventProcessor$EventDispatcher.visitReceived(ClassifyingExecutorFilter.java:298)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$ReceivedEvent.accept(ClassifyingExecutorFilter.java:182)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$EventProcessor.run(ClassifyingExecutorFilter.java:361)
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)

props/messaging-users.properties exists in the exact same place it has existed for the last nine months, and this only happens randomly, once in a blue moon. It is immediately followed by:

2008-07-11 15:32:26,198 ERROR [WorkManager(2)-11530~org.jboss.jms.tx.ResourceManager] org.jboss.jms.exception.MessagingXAException: A security exception happend!
org.jboss.jms.exception.MessagingXAException: A security exception happend!
at org.jboss.jms.tx.ResourceManager.sendTransactionXA(ResourceManager.java:666)
at org.jboss.jms.tx.ResourceManager.commit(ResourceManager.java:367)
at org.jboss.jms.tx.MessagingXAResource.commit(MessagingXAResource.java:254)
at org.jboss.resource.connectionmanager.xa.JcaXAResourceWrapper.commit(JcaXAResourceWrapper.java:53)
at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:636)
at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2619)
at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1779)
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.ejb3.mdb.inflow.MessageInflowLocalProxy.endTransaction(MessageInflowLocalProxy.java:433)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:290)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
at $Proxy197.onDeliver(Unknown Source)
at sun.reflect.GeneratedMethodAccessor162.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at com.acme.gateway.smppra.spi.BaseManagedConnection.dispatch(BaseManagedConnection.java:752)
at com.acme.gateway.smppra.spi.BaseManagedConnection.messageReceived(BaseManagedConnection.java:786)
at org.apache.mina.handler.multiton.SingleSessionIoHandlerDelegate.messageReceived(SingleSessionIoHandlerDelegate.java:132)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:570)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.common.IoFilterAdapter.messageReceived(IoFilterAdapter.java:80)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$EventProcessor$EventDispatcher.visitReceived(ClassifyingExecutorFilter.java:298)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$ReceivedEvent.accept(ClassifyingExecutorFilter.java:182)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$EventProcessor.run(ClassifyingExecutorFilter.java:361)
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)
Caused by: javax.jms.JMSSecurityException: User guest is NOT authenticated
at org.jboss.jms.server.security.SecurityMetadataStore.authenticate(SecurityMetadataStore.java:202)
at org.jboss.jms.server.container.SecurityAspect.check(SecurityAspect.java:296)
at org.jboss.jms.server.container.SecurityAspect.handleSendTransaction(SecurityAspect.java:190)
at sun.reflect.GeneratedMethodAccessor136.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:795)
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)
... 36 more

Then there is this one:

2008-07-11 11:34:59,110 WARN [WorkManager(2)-11167~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
2008-07-11 11:34:59,111 WARN [WorkManager(2)-11167~com.arjuna.ats.arjuna.logging.arjLoggerI18N] () [com.arjuna.ats.arjuna.coordinator.BasicAction_36] - BasicAction.End() - prepare phase of action-id a7e00cd:ec36:48639754:5f39631 failed.
2008-07-11 11:34:59,111 WARN [WorkManager(2)-11167~com.arjuna.ats.arjuna.logging.arjLoggerI18N] () [com.arjuna.ats.arjuna.coordinator.BasicAction_38] - Action Aborting
2008-07-11 11:34:59,140 ERROR [WorkManager(2)-11167~org.jboss.resource.adapter.jms.inflow.JmsServerSession] () org.jboss.resource.adapter.jms.inflow.JmsServerSession@17a95c6 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)

JBM is the only RM in my stack that uses the XA_RETRY code.

Finally, there is this one:

java.lang.reflect.InvocationTargetException
at sun.reflect.GeneratedMethodAccessor162.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at com.acme.gateway.smppra.spi.BaseManagedConnection.dispatch(BaseManagedConnection.java:752)
at com.acme.gateway.smppra.spi.BaseManagedConnection.messageReceived(BaseManagedConnection.java:786)
at org.apache.mina.handler.multiton.SingleSessionIoHandlerDelegate.messageReceived(SingleSessionIoHandlerDelegate.java:132)
at org.apache.mina.common.support.AbstractIoFilterChain$TailFilter.messageReceived(AbstractIoFilterChain.java:570)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)
at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at org.apache.mina.common.IoFilterAdapter.messageReceived(IoFilterAdapter.java:80)
at org.apache.mina.common.support.AbstractIoFilterChain.callNextMessageReceived(AbstractIoFilterChain.java:299)


at org.apache.mina.common.support.AbstractIoFilterChain.access$1100(AbstractIoFilterChain.java:53)
at org.apache.mina.common.support.AbstractIoFilterChain$EntryImpl$1.messageReceived(AbstractIoFilterChain.java:648)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$EventProcessor$EventDispatcher.visitReceived(ClassifyingExecutorFilter.java:298)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$ReceivedEvent.accept(ClassifyingExecutorFilter.java:182)
at com.acme.gateway.smppra.spi.io.filter.ClassifyingExecutorFilter$EventProcessor.run(ClassifyingExecutorFilter.java:361)
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)
Caused by: javax.ejb.EJBTransactionRolledbackException
at org.jboss.ejb3.tx.Ejb3TxPolicy.handleInCallerTx(Ejb3TxPolicy.java:87)
at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:130)
at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77)
at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:240)
at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:210)
at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:84)
at $Proxy158.enqueueInboundLive(Unknown Source)
at com.acme.gateway.CarrierGateway.onRoutable(CarrierGateway.java:62)
at com.acme.gateway.smppra.adapter.PDUListenerCoalescingAdapter.onDeliver(PDUListenerCoalescingAdapter.java:81)
at sun.reflect.GeneratedMethodAccessor163.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.mdb.MessagingContainer.localInvoke(MessagingContainer.java:249)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.delivery(MessageInflowLocalProxy.java:268)
at org.jboss.ejb3.mdb.inflow.MessageInflowLocalProxy.invoke(MessageInflowLocalProxy.java:138)
at $Proxy197.onDeliver(Unknown Source)
... 21 more

Caused by: java.lang.NullPointerException
at org.jboss.mx.loading.RepositoryClassLoader.findClass(RepositoryClassLoader.java:630)
at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
at org.jboss.mx.loading.RepositoryClassLoader.loadClassImpl(RepositoryClassLoader.java:474)
at org.jboss.mx.loading.RepositoryClassLoader.loadClass(RepositoryClassLoader.java:415)
at java.lang.ClassLoader.loadClass(ClassLoader.java:251)
at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319)
at java.lang.Class.forName0(Native Method)
at java.lang.Class.forName(Class.java:242)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:731)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
at org.jboss.security.plugins.JaasSecurityManager.defaultLogin(JaasSecurityManager.java:603)
at org.jboss.security.plugins.JaasSecurityManager.authenticate(JaasSecurityManager.java:537)
at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:344)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.getSubject(BaseConnectionManager2.java:588)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.allocateConnection(BaseConnectionManager2.java:395)
at org.jboss.resource.connectionmanager.BaseConnectionManager2$ConnectionManagerProxy.allocateConnection(BaseConnectionManager2.java:842)
at org.jboss.resource.adapter.jms.JmsSessionFactoryImpl.allocateConnection(JmsSessionFactoryImpl.java:389)
at org.jboss.resource.adapter.jms.JmsSessionFactoryImpl.createSession(JmsSessionFactoryImpl.java:369)
at com.acme.gateway.util.jms.JmsOperation.execute(JmsOperation.java:51)
at com.acme.gateway.service.EnqueuerImpl.enqueue(EnqueuerImpl.java:336)
at com.acme.gateway.service.EnqueuerImpl.enqueueInboundLive(EnqueuerImpl.java:421)
at sun.reflect.GeneratedMethodAccessor164.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112)
at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166)
at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126)
... 60 more

I'm not sure this is JBM, but it has something to do with security like the first one, so it might be related.

Any thoughts?

[noelo]

Is the disk that jboss (or its config) a native disk i.e. attached to the server or remove e.g. nfs mount from a netapp....I have seen errors like this before in a standalone tomcat installation and I put it down to a disk error. But then again I may be wrong...

[ydzsidemiik]

I don't think that's it -- JBoss is on the server's own disk, a simple RAID-1.

It was a good guess though, and an appreciated bump :)

[ydzsidemiik]

I know I'm stretching a bit here, but I can't convince my handlers to buy a support contract. If I was a high-powered contractor I'd have shelled out for my own by now, but I'm just a lowly junior developer. This application is my responsibility and I want it to work well. I have the resources I've been given, such as they are.

I'm basically begging for a bone. I genuinely don't think my own application is the cause of these issues, but I will openly entertain suggestions to the contrary, along with any other insight at all. I'm not asking anyone to debug my code. Just give me a clue; I promise to submit patches if any result.

[ataylor]

I have to agree with noelo, it looks like a disk problem.

I would suggest running in a different environment to see if the error still occurs.

[clebert.suconic]

You're using the Properties Login Module in your security configuration. That will use a property file to store users and passwords.

If I were you I would change that to a database. It *might be* some limit on accessing that file. A database would control it better as you're having problems with high load.

[ydzsidemiik]

The FD limit is an interesting thought; it hadn't occurred to me. I will try raising it. If that doesn't work, I will try the database login module, and then moving the application to a different server.

Do either of you by any chance know under what circumstances JBM returns XA_RETRY on prepare to the TM?

Your help is much appreciated. Many thanks.

[clebert.suconic]

"ydzsidemiik" wrote:
The FD limit is an interesting thought; it hadn't occurred to me. I will try raising it. If that doesn't work, I will try the database login module, and then moving the application to a different server.

Do either of you by any chance know under what circumstances JBM returns XA_RETRY on prepare to the TM?

Your help is much appreciated. Many thanks.

Why you don't just change the login-config to use a Database?

Regarding your question about XA_RETRY, the only reference to XA_RETRY I could find at our SVN Branch is during some security exception, what would make sense for you to change your configs from file to database:

from:

http://anonsvn.jboss.org/repos/messaging/branches/Branch_Stable/src/main/org/jboss/jms/tx/ResourceManager.java

private void sendTransactionXA(TransactionRequest request, ConnectionDelegate connection)
 throws XAException
 {
 try
 {
 connection.sendTransaction(request, false);
 }
 catch (JMSSecurityException security)
 {
 MessagingXAException xaEx = new MessagingXAException(XAException.XA_RBROLLBACK, "A security exception happend!", security);
 log.error(xaEx, xaEx);
 throw xaEx;
 }
 catch (Throwable t)
 {
 //Catch anything else

 //We assume that any error is recoverable - and the recovery manager should retry again
 //either after the network connection has been repaired (if that was the problem), or
 //the server has been fixed.

 //(In some cases it will not be possible to fix so the user will have to manually resolve the tx)

 //Therefore we throw XA_RETRY
 //Note we DO NOT throw XAER_RMFAIL or XAER_RMERR since both if these will cause the Arjuna
 //tx mgr NOT to retry and the transaction will have to be resolve manually.

 throw new MessagingXAException(XAException.XA_RETRY, "A Throwable was caught in sending the transaction", t);
 }
 }

[ydzsidemiik]

Ok, I will push the change into the next maintenance window. I will bump this thread with an update once I have some info on how it went.

Be patient with this lowly noob :)

[clebert.suconic]

One thing has occurred to me...


Double check your configs because of this:

Caused by: javax.jms.JMSSecurityException: User guest is NOT authenticated

I have seen this error when the login is not properly configured. But this is would not be a sporadic failure. (Unless you have something using the guest user only sporadically)

Make sure you can connect a producer without specifying user/password on the server. Try using the examples (producer.. queues.. etc).

[ydzsidemiik]

My security configuration is out-of-the-box, and all my queue deployments mirror the example ones that permit guest access. All clients, both in-container (JMSRA) and outside it connect without user/password credentials.

The DB change was scheduled for today. However, a couple of days ago a colleague stubmbled across this:

http://www.mail-archive.com/[e-mail]/msg31913.html//www.mail-archive.com/[e-mail]/msg31913.html

On a whim, I decided to try bumping jboss.security:JaasSecurityManager.DefaultCacheTimeout from 1800 to 31536000 (1 year). As a result of this change, the failures seem to have stopped. It certainly looks at this point like none of this was JBM's fault, and instead caused by some faulty invalidation code in SX. I won't be able to change my user/role configuration without restarting the server anymore, but I can live with that if my transactions stop dying mysterious deaths. :)

Thanks for all your help gentlemen. The ML thread suggests the issue is old and known, but do let me know if I can offer something further.

[ydzsidemiik]

Also, this is incredibly anecdotal, but I was witnessing the JBM queue MessageCount and DeliveringCount tick upwards together while this was happening, independently of the actual number of messages. That is, I could run listAllMessages on the queue mbean and see nothing, but MessageCount and DeliveringCount could both be some n > 0 which would tick up at a rate of few per day.

There may be some data race or unsafe exception handling occurring in relation to these exceptions. (ie, increment the counter but the commit into queue fails with unexpected security exception?)

Anyway, I thought I'd mention it.

[pkorros]

Hi,
I am the author of the issue you refer to your message

http://www.mail-archive.com/[e-mail]/msg31913.html//www.mail-archive.com/[e-mail]/msg31913.html

Back then i solved the problem by disabling the security manager interceptor of the JbossMQ implementation.

Recently I moved to the Jboss messaging implementation and starting having the same problem (nightmare) again.

I would like to ask if raising the DefaultCacheTimeout did solve the problem.

Thanks.