Hi Joey, I just tried the change myself to confim it works as expected, causing a suitably overwhelming amount of debug logging during use. To be clear, it is broker side logging the change turns on which by default goes to the file $QPID_WORK/log/qpid.log (where QPID_WORK defaults to your homedir if you dont set it).
You could also turn on client logging to get a matching set, by ensuring a suitable SLF4J binding and associated logging implementation is available and again setting the org.apache.qpid logger to debug. Can you post an example of the particular 404 exceptions you are seeing? Robbie On 26 June 2012 18:04, Joey Daughtery <[email protected]> wrote: > All > After making the modification to log4j.xml, I really did not see any DEBUG > statements. Also, there is an exception below the RBTIMEOUT that has an > error code of 409. Note that I also see some exceptions on occasion that > has an error code of 404 associated with qpid. > > 12:13:53,368 WARN [com.arjuna.ats.jta] (Dispatcher-0-Conn-1) ARJUNA016041: > prepare on < formatId=131077, gtrid_length=29, bqual_length=36, > tx_uid=0:ffff7f000001:-796e14cd:4fe9dbc6:43cc, node_name=1, > branch_uid=0:ffff7f000001:-796e14cd:4fe9dbc6:43cd, > subordinatenodename=null, eis_name=unknown eis name > > (org.apache.qpid.client.XAResourceImpl@1d25d8a0) failed with exception > XAException.XA_RBTIMEOUT: javax.transaction.xa.XAException > at > org.apache.qpid.client.XAResourceImpl.checkStatus(XAResourceImpl.java:507) > [qpid-client-0.17.jar:] > at org.apache.qpid.client.XAResourceImpl.end(XAResourceImpl.java:166) > [qpid-client-0.17.jar:] > at > com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelPrepare(XAResourceRecord.java:208) > at > com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2535) > at > com.arjuna.ats.arjuna.coordinator.BasicAction.doPrepare(BasicAction.java:2502) > at > com.arjuna.ats.arjuna.coordinator.BasicAction.prepare(BasicAction.java:2079) > at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1472) > at > com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) > at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:164) > at > com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165) > at > com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117) > at > com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) > at > org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:72) > [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] > at sun.reflect.GeneratedMethodAccessor10.invoke(Unknown Source) [:1.6.0_32] > at > sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) > [rt.jar:1.6.0_32] > at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_32] > at > org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60) > [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] > at > org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136) > [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] > at > org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) > [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] > at $Proxy15.afterDelivery(Unknown Source) at > org.apache.qpid.ra.inflow.QpidMessageHandler.onMessage(QpidMessageHandler.java:217) > at > org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:751) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:141) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:725) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:186) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:54) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.AMQSession$Dispatcher.notifyConsumer(AMQSession.java:3475) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.AMQSession$Dispatcher.dispatchMessage(AMQSession.java:3414) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.AMQSession$Dispatcher.access$1000(AMQSession.java:3201) > [qpid-client-0.17.jar:] > at org.apache.qpid.client.AMQSession.dispatch(AMQSession.java:3194) > [qpid-client-0.17.jar:] > at > org.apache.qpid.client.message.UnprocessedMessage.dispatch(UnprocessedMessage.java:54) > [qpid-client-0.17.jar:] > at org.apache.qpid.client.AMQSession$Dispatcher.run(AMQSession.java:3337) > [qpid-client-0.17.jar:] > at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_32] > > 12:13:53,387 WARN [com.arjuna.ats.arjuna] (Dispatcher-0-Conn-1) > ARJUNA012073: BasicAction.End() - prepare phase of action-id > 0:ffff7f000001:-796e14cd:4fe9dbc6:43cc failed. > 12:13:53,387 WARN [com.arjuna.ats.arjuna] (Dispatcher-0-Conn-1) > ARJUNA012075: Action Aborting > 12:13:53,393 INFO [org.apache.qpid.client.AMQConnection] (IoReceiver - / > 127.0.0.1:5672) Closing AMQConnection due to :org.apache.qpid.AMQException: > ch=1 id=724 ExecutionException(errorCode=ILLEGAL_STATE, commandId=878, > description=Xid Xid(format=131077, globalId=[B@4738fec2, > branchId=[B@6edd9715) not associated with the current session) [error code > 409: argument invalid] > 12:13:53,394 WARN [org.apache.qpid.ra.inflow.QpidExceptionHandler] > (IoReceiver - /127.0.0.1:5672) Failure in Qpid activation > org.apache.qpid.ra.inflow.QpidActivationSpec(ra=org.apache.qpid.ra.QpidResourceAdapter@1398a09edestination=java:jboss/exported/iHarvestQueue > destinationType=javax.jms.Queue ack=Auto-acknowledge durable=false > clientID=null user=null maxSession=10 connectionPerHandler=true): > javax.jms.JMSException: Exception thrown against AMQConnection: > Host: 127.0.0.1 > Port: 5672 > Virtual Host: test > Client ID: client_id > Active session count: 1: org.apache.qpid.AMQException: ch=1 id=724 > ExecutionException(errorCode=ILLEGAL_STATE, commandId=878, description=Xid > Xid(format=131077, globalId=[B@4738fec2, branchId=[B@6edd9715) not > associated with the current session) [error code 409: argument invalid] > at > org.apache.qpid.client.AMQConnection.exceptionReceived(AMQConnection.java:1226) > at > org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1057) > at > org.apache.qpid.client.AMQSession_0_10.exception(AMQSession_0_10.java:907) > at > org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:182) > at > org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:32) > at > org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:103) > at > org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:55) > at > org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:50) > at > org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:32) > at org.apache.qpid.transport.Method.delegate(Method.java:159) > at org.apache.qpid.transport.Session.received(Session.java:584) > at org.apache.qpid.transport.Connection.dispatch(Connection.java:421) > at > org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64) > at > org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40) > at > org.apache.qpid.transport.MethodDelegate.executionException(MethodDelegate.java:110) > at > org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:103) > at > org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54) > at > org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40) > at org.apache.qpid.transport.Method.delegate(Method.java:159) > at org.apache.qpid.transport.Connection.received(Connection.java:376) > at org.apache.qpid.transport.Connection.received(Connection.java:67) > at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:97) > at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:198) > at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:131) > at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128) > at org.apache.qpid.transport.network.Assembler.received(Assembler.java:102) > at org.apache.qpid.transport.network.Assembler.received(Assembler.java:44) > at > org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:189) > at > org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:105) > at > org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:44) > at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:152) > at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_32] > Caused by: org.apache.qpid.AMQException: ch=1 id=724 > ExecutionException(errorCode=ILLEGAL_STATE, commandId=878, description=Xid > Xid(format=131077, globalId=[B@4738fec2, branchId=[B@6edd9715) not > associated with the current session) [error code 409: argument invalid] > at > org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1054) > ... 30 more > > Thanks > > Joe > > On Tue, Jun 26, 2012 at 11:42 AM, Robbie Gemmell > <[email protected]>wrote: > >> If you open the <broker.install.path>/etc/log4j.xml file and edit the >> value of the org.apache.qpid category as follows it should provide a >> lot of additional logging, which might help shed some light: >> >> From: >> <category additivity="true" name="org.apache.qpid"> >> <priority value="warn"/> >> </category> >> >> To: >> <category additivity="true" name="org.apache.qpid"> >> <priority value="debug"/> >> </category> >> >> (Alternatively, all the loggers can be manipulated while the broker is >> running by attaching JConsole or similar to it and using the >> LoggingManagement MBean) >> >> Robbie >> >> On 26 June 2012 16:07, Weston M. Price <[email protected]> wrote: >> > Note, while JCA is being used, the underly ResourceManager is timing >> out. Joe is using the Java Broker and I know XA support is fairly new. Is >> there any tracing mechanism we can use to isolate the problem? >> > >> > Regards, >> > >> > Weston >> > On Jun 26, 2012, at 10:55 AM, Joey Daughtery wrote: >> > >> >> All >> >> I am starting to see the following exception quite often. All the data >> >> that is sent to the queue is received by the mdb and stored. The test >> >> client that I have sending TextMessages to the queue sends one per 500ms >> >> and I am sending a total of 5000. When the MDB receives the >> TextMessage, >> >> it basically does an update on a record in mongodb. >> >> >> >> >> >> >> >> >> >> 08:44:19,524 WARN [com.arjuna.ats.jta] (Dispatcher-0-Conn-1) >> ARJUNA016036: >> >> commit on < formatId=131077, gtrid_length=29, bqual_length=36, >> >> tx_uid=0:ffff7f000001:61f68a5e:4fe9ae65:13, node_name=1, >> >> branch_uid=0:ffff7f000001:61f68a5e:4fe9ae65:14, >> subordinatenodename=null, >> >> eis_name=unknown eis name > >> (org.apache.qpid.client.XAResourceImpl@6fe03f3b) >> >> failed with exception $XAException.XA_RBTIMEOUT: >> >> javax.transaction.xa.XAException >> >> at >> >> >> org.apache.qpid.client.XAResourceImpl.checkStatus(XAResourceImpl.java:507) >> >> [qpid-client-0.17.jar:] >> >> at org.apache.qpid.client.XAResourceImpl.commit(XAResourceImpl.java:112) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelCommit(XAResourceRecord.java:451) >> >> at >> >> >> com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2753) >> >> at >> >> >> com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:2669) >> >> at >> >> >> com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:1804) >> >> at >> com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1495) >> >> at >> >> >> com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:98) >> >> at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:164) >> >> at >> >> >> com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1165) >> >> at >> >> >> com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:117) >> >> at >> >> >> com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75) >> >> at >> >> >> org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.afterDelivery(MessageEndpointInvocationHandler.java:72) >> >> [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] >> >> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) >> >> [rt.jar:1.6.0_32] >> >> at >> >> >> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) >> >> [rt.jar:1.6.0_32] >> >> at >> >> >> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) >> >> [rt.jar:1.6.0_32] >> >> at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_32] >> >> at >> >> >> org.jboss.as.ejb3.inflow.AbstractInvocationHandler.handle(AbstractInvocationHandler.java:60) >> >> [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] >> >> at >> >> >> org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:136) >> >> [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] >> >> at >> >> >> org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73) >> >> [jboss-as-ejb3-7.1.1.Final.jar:7.1.1.Final] >> >> at $Proxy15.afterDelivery(Unknown Source) at >> >> >> org.apache.qpid.ra.inflow.QpidMessageHandler.onMessage(QpidMessageHandler.java:217) >> >> at >> >> >> org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:751) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:141) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.BasicMessageConsumer.notifyMessage(BasicMessageConsumer.java:725) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:186) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.BasicMessageConsumer_0_10.notifyMessage(BasicMessageConsumer_0_10.java:54) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.AMQSession$Dispatcher.notifyConsumer(AMQSession.java:3475) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.AMQSession$Dispatcher.dispatchMessage(AMQSession.java:3414) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.AMQSession$Dispatcher.access$1000(AMQSession.java:3201) >> >> [qpid-client-0.17.jar:] >> >> at org.apache.qpid.client.AMQSession.dispatch(AMQSession.java:3194) >> >> [qpid-client-0.17.jar:] >> >> at >> >> >> org.apache.qpid.client.message.UnprocessedMessage.dispatch(UnprocessedMessage.java:54) >> >> [qpid-client-0.17.jar:] >> >> at >> org.apache.qpid.client.AMQSession$Dispatcher.run(AMQSession.java:3337) >> >> [qpid-client-0.17.jar:] >> >> at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_32] >> >> >> >> Thanks >> >> >> >> Joe >> > >> > >> > --------------------------------------------------------------------- >> > To unsubscribe, e-mail: [email protected] >> > For additional commands, e-mail: [email protected] >> > >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: [email protected] >> For additional commands, e-mail: [email protected] >> >> --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
