Hey Kathey, that for taking the time to respond. Unfortunately we had to
bounce the network server and not it is going through the derby recovery logs.
18000 of them at one every 10 seconds. So 5 hours of down time ☹
What seems to trigger the issue is that we get into a situation where we have a
transaction that is pretty long and a lock timeout occurs. Something happens
in Derby during the cleanup of the locks however. We also have
derby.properties setup to rollback an XA transaction if it takes a very long
time as well:
derby.locks.waitTimeout=60
derby.jdbc.xaTransactionTimeout=1800
It seems that derby got into a deadlock:
Found one Java-level deadlock:
=============================
"DRDAConnThread_34":
waiting to lock monitor 0x0000000104b14d18 (object 0xfffffffd9090f058, a
org.apache.derby.jdbc.XATransactionState),
which is held by "Timer-0"
"Timer-0":
waiting to lock monitor 0x00000001038b96e8 (object 0xfffffffd9090d8b0, a
org.apache.derby.impl.jdbc.EmbedConnection40),
which is held by "DRDAConnThread_34"
Java stack information for the threads listed above:
===================================================
"DRDAConnThread_34":
at org.apache.derby.jdbc.XATransactionState.cleanupOnError(Unknown Source)
- waiting to lock <0xfffffffd9090f058> (a
org.apache.derby.jdbc.XATransactionState)
at
org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown
Source)
at
org.apache.derby.impl.jdbc.TransactionResourceImpl.cleanupOnError(Unknown
Source)
at
org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown
Source)
at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown
Source)
at org.apache.derby.impl.jdbc.ConnectionChild.handleException(Unknown
Source)
at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown
Source)
- locked <0xfffffffd9090d8b0> (a
org.apache.derby.impl.jdbc.EmbedConnection40)
at
org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Unknown
Source)
at org.apache.derby.impl.jdbc.EmbedPreparedStatement.execute(Unknown
Source)
at org.apache.derby.iapi.jdbc.BrokeredPreparedStatement.execute(Unknown
Source)
at org.apache.derby.impl.drda.DRDAStatement.execute(Unknown Source)
at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTTobjects(Unknown
Source)
at org.apache.derby.impl.drda.DRDAConnThread.parseEXCSQLSTT(Unknown Source)
at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown
Source)
at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source)
"Timer-0":
at org.apache.derby.impl.jdbc.EmbedConnection.xa_rollback(Unknown Source)
- waiting to lock <0xfffffffd9090d8b0> (a
org.apache.derby.impl.jdbc.EmbedConnection40)
at org.apache.derby.jdbc.XATransactionState.cancel(Unknown Source)
- locked <0xfffffffd9090f058> (a org.apache.derby.jdbc.XATransactionState)
at
org.apache.derby.jdbc.XATransactionState$CancelXATransactionTask.run(Unknown
Source)
at java.util.TimerThread.mainLoop(Timer.java:555)
at java.util.TimerThread.run(Timer.java:505)
Found 1 deadlock.
So we can see from this the locking pattern that is causing the issue. The
timer task locks the XATransactionState and then attempts to lock the
EmbedConnectio40 and the cleanupOError is locking the EmbedConnection40 and
then the XATransactionState. Viola deadlock.
I actually wrote an application to go through and create an Xid and attempt to
rollback or commit the transaction but that also hit this lock problem:
System.out.println("Connection to the database");
XAConnection xaConnection = null;
Connection conn = null;
String driver = "org.apache.derby.jdbc.ClientDataSource";
ClientXADataSource ds = new ClientXADataSource();
ds.setDatabaseName("csemdb");
ds.setServerName("localhost");
ds.setPortNumber(1527);
Class.forName(driver);
xaConnection = ds.getXAConnection("CSEM", "CSEM");
conn = xaConnection.getConnection();
System.out.println("Transactions before");
dumpTransactionTable(conn);
XAResource xaResource = xaConnection.getXAResource();
System.out.println("Scanning for XA Transactions");
for (Xid xid :
xaResource.recover(XAResource.TMSTARTRSCAN|XAResource.TMENDRSCAN)) {
// for (Xid xid : xaResource.recover(XAResource.TMNOFLAGS)) {
System.out.println("Rolling back " + xid.toString());
xaResource.rollback(xid);
System.out.println("Rolled back " + xid.toString());
}
System.out.println("Transactions after");
dumpTransactionTable(conn);
System.out.println("Now trying the hard way");
List<MyXid> myXids = getGlobalTransactions(conn);
for (MyXid xid : myXids) {
System.out.println("commiting " + xid.toString());
xaResource.commit(xid, true);
}
System.out.println("Transactions after");
dumpTransactionTable(conn);
In my test case, I am able to get the database into the state where this a XA
transaction hanging around and the above code did clear it, but this test case
did not get the derby engine into the deadlock. My hope at the customer site
was to be able to clear the transaction with this application and then derby
would start munching on its transaction log files and not have 18000 of these
around. But alas the deadlock stopped that problem as well. So a restart
need to occur and now derby processing those logs one at a time taking about 10
seconds each.
I will log a jira issue on this and also will look at the source to see if I
can come up with a fix for the locking pattern.
From: Katherine Marsden [mailto:[email protected]]
Sent: Friday, March 25, 2016 11:43 AM
To: [email protected]
Subject: Re: Need help with clearing a XA transaction ! Important
It's been quite a while, and I don't even have Derby setup but I'll ask some
questions.
Do you see the same behavior with embedded?
With Network Server, in your test environment, does the transaction persist if
you bounce network server?
It seems to me there was a command to list the network server active
connections. Can you run that and see if the session is still there?
Kathey
On Mar 25, 2016, at 7:48 AM, Bergquist, Brett
<[email protected]<mailto:[email protected]>> wrote:
I have a database with a stuck XA transaction. Derby 10.9.
I am able to reproduce this problem with two test programs. In the first
program I do:
try {
System.out.println("Connection to the database");
XAConnection xaConnection = null;
Connection conn = null;
String driver = "org.apache.derby.jdbc.ClientDataSource";
ClientXADataSource ds = new ClientXADataSource();
ds.setDatabaseName("csemdb");
ds.setServerName("localhost");
ds.setPortNumber(1527);
Class.forName(driver);
xaConnection = ds.getXAConnection("CSEM", "CSEM");
conn = xaConnection.getConnection();
System.out.println("creating a transaction");
XAResource xaResource = xaConnection.getXAResource();
Xid xid = new MyXid(100, new byte[]{0x01}, new byte[]{0x02});
xaResource.start(xid, XAResource.TMNOFLAGS);
createTransaction(conn);
xaResource.end(xid, XAResource.TMSUCCESS);
System.exit(1);
} catch (XAException ex) {
Logger.getLogger(RollbackTransactionsTest.class.getName()).log(Level.SEVERE,
null, ex);
} catch (SQLException ex) {
Logger.getLogger(RollbackTransactionsTest.class.getName()).log(Level.SEVERE,
null, ex);
} catch (ClassNotFoundException ex) {
Logger.getLogger(RollbackTransactionsTest.class.getName()).log(Level.SEVERE,
null, ex);
}
Basically I create a XA transaction, start it, execute an insert statement, end
it, but never prepare or commit it and the exit the application. The leaves a
transaction in the database:
XID GLOBAL_XID USERNAME TYPE STATUS
FIRST_INSTANT SQL_TEXT
132775 (100,01,02) CSEM UserTransaction ACTIVE
(108,782111) <null>
I try to rollback this transaction with another program but it does not even
see the transaction:
try {
System.out.println("Connection to the database");
XAConnection xaConnection = null;
Connection conn = null;
String driver = "org.apache.derby.jdbc.ClientDataSource";
ClientXADataSource ds = new ClientXADataSource();
ds.setDatabaseName("csemdb");
ds.setServerName("localhost");
ds.setPortNumber(1527);
Class.forName(driver);
xaConnection = ds.getXAConnection("CSEM", "CSEM");
conn = xaConnection.getConnection();
System.out.println("Transactions before");
dumpTransactionTable(conn);
XAResource xaResource = xaConnection.getXAResource();
System.out.println("Scanning for XA Transactions");
for (Xid xid :
xaResource.recover(XAResource.TMSTARTRSCAN|XAResource.TMENDRSCAN)) {
System.out.println("Rolling back " + xid.toString());
xaResource.rollback(xid);
System.out.println("Rolled back " + xid.toString());
}
System.out.println("Transactions after");
dumpTransactionTable(conn);
} catch (XAException ex) {
Logger.getLogger(RollbackTransactions.class.getName()).log(Level.SEVERE, null,
ex);
} catch (SQLException ex) {
Logger.getLogger(RollbackTransactions.class.getName()).log(Level.SEVERE, null,
ex);
} catch (ClassNotFoundException ex) {
Logger.getLogger(RollbackTransactions.class.getName()).log(Level.SEVERE, null,
ex);
}
This shows this when run:
Connection to the database
Transactions before
XID,GLOBAL_XID,USERNAME,TYPE,STATUS,FIRST_INSTANT,SQL_TEXT
132775,(100,01,02),CSEM,UserTransaction,ACTIVE,(108,782111),null
Scanning for XA Transactions
Transactions after
XID,GLOBAL_XID,USERNAME,TYPE,STATUS,FIRST_INSTANT,SQL_TEXT
132775,(100,01,02),CSEM,UserTransaction,ACTIVE,(108,782111),null
So the transaction is seen in the syscs_diag.transaction_table, but not seen by
the XAResource.recover.
Any help will be greatly appreciated as this has occurred in a production
environment and because of such, the derby transaction logs are multiplying.
Shutting down the system and restarting will take many hours for derby to
process the transaction logs.
________________________________
Canoga Perkins
20600 Prairie Street
Chatsworth, CA 91311
(818) 718-6300
This e-mail and any attached document(s) is confidential and is intended only
for the review of the party to whom it is addressed. If you have received this
transmission in error, please notify the sender immediately and discard the
original message and any attachment(s).
________________________________
Canoga Perkins
20600 Prairie Street
Chatsworth, CA 91311
(818) 718-6300
This e-mail and any attached document(s) is confidential and is intended only
for the review of the party to whom it is addressed. If you have received this
transmission in error, please notify the sender immediately and discard the
original message and any attachment(s).
