TransactionManager - error in delist; already committed

[patrickvankann]

I'm getting a transaction-related problem where the TransactionManager claims that my container managed transaction is "already committed" during delist(). The transaction seems to commit just fine and data gets updated in my database - and the error only shows on the console and in the log.

I am having trouble debugging this problem because I cannot see the full stack-trace of the nested exception. I have turned on debugging in the TransactionManager as described in READ THIS FIRST but the full stack of the root cause of the exception is not being shown. Below is the edited log message - I want to be able to see the extra lines after "...67 more". If anyone can help me to be able to see the full stack trace I would be most grateful - and any clues as to what might be causing the underlying exception would also be most excellent! Thanks everyone.

06,519 TRACE [org.jboss.tm.TransactionImpl] Committing, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=socks//15, BranchQual=], status=STATUS_ACTIVE
2004-08-19 18:05:06,519 TRACE [org.jboss.tm.TransactionImpl] calling sync 0, org.exolab.castor.jdo.engine.DatabaseImpl@10d78ec:cookietime
2004-08-19 18:05:06,529 TRACE [org.jboss.tm.TransactionImpl] calling sync 1, org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener$TxRemover@12929b2
2004-08-19 18:05:06,529 TRACE [org.jboss.tm.TransactionImpl] Before completion done, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=socks//15, BranchQual=], status=STATUS_ACTIVE
2004-08-19 18:05:06,529 TRACE [org.jboss.tm.TransactionImpl] endresources(0): state=1
2004-08-19 18:05:06,529 TRACE [org.jboss.tm.TransactionImpl] endResource(XidImpl [FormatId=257, GlobalId=socks//15, BranchQual=1]) entered: org.jboss.resource.adapter.jdbc.xa.XAManagedConnection@f44031 flag=67108864
2004-08-19 18:05:06,529 TRACE [org.jboss.tm.TransactionImpl] endResource(XidImpl [FormatId=257, GlobalId=socks//15, BranchQual=1]) leaving: org.jboss.resource.adapter.jdbc.xa.XAManagedConnection@f44031 flag=67108864
2004-08-19 18:05:06,529 TRACE [org.jboss.tm.TransactionImpl] One phase commit: One resource.
2004-08-19 18:05:06,529 TRACE [org.jboss.tm.TransactionImpl] Committing resources, resourceStates[0]=3
2004-08-19 18:05:06,569 TRACE [org.jboss.tm.TransactionImpl] delistResource(): Entered, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=socks//15, BranchQual=] status=STATUS_COMMITED
2004-08-19 18:05:06,569 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.parentTraceEnabled=true
2004-08-19 18:05:06,569 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.nestedTraceEnabled=false
2004-08-19 18:05:06,569 DEBUG [org.jboss.util.NestedThrowable] org.jboss.util.NestedThrowable.detectDuplicateNesting=true
2004-08-19 18:05:06,569 ERROR [org.jboss.resource.connectionmanager.TxConnectionManager] Error while closing connection handle!
org.jboss.resource.JBossResourceException: Error in delist!; - nested throwable: (java.lang.IllegalStateException: Already committed.)
... [etc etc - some extraneous lines deleted here...]
Caused by: java.lang.IllegalStateException: Already committed.
at org.jboss.tm.TransactionImpl.delistResource(TransactionImpl.java:529)
at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.delist(TxConnectionManager.java:486)
... 67 more

[adrian.brock]

The 67 more are the extraneous lines you deleted.

[patrickvankann]

Thanks for your prompt response. I am now looking at the code of TransactionImpl.java in the JBoss 3.2.5 source and the JTA specification. My understanding is that delisting should only happen on commited transactions - so why does the JBoss implementation throw an exception if a resource is committed? i.e. from delistResource()...

case Status.STATUS_COMMITTED:
throw new IllegalStateException("Already committed.");

In fact, looking at the trace this seems to make no sense at all:

2004-08-24 11:47:50,021 TRACE [org.jboss.tm.TransactionImpl] calling sync 1, org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener$TxRemover@18e5ebd
2004-08-24 11:47:50,021 TRACE [org.jboss.tm.TransactionImpl] Before completion done, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=socks//30, BranchQual=], status=STATUS_ACTIVE
2004-08-24 11:47:50,021 TRACE [org.jboss.tm.TransactionImpl] endresources(0): state=1
2004-08-24 11:47:50,021 TRACE [org.jboss.tm.TransactionImpl] endResource(XidImpl [FormatId=257, GlobalId=socks//30, BranchQual=1]) entered: org.jboss.resource.adapter.jdbc.xa.XAManagedConnection@17e982f flag=67108864
2004-08-24 11:47:50,041 TRACE [org.jboss.tm.TransactionImpl] endResource(XidImpl [FormatId=257, GlobalId=socks//30, BranchQual=1]) leaving: org.jboss.resource.adapter.jdbc.xa.XAManagedConnection@17e982f flag=67108864
2004-08-24 11:47:50,041 TRACE [org.jboss.tm.TransactionImpl] One phase commit: One resource.
2004-08-24 11:47:50,041 TRACE [org.jboss.tm.TransactionImpl] Committing resources, resourceStates[0]=3
2004-08-24 11:47:50,151 TRACE [org.jboss.tm.TransactionImpl] delistResource(): Entered, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=socks//30, BranchQual=] status=STATUS_COMMITED

The transaction manager explicitly commits the resources and then calls delistResource() - so of course it is already committed.

I would be most grateful if someone who understands why this is so could clarify it to me.

[adrian.brock]

THis has been fixed for 3.2.6.

The example given by somebody else on a different thread (where the full stacktrace is available) shows that it is just noise in the logs and has no detrimental affect.

[natebowler]

What is the release date of 3.2.6? I have a problem with integrating TopLink into JBoss and JTS/CMP.

This exception being thrown does effect the afterCompletion() callback for my JTSSynchronizationListener causing cache merge to fail.

If this error is benign as far as JBoss is concerned, I can capture it and suppress it until 3.2.6 is released.

Any additional information on this would be appreciated.

Nate

[natebowler]

Actually, it doesn't look like I can just wrap this in a try{}catch{} and ignore it. If I do this, everything seems to work fine, but it looks like the error prevents connections from being returned to the connection pool. Eventually this resource is saturated and everything halts to a stop.

This JBoss/TopLink interaction is internal and I can't see a workaround.

I don't know if you've had any other users talk about this, but I can't see how it is possible for JBoss/TopLink JTS integration to work without this fix.

[patrickvankann]

There appear to be two separate problems being discussed here.
They are:
1) The TransactionManager incorrectly throws an IllegalStateException during delist when it encounters commited transactions, which would be harmless except for the fact that...
2) Connections are not returned to the pool when the exception 1) is thrown.

I have downloaded 3.2.6 RC1 and issue 2) seems to be fixed. Connections are returned to the pool despite 1)

However 1) appears to be not fixed. This is the problem I am concerned with as I had in fact already fixed 2) myself on the 3.2.5 source. Is this scheduled to be fixed in 3.2.6 or a later release? Or is it not a bug?

Thanks in advance for any clarification

[adrian.brock]

The fix was after 3.2.6RC1
http://cvs.sourceforge.net/viewcvs.py/jboss/jbosscx/src/main/org/jboss/resource/connectionmanager/TransactionSynchronizer.java?rev=1.1&view=log
+ related modifications.

If you closed your connections like you are supposed to, you wouldn't even get these
problems.

[natebowler]

Actually, I just downloaded 3.2.6RC2 and I'm noticing the exact same behavior as in 3.2.3. I get the following exception on virtually every statement.

14:17:14,319 ERROR [TxConnectionManager] Error while closing connection handle!org.jboss.resource.JBossResourceException: Error in delist!; - nested throwable: (java.lang.IllegalStateException: Already committed.)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.rethrowAsResourceException(BaseConnectionManager2
.java:113)
......

And I run out of database connections after about 30 seconds into our test suite.

Keep in mind that I am using POJO TopLink configured with a JTS listener. Everything appears to be working properly except for this.

The basic problem is that this exception causes TopLink to exit out of this routine prior to returning the connection to the pool.

I would be happy to dig deeper into this to give an exact order of events that is happening here, however I'm concerned that this issue is not being solved. What can I post or do to help this issue?

Nate

[natebowler]

Could somebody please post what exactly was fixed here? I'm using 3.2.6 final and I'm getting the same error I've always been getting trying to integrate TopLink using JTS and JBoss 3.2.6.

The problem is this: In the afterCompletion() event, TopLink closes the DB connections (returns them to the pool). Every time this happens, I get a stack trace with the message:

org.jboss.resource.JBossResourceException: Error in delist!; - nested throwable: (java.lang.IllegalStateException: Already committed.)
at org.jboss.resource.connectionmanager.BaseConnectionManager2.rethrowAsResourceException(BaseConnectionManager2.java:113)
at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.delist(TxConnectionManager.java:489)
at org.jboss.resource.connectionmanager.TxConnectionManager$TxConnectionEventListener.connectionClosed(TxConnectionManager.java:523)
at org.jboss.resource.adapter.jdbc.BaseWrapperManagedConnection.closeHandle(BaseWrapperManagedConnection.java:320)
at org.jboss.resource.adapter.jdbc.WrappedConnection.close(WrappedConnection.java:123)
at oracle.toplink.internal.databaseaccess.DatabaseAccessor.closeDatasourceConnection(DatabaseAccessor.java:326)


If I remove the TopLink call that closes the connection (UnitOfWork.afterTransaction(boolean, boolean), I get an error in the beforeCompletion() callback that I didn't close the connection.

I can't win here!

Now, TopLink allows you to write your own JTS hook, and this is what I'm doing. TopLink comes with JTS listeners for many platforms be default, but JBoss is not one. I would like to create one that will work, but I have no idea how to make JBoss happy.

Does anyone have any ideas how I can integrate TopLink JTS support into JBoss? If I can't get an answer here, where can I go?

Nate

[patrickvankann]

I have found that adding
<track-connection-by-tx>true</track-connection-by-tx>
to my datasource definition has fixed this problem in both JBoss 3.2.6 and JBoss 3.2.5.

It's a bit frustrating as I have no idea why and only stumbled on the solution due to similar problems I had using JBoss 4.0.