NullPointerException while using XAConnection/PooledConnection in a heavily contended multithreaded scenario

• Key: DERBY-2142
• Type: Bug
• Status: Resolved
• Resolution: Fixed
• Priority: Major
• Assignee: Kathey Marsden
• Reporter: Asif H. Shahid
• Component/s: JDBC
• Affects Version/s: 10.0.2.0, 10.0.2.1, 10.1.1.0, 10.1.2.1, 10.1.3.1, 10.2.1.6
• Fix Version/s: 10.1.3.2, 10.2.2.1, 10.3.3.0, 10.4.1.3

Description

We are using the Derby's Transactional DataSource class ( org.apache.derby.jdbc.EmbeddedXADataSource ) to create a pool of XAConnections in our application.
Whenever a thread in a JTA transaction requests for a SQLConnection , we retrieve an XAConnection from the pool. From the XAConnection , we register the XAResource with the TransactionManager & return a java.sql.Connection to the application.
A class implementing the ConnectionEventListener is registered with the XAConnection to get callback connectionClosed ( ) when the thead closes the java.sql.Connection. In this callback, we invoke XAResource.end & return the XAConnection to our pool so that other threads can use it.

We have encountered NullPointerException , when performing operation on java.sql.Connection.
The stacktrace is as follows
at
org.apache.derby.jdbc.XAStatementControl.<init>(XAStatementControl.java:71)
   at
org.apache.derby.jdbc.EmbedXAConnection.wrapStatement(EmbedXAConnection.java:162)
   at
org.apache.derby.iapi.jdbc.BrokeredConnection.createStatement(Unknown
Source)
   at
com.gemstone.gemfire.internal.datasource.ConnectionPoolingTest$1.run(ConnectionPoolingTest.java:174)
   at java.lang.Thread.run(Thread.java:595)


I have done some debugging on source code of db-derby-10.2.1.6-src & have following explanation of the bug & a suggested fix. However, I want to confirm that it is genuinely a bug & not a problem in our understanding of the Datasource spec behaviour.

Reason for the bug:-

The class EmbedPooledConnection.java stores in the field currentConnectionHandle ( of class BrokeredConnection) a reference of the java.sql.Connection object , being returned to the application,
Now ,whenever the client closes the java.sql.Connection , the code flow is

EmbedPooledConnection.close() --> EmbedPooledConnection.notifyClose().
In the function EmbedPooledConnection.notifyClose(), it notifies my listener ( javax.sql.ConnectionEventListener) ) where I return the XAConnection to the pool ( after deregistering the XAResource).
The last line of EmbedPooledConnection.close() makes the currentConnectionHandle field as null.

The issue here is that javax.sql.ConnectionEventListener.connectionClosed is invoked before making the currentConenctionHandle field as null. Thus XAConnection is returned to the pool , ready for pickup by a new thread. This new thread obtains a java.sql.Connection whose reference gets assigned to the currentConnectionHandle field, meanwhile the previous thread completes the EmbedPooledConnection.close making the newly assigned currentConnectionHandle as null.

Thus a previous thread's close makes a field null of an XAConnection, which has been assigned to a new thread.
The bug is easily reproducible in a multi threaded scenario ( 20 threads or so) with a pool size of around 4 XAConnections so that there is heavy contention on XAConnection.

The fix is to rearrange the code of EmbedPooledConenction.java 's closingConnection () as

bug :
public boolean closingConnection() {
     notifyClose();
     currentConnectionHandle = null;
    return false;

}

bug fix :
public boolean closingConnection() {
     currentConnectionHandle = null;
     notifyClose();
     return false;
}

Comments

[Daniel John Debrunner]

Thanks Asif for the suggested change and detailed analysis. I think you are correct in that it would make sense to re-order the code as you have shown, though possibly some investigation should be made to see if clearing currentConnectionHandle before notifyClose() breaks any assumptions during the notification of the close. Since the listeners can get a handed to the PooledConnection or XAConnection & XAResource we would just have to ensure that any method they can call on those interfaces behaves correctly.

I also think in addition synchronization should be added, probably by making closingConnection() a synchronized method.

[Rick Hillegas]

Adjusting urgency and priority to the standard levels.

[Kathey Marsden]

Asif, do you have a reproduction for this issue?

[Kathey Marsden]

Attached is patch for this issue with Asif's suggetion. (Thank you Asif.) plus making closingConnection synchronized as Dan suggested. I am still kind of fuzzy on what I have to check to make sure PooledConnection, XAConnection and XAResource methods behave correctly, but am trying to figure that out. Any tips would be greatly appreciated. suites.All passed, running derbyall now.

[Mamta A. Satoor]

The ConnectionEventListner javadoc for connectionClosed says
          Notifies this ConnectionEventListener that the application has called the method close on its representation of a pooled connection.

It does not say whether the notification has been sent after the pooled connection is marked closed or before the pooled connection will be marked closed so it seems like it will be ok for us to mark currentConnectionHandle as null and then send the notifications.

[Daniel John Debrunner]

Section 11.2 & 12.5 of JDBC 4 specification indicate that the connection can be returned to the pool when the ConnectionEventListener.connectionClosed() is called, so the pooled connection must be (as Asif suggested) set into the correct state before the callback is made.

[Daniel John Debrunner]

There's some potential for minor cleanup here - notifyClose() is synchronized and only ever called from closingConnection.
So with the current patch the synchronization will be obtained twice. Merging the two methods into one would avoid this and the indication that notifyClose() can be called from other code.

Thanks Dan and Mamta for the input. Dan could you elaborate on your comment:
"Since the listeners can get a handed to the PooledConnection or XAConnection & XAResource we would just have to ensure that any method they can call on those interfaces behaves correctly."

What exactly do I need to be checking?

[Daniel John Debrunner]

>> "Since the listeners can get a handed to the PooledConnection or XAConnection & XAResource we would just have to ensure that any method they can call on those interfaces behaves correctly."
> What exactly do I need to be checking?

Nothing. :-)

It's covered by my recent comment which probably was posted while you were writing yours.

Sections 11.2 and 12.5 state that at the time of the callback they can return the PooledConnection to the pool for re-use, thus at time of the callback the PooledConnection must be disassociated from its previous logical connection. Note the logical connection is being closed, not the pooled connection.

The buggy code passes the PooledConnection to the callbacks in a state where it is still associated to the just closed logical connection, my original concern was what is the expected state of the PooledConnection for the listeners: still associated or disassociated. I hadn't researched the details then.

[Kathey Marsden]

Attached is a revised patch rolling notifyClose into closingConnection().derby-2142_diff2.txt

[Daniel John Debrunner]

Patch 2 seems to have lost the synchronization on the closingConnection() method.

---------------

This comment here is lacking the "why", it's really just describing the code so it's not adding any value.
Why it needs to be before is the important information here.

+ //DERBY-2142 - Null out the connection handle BEFORE notifying listeners.
  currentConnectionHandle = null;

[Kathey Marsden]

Thanks Dan for catching that! I was reeditting with emacs to get the white space right and botched the change #:(

I sure would feel better if I had a repro for this.
running tests now on derby-2142_diff3.txt

[Daniel John Debrunner]

I added a test fixture DataSourceTest.testPooledReuseOnClose that covers this bug. Failed before revision 616141 and passes now on embedded.

It fails for network client, I didn't investigate that, just didn't run the test in that environment. Either a new bug should be added or it should be fixed under this bug.

It would be good if you could make this code comment have value (see earlier issue comment):

+ //DERBY-2142 - Null out the connection handle BEFORE notifying listeners.

adding the why might help ensure the code doesn't get re-ordered in the future and explain it for anyone reading the code.

[Kristian Waagan]

Thanks for adding the test fixture Dan.

I think the client driver might have the same problem as the embedded driver. I'm currently working in that area of the code, and I'll investigate it.
If required, I'd like to attach a patch to this issue.

[Kathey Marsden]

Hi Dan,

Thanks for the fixture. Here is the revised comment, gleaned from the comments in this issue and my understanding of it.


//DERBY-2142-Null out the connection handle BEFORE notifying listeners.
//At time of the callback the PooledConnection must be
//disassociated from its previous logical connection.
//If not, there is a risk that the Pooled
//Connection could be returned to the pool, ready for pickup by a
//new thread. This new thread then might obtain a java.sql.Connection
//whose reference might get assigned to the currentConnectionHandle
//field, meanwhile the previous thread completes the close making
//the newly assigned currentConnectionHandle null, resulting in an NPE.

[Kathey Marsden]

I ported the embedded fix to 10.3, 10.2 and 10.1. If the client fix won't be going to all those branches, it might make sense to make a new issue for that.

[Kathey Marsden]

Resolving this issue for embedded. Opened DERBY-3379 for client.