I'm having some trouble getting client side tracing to work. The connections
are managed by Glassfish connection pool so I don't know where to set the
traceDirectory and traceLevel properties. Can these be specified as
properties like the password, etc.
Just a little more info as well.
Once of the threads got this error:
[#|2011-12-21T10:28:54.224-0800|INFO|sun-appserver2.1|javax.enterprise.system.container.ejb|_ThreadID=20;_ThreadName=httpSSLWorkerThread-8080-0;|
javax.ejb.TransactionRolledbackLocalException: Exception thrown from bean;
nested exception is: Exception [EclipseLink-4002] (Eclipse Persistence Services
- 1.1.3.v20091002-r5404): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLTransactionRollbackException: DERBY SQL error:
SQLCODE: -1, SQLSTATE: 40XL2, SQLERRMC:
There was a long time where a lock could not be obtained and then next thing
reported by the thread is:
[#|2011-12-21T10:28:54.269-0800|WARNING|sun-appserver2.1|javax.enterprise.system.core.transaction|_ThreadID=20;_ThreadName=httpSSLWorkerThread-8080-0;_RequestID=5e6bd3ac-516f-4d96-8018-baf3ce187f69;|JTS5064:
Unexpected exception occurred while delisting the resource
org.apache.derby.client.am.XaException: XAER_RMFAIL : No current connection.
at
org.apache.derby.client.net.NetXAResource.throwXAException(NetXAResource.java:766)
at
org.apache.derby.client.net.NetXAResource.throwXAException(NetXAResource.java:663)
at
org.apache.derby.client.net.NetXAResource.connectionClosedFailure(NetXAResource.java:933)
at
org.apache.derby.client.net.NetXAResource.end(NetXAResource.java:230)
at com.sun.gjc.spi.XAResourceImpl.end(XAResourceImpl.java:100)
at
com.sun.jts.jta.TransactionState.rollback(TransactionState.java:199)
at
com.sun.jts.jtsxa.OTSResourceImpl.rollback(OTSResourceImpl.java:311)
....
And then later:
[#|2011-12-21T10:28:54.380-0800|SEVERE|sun-appserver2.1|javax.enterprise.system.core.transaction|_ThreadID=20;_ThreadName=httpSSLWorkerThread-8080-0;org.omg.CORBA.INTERNAL:
vmcid: 0x0 minor code: 0 completed:
Maybe;rollback;_RequestID=5e6bd3ac-516f-4d96-8018-baf3ce187f69;|JTS5031:
Exception [org.omg.CORBA.INTERNAL: vmcid: 0x0 minor code: 0 completed:
Maybe] on Resource [rollback] operation.|#]
And then later:
[#|2011-12-21T10:28:54.382-0800|WARNING|sun-appserver2.1|javax.enterprise.resource.resourceadapter|_ThreadID=20;_ThreadName=httpSSLWorkerThread-8080-0;_RequestID=5e6bd3ac-516f-4d96-8018-baf3ce187f69;|RAR7115:
Unable to set ClientInfo for connection
java.sql.SQLClientInfoException: No current connection.
at
org.apache.derby.client.net.NetConnection40.setClientInfo(NetConnection40.java:274)
at
org.apache.derby.client.am.LogicalConnection40.setClientInfo(LogicalConnection40.java:254)
at
com.sun.gjc.spi.jdbc40.ConnectionHolder40.setClientInfo(ConnectionHolder40.java:304)
at
com.sun.gjc.spi.jdbc40.ConnectionHolder40.close(ConnectionHolder40.java:513)
at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeDatasourceConnection(DatabaseAccessor.java:450)
at
org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeConnection(DatasourceAccessor.java:488)
Another thread saw:
[#|2011-12-21T10:28:54.315-0800|INFO|sun-appserver2.1|javax.enterprise.system.container.ejb|_ThreadID=75;_ThreadName=httpSSLWorkerThread-8080-3;|
javax.ejb.TransactionRolledbackLocalException: Exception thrown from bean;
nested exception is: Exception [EclipseLink-4002] (Eclipse Persistence Services
- 1.1.3.v20091002-r5404): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: java.sql.SQLTransactionRollbackException: DERBY SQL error:
SQLCODE: -1, SQLSTATE: 40XL2, SQLERRMC:
Wed Dec 21 10:28:54 PST 2011
And then saw:
[#|2011-12-21T10:28:54.326-0800|WARNING|sun-appserver2.1|javax.enterprise.system.core.transaction|_ThreadID=75;_ThreadName=httpSSLWorkerThread-8080-3;_RequestID=b2c68a79-1eb1-497d-aab5-f3875f656ed4;|JTS5064:
Unexpected exception occurred while delisting the resource
java.lang.NullPointerException
at
org.apache.derby.client.net.Request.sendBytes(Request.java:1289)
at org.apache.derby.client.net.Request.flush(Request.java:1283)
at
org.apache.derby.client.net.NetAgent.sendRequest(NetAgent.java:393)
at
org.apache.derby.client.net.NetAgent.flush_(NetAgent.java:273)
at
org.apache.derby.client.am.Agent.flowOutsideUOW(Agent.java:196)
at
org.apache.derby.client.net.NetXAResource.end(NetXAResource.java:242)
at com.sun.gjc.spi.XAResourceImpl.end(XAResourceImpl.java:100)
and then saw:
[#|2011-12-21T10:28:54.389-0800|WARNING|sun-appserver2.1|javax.enterprise.resource.resourceadapter|_ThreadID=75;_ThreadName=httpSSLWorkerThread-8080-3;_RequestID=b2c68a79-1eb1-497d-aab5-f3875f656ed4;|RAR7115:
Unable to set ClientInfo for connection
java.sql.SQLClientInfoException: No current connection.
at
org.apache.derby.client.net.NetConnection40.setClientInfo(NetConnection40.java:274)
at
org.apache.derby.client.am.LogicalConnection40.setClientInfo(LogicalConnection40.java:254)
at
com.sun.gjc.spi.jdbc40.ConnectionHolder40.setClientInfo(ConnectionHolder40.java:304)
at
com.sun.gjc.spi.jdbc40.ConnectionHolder40.close(ConnectionHolder40.java:513)
at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeDatasourceConnection(DatabaseAccessor.java:450)
at
org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeConnection(DatasourceAccessor.java:488)
at
org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.closeConnection(DatabaseAccessor.java:473)
at
org.eclipse.persistence.internal.databaseaccess.DatasourceAccessor.closeJTSConnection(DatasourceAccessor.java:174)
So it looks like something is closing the internals of the connections in not a
good way as the NullPointerException above can only occur if the
socketOutputStream passed to sendBytes is null.
Note that the Glassfish database connection pool is setup to close all
connection on a connection error.
From: Bergquist, Brett [mailto:[email protected]]
Sent: Wednesday, December 21, 2011 11:34 AM
To: [email protected]
Subject: RE: Problem with a deadlock with Derby 10.8.1.2 and Glassfish V2.1.1
I cannot upgrade to 10.8.8.2 at this point as this is in production without
upgrade possibility. A also at this point, I don't want to change to many
variables and have the problem disappear. Right now I can get it to reproduce
pretty readily.
I was able to connect with a debug and indeed the thread is blocking on the
"java.net.SocketInputStream.read". Through the debugger if I force an
interrupt, I returns from the socket call with an I/O error. So does this mean
that the problem is in the derby server side since the socket is valid and not
closed before I issue the interrupt?
I am going to enable tracing and see what I find.
From: Katherine Marsden [mailto:[email protected]]
Sent: Wednesday, December 21, 2011 11:14 AM
To: [email protected]
Subject: Re: Problem with a deadlock with Derby 10.8.1.2 and Glassfish V2.1.1
On 12/21/2011 6:14 AM, Bergquist, Brett wrote:
I have a problem with a deadlock with Derby 10.8.1.2 and Glassfish V2.1.1 but
at this point I cannot tell if it is a Derby problem or a Glassfish problem so
I am looking for some guidance.
A database pool is created using the "org.apache.derby.jdbc.ClientXADataSource"
XADataSource. Connection validation is turned on and uses "auto-commit" to
validate the connection and attempts to close all connections on any validation
failure.
The deadlock is triggered when I have a couple of transactions that cause a
Derby locks deadlock. Deadlock detection and tracing is turned on in Derby and
it correctly detects the locking deadlock and terminates one of the
transactions. Soon after this, however, Glassfish becomes stuck. Here is
the only reference to Derby in the "jstack" output of Glassfish:
"PMCollectionActivationManager.newPmTestResult" daemon prio=3
tid=0x0000000103926800 nid=0xaf runnable [0xfffffffc218fa000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at org.apache.derby.client.net.Reply.fill(Unknown Source)
at
org.apache.derby.client.net.Reply.ensureALayerDataInBuffer(Unknown Source)
at org.apache.derby.client.net.Reply.readDssHeader(Unknown
Source)
at
org.apache.derby.client.net.Reply.startSameIdChainParse(Unknown Source)
at
org.apache.derby.client.net.NetXAConnectionReply.readLocalXACommit(Unknown
Source)
at
org.apache.derby.client.net.NetXAConnection.readLocalXACommit_(Unknown Source)
at
org.apache.derby.client.net.NetXAConnection.readCommit(Unknown Source)
at
org.apache.derby.client.net.NetConnection.readXACommit_(Unknown Source)
at org.apache.derby.client.am.Connection.readCommit(Unknown
Source)
at org.apache.derby.client.am.Connection.readAutoCommit(Unknown
Source)
at org.apache.derby.client.am.Connection.flowClose(Unknown
Source)
at
org.apache.derby.client.am.Connection.closeResourcesX(Unknown Source)
at org.apache.derby.client.am.Connection.closeResources(Unknown
Source)
- locked <0xfffffffc91831e18> (a
org.apache.derby.client.net.NetConnection40)
at
org.apache.derby.client.net.NetConnection.closeResources(Unknown Source)
- locked <0xfffffffc91831e18> (a
org.apache.derby.client.net.NetConnection40)
at org.apache.derby.client.ClientPooledConnection.close(Unknown
Source)
- locked <0xfffffffc91831cf8> (a
org.apache.derby.client.ClientXAConnection40)
at org.apache.derby.client.ClientXAConnection.close(Unknown
Source)
- locked <0xfffffffc91831cf8> (a
org.apache.derby.client.ClientXAConnection40)
at
com.sun.gjc.spi.ManagedConnection.destroy(ManagedConnection.java:276)
First thing I would suggest is move up to 10.8.2.2 just to get running on the
latest.
I wonder is there indication in the derby.log what went wrong here? If not, I
would suggest enabling client and server side DRDA tracing to get a clue as to
what went wrong with the protocol here.
http://wiki.apache.org/db-derby/ProtocolDebuggingTips
Maybe there is some issue with the logic that dermines if autocommit will
generate flow.
// precondition: autoCommit_ is true
void readAutoCommit() throws SqlException {
if (willAutoCommitGenerateFlow()) {
readCommit();
}
}
public boolean willAutoCommitGenerateFlow() throws
org.apache.derby.client.am.SqlException {
if (!autoCommit_) {
return false;
}
if (! allowLocalCommitRollback_()) {
return false;
}
return true;
}
