Red Hat Bugzilla – Bug 991049
Incorrect log level is used for XAException when TX recovery happens
Last modified: 2014-09-02 02:46:40 EDT
When TM uses JTS then by the OTS specification two calls of rollback against one Xid could be called (some details could be found in this bz https://bugzilla.redhat.com/show_bug.cgi?id=988724). HornetQ returns correct response code for the second call which is XAER_NOTA. But before the response code is returned to TM HornetQ logs warning message with this transaction [1]. This warning is shown to user and it looks like an error happened during the recovery. But in fact it's not true because this is supposed. There is no context or explanation of the exception in the log. It's really confusing. I would suggest put such exception to debug or trace level as it would indicate that the exception could be expected. [1] WARN [org.hornetq.jms.server] (RequestProcessor-10) HQ122016: Error in XA Recovery: javax.transaction.xa.XAException at org.hornetq.core.client.impl.ClientSessionImpl.rollback(ClientSessionImpl.java:1666) [hornetq-core-client-2.3.2.Final-redhat-1.jar:2.3.2.Final-redhat-1] at org.hornetq.core.client.impl.DelegatingSession.rollback(DelegatingSession.java:494) [hornetq-core-client-2.3.2.Final-redhat-1.jar:2.3.2.Final-redhat-1] at org.hornetq.jms.server.recovery.HornetQXAResourceWrapper.rollback(HornetQXAResourceWrapper.java:126) [hornetq-jms-server-2.3.2.Final-redhat-1.jar:2.3.2.Final-redhat-1] at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.rollback(XAResourceRecord.java:357) [jbossjts-jacorb-4.17.5.Final-redhat-1.jar:4.17.5.Final-redhat-1] at com.arjuna.ArjunaOTS.OTSAbstractRecordPOA._invoke(OTSAbstractRecordPOA.java:213) [jbossjts-jacorb-4.17.5.Final-redhat-1.jar:4.17.5.Final-redhat-1] at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:306) [jacorb-2.3.2-redhat-4.jar:2.3.2-redhat-4] at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:626) [jacorb-2.3.2-redhat-4.jar:2.3.2-redhat-4] at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:769) [jacorb-2.3.2-redhat-4.jar:2.3.2-redhat-4]
Hi Clebert, I would like ask about this bz. I've hit the problem for 6.1.1.ER4 and when I've run tests for ER6 the exception disappeared from the server log. Is it intentional? (as there is no info here). Is it some status change here? Thank you Ondra
I assumed this as a simple request to change the log.warn to log.debug and made the change here: https://github.com/hornetq/hornetq/commit/dae1f01c288a92169262cf0e1b2e05e34ff984ed I thought I had changed this... this been changed since HornetQ 2.3.4. so ER7 contains this fix.
Hi Clebert, thank you. I verified it. There could be checked in difference between run against ER4 and ER7. https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-60-jbossts-crashrec-tests-jms/35/ https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-60-jbossts-crashrec-tests-jms/38/
Marking for exclusion from the 6.1.1 Release Notes document as an entry for this bug could not be completed or verified in time.