Bug 991049 - Incorrect log level is used for XAException when TX recovery happens
Incorrect log level is used for XAException when TX recovery happens
Status: CLOSED CURRENTRELEASE
Product: JBoss Enterprise Application Platform 6
Classification: JBoss
Component: HornetQ (Show other bugs)
6.1.1
Unspecified Unspecified
unspecified Severity unspecified
: ER7
: EAP 6.1.1
Assigned To: Clebert Suconic
Miroslav Novak
Russell Dickenson
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-08-01 09:21 EDT by Ondrej Chaloupka
Modified: 2014-09-02 02:46 EDT (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Cause: The Transaction Manager will eventually try to rollback an XID with an unknown state (Prepare called and not sure if it was completed or not). Consequence: HornetQ will log a WARN with the XID not being existent Fix: Ignore the WARN. We now issue a log.Debug instead of log.warn Result: No warns are raised.
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-09-16 16:20:10 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
csuconic: needinfo-


Attachments (Terms of Use)

  None (edit)
Description Ondrej Chaloupka 2013-08-01 09:21:38 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]
Comment 2 Ondrej Chaloupka 2013-08-20 12:47:02 EDT
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
Comment 3 Clebert Suconic 2013-08-23 10:11:37 EDT
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.
Comment 6 Ondrej Chaloupka 2013-08-28 04:09:48 EDT
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/
Comment 7 Scott Mumford 2013-08-28 23:47:33 EDT
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.

Note You need to log in before you can comment on or make changes to this bug.