Bug 991049

Summary:	Incorrect log level is used for XAException when TX recovery happens
Product:	[JBoss] JBoss Enterprise Application Platform 6	Reporter:	Ondrej Chaloupka <ochaloup>
Component:	HornetQ	Assignee:	Clebert Suconic <csuconic>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Miroslav Novak <mnovak>
Severity:	unspecified	Docs Contact:	Russell Dickenson <rdickens>
Priority:	unspecified
Version:	6.1.1	CC:	csuconic, jochen.riedlinger, msvehla, myarboro, smumford
Target Milestone:	ER7	Flags:	csuconic: needinfo-
Target Release:	EAP 6.1.1
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
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 20:20:10 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Ondrej Chaloupka 2013-08-01 13:21:38 UTC

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 16:47:02 UTC

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 14:11:37 UTC

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 08:09:48 UTC

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-29 03:47:33 UTC

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.