Bug 1023193

Summary: JMS generic RA shows 'lock owned during cleanup' warning during periodic crash recovery
Product: [JBoss] JBoss Enterprise Application Platform 6 Reporter: Ondrej Chaloupka <ochaloup>
Component: JMSAssignee: Jeff Mesnil <jmesnil>
Status: CLOSED EOL QA Contact: Miroslav Novak <mnovak>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 6.2.0CC: mnovak, msvehla, tom.jenkinson
Target Milestone: ---   
Target Release: EAP 6.4.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Known Issue
Doc Text:
A minor issue with periodic recovery has been identified, where warning messages beginning with the following text are logged. ---- WARN [org.jboss.resource.adapter.jms.JmsManagedConnection] (Periodic Recovery) Lock owned during cleanup: java.lang.Throwable: Lock owned during cleanup ---- The underlying cause of the issue is that the generic JMS adapter mishandles the second periodic recovery call. In accordance with the Object Transaction Service specification, when the transaction manager is set to be run on the Java Transaction Service (JTS) the periodic recovery calls rollback for the same XID twice. The issue is that the generic JMS adapter incorrectly handles the second call of the rollback for the same XID and the above warnings are logged. Note that despite the warning messages, recovery occurs correctly.
 Story Points: ---
Clone Of: Environment:
Last Closed: 2019-08-19 12:45: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:

Description Ondrej Chaloupka 2013-10-24 20:41:03 UTC 
When periodic crash recovery runs with Tibco remote broker and rollback is expected then the log contains "java.lang.Throwable: Lock owned during cleanup" warning [1]. The server log should be clean for crash recovery.
This seems does not influence the results of the test (functionality of the recovery).

[1]
WARN  [org.jboss.resource.adapter.jms.JmsManagedConnection] (Periodic Recovery) Lock owned during cleanup: java.lang.Throwable: Lock owned during cleanup
 at java.lang.Object.wait(Native Method) [rt.jar:1.7.0_45]
 at java.lang.Object.wait(Object.java:503) [rt.jar:1.7.0_45]
 at com.tibco.tibjms.TibjmsxLink.sendRequest(TibjmsxLink.java:359) [tibjms.jar:6.3.0]
 at com.tibco.tibjms.TibjmsXAResource.rollbackTx(TibjmsXAResource.java:645) [tibjms.jar:6.3.0]
 at com.tibco.tibjms.TibjmsXAResource._rollback(TibjmsXAResource.java:455) [tibjms.jar:6.3.0]
 at com.tibco.tibjms.TibjmsXAResource.rollback(TibjmsXAResource.java:444) [tibjms.jar:6.3.0]
 at org.jboss.resource.adapter.jms.JmsXAResource.rollback(JmsXAResource.java:94)
 at org.jboss.jca.core.tx.jbossts.XAResourceWrapperImpl.rollback(XAResourceWrapperImpl.java:186)
 at com.arjuna.ats.internal.jta.resources.jts.orbspecific.XAResourceRecord.rollback(XAResourceRecord.java:377) [jbossjts-jacorb-4.17.12.Final-redhat-1.jar:4.17.12.Final-redhat-1]
 at com.arjuna.ArjunaOTS.OTSAbstractRecordPOA._invoke(OTSAbstractRecordPOA.java:213) [jbossjts-jacorb-4.17.12.Final-redhat-1.jar:4.17.12.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 1 Ondrej Chaloupka 2013-10-24 20:44:06 UTC 
I forgot to mention that this happens with transactions set to jts.
Comment 4 tom.jenkinson 2013-10-28 15:38:33 UTC 
This may not be the cause but is it possible that rollback has been called twice? In the scenario where we get to call rollback on the XAR (e.g. immediately pre crash) but then crash we will call it again on recovery.
Comment 5 Ondrej Chaloupka 2013-10-29 09:02:21 UTC 
Hi,

I've checked the proceeding of the recovery and it seems that Tom is right. The second call of the rollback on the XAR (arjuna 4.17.12.Final call from XAResourceRecord, l:377) causes the warning being written to the server log. 

Just a note: the second call of the rollback on the same XAR is OK. It's in accordance with OTS specification (discussed on this bz https://bugzilla.redhat.com/show_bug.cgi?id=988724#c2).

Ondra
Comment 6 Russell Dickenson 2013-12-02 00:29:30 UTC 
I have edited this BZ ticket's release notes entry. Please review the text and confirm whether or not it is accurate.
Comment 7 Ondrej Chaloupka 2013-12-02 08:05:13 UTC 
The text is ok.
I just added the abbreviation jts to the text for this being more obvious what does it mean. It's because the abbreviation jts is used as configuration parameter in transaction subsystem.
Comment 8 tom.jenkinson 2014-09-03 09:37:23 UTC 
Hi,

This issue has not been touched in many months. Is it intended to be resolved in product or can we close it?

Tom