Hi,
Some time back, before the major re-org of Aarons code,
I suspected a race due that gave me an unexpected
failure doing commit about once every 2-5 million
transactions. I had some suspection about an
unsynchronized map that could cause a race condition,
but adding _any_ kind of code that could verify this
made the race go away. (Sorry, I do not remember
that problem any better.)
Then the re-org came, and the problem went away for
me, but maybe there is still a similar problem in
the new pool code?
Could this be a race condition in BaseConnectionManager
or one of the subclasses, due to the use of
unsynchronized maps?
In any case, be careful about what you assume about
the TM. For example, the current "fast" TM serializes
calls to different Synchronization callbacks, but
other TMs may actually do the different sync callbacks
for the same transaction concurrently, on different
threads. Similar with the XAResource calls prepare(),
commit() and rollback().
As for your current problem: IF the TM does
afterCompletion _before_ beforeCompletion for the
same TX, that _is_ a bad bug in the TM, but I am
not quite convinced about it.
To find out, try adding some extra trace code to
TxCapsule.java, in the doBeforeCompletion() and
doAfterCompletion() methods, like
Logger.debug("Starting beforeCompletion() for tx " + toString())
and
Logger.debug("Done with beforeCompletion() for tx " + toString())
Sorry about this non-answer, but I am out-of-sync
on the pool code, and does not have time to read up
on it.
Best Regards,
Ole Husgaard.
David Jencks wrote:
>
> I should note that this error does not always happen on the first test run,
> but frequently, and I think always on the second or following. (using the
> swinguitestrunner)
>
> On 2001.07.28 14:59:26 -0400 David Jencks wrote:
> > Hi,
> >
> > I think there may be a problem somewhere in jbosscx or maybe the
> > txcapsule
> > or interceptors.
> >
> > jboss 2.5 from cvs yesterday.
> >
> > I changed MinervaDS (using jbosscx) to be named DefaultDS (and renamed
> > DefaultDS to not interfere) and ran the banktest. In testMultiThread I
> > got
> > a npe in this code in BaseConnectionManager.SharedLocalConnection
> >
> > /**
> > * Only return connection to the pool if this is the last handle
> > to
> > * the current ManagedConnection, and there's no TX. This could
> > * be the case, for example, with a UserTransaction where the TX
> > * was committed before the connection was closed.
> > */
> > public void connectionClosed(ConnectionEvent evt) {
> > connectionHandleClosed(evt.getConnectionHandle());
> > if(removeHandle() <= 0) { // If this was the last handle...
> > if(trans == null) { // And the transaction is over...
> > if(pool != null) { // Put back in the pool...
> > pool.releaseObject(con);
> > } else {
> > try { // Or get rid of entirely.
> > con.destroy();
> > <<<<<<<<<<<<========npe here
> > } catch(ResourceException e) {
> > e.printStackTrace();
> > }
> > }
> > clear();
> > }
> > }
> > }
> > Putting some trace code in reveals that Clear() was called on this
> > instance
> > earlier:
> >
> > Default,INFO] ===========================================
> > [Default,INFO] ConnectionClosed - null con
> > [Default,ERROR] java.lang.Exception: clear called
> > [Default,ERROR] at
>org.jboss.pool.connector.BaseConnectionManager$ConnectionListener.clear(BaseConnectionManager.java:240)
> > [Default,ERROR] at
>org.jboss.pool.connector.BaseConnectionManager$SharedLocalConnectionListener.clear(BaseConnectionManager.java:480)
> > [Default,ERROR] at
>org.jboss.pool.connector.BaseConnectionManager$SharedLocalConnectionListener.afterCompletion(BaseConnectionManager.java:398)
> > [Default,ERROR] at
>org.jboss.tm.TxCapsule.doAfterCompletion(TxCapsule.java:1234)
> > [Default,ERROR] at org.jboss.tm.TxCapsule.commit(TxCapsule.java:355)
> > [Default,ERROR] at
>org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:76)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:169)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:63)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:195)
> > [Default,ERROR] at
>org.jboss.ejb.EntityContainer.invoke(EntityContainer.java:392)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.jrmp.server.JRMPContainerInvoker.invoke(JRMPContainerInvoker.java:445)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.jrmp.interfaces.GenericProxy.invokeContainer(GenericProxy.java:339)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.jrmp.interfaces.EntityProxy.invoke(EntityProxy.java:133)
> > [Default,ERROR] at $Proxy28.withdraw(Unknown Source)
> > [Default,ERROR] at
>org.jboss.test.bank.ejb.TellerBean.transfer(TellerBean.java:37)
> > [Default,ERROR] at java.lang.reflect.Method.invoke(Native Method)
> > [Default,ERROR] at
>org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:572)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:97)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.TxInterceptorBMT.invoke(TxInterceptorBMT.java:62)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:67)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:195)
> > [Default,ERROR] at
>org.jboss.ejb.StatelessSessionContainer.invoke(StatelessSessionContainer.java:282)
> > [Default,ERROR] at
>org.jboss.ejb.plugins.jrmp.server.JRMPContainerInvoker.invoke(JRMPContainerInvoker.java:364)
> > [Default,ERROR] at java.lang.reflect.Method.invoke(Native Method)
> > [Default,ERROR] at
>sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:241)
> > [Default,ERROR] at sun.rmi.transport.Transport$1.run(Transport.java:152)
> > [Default,ERROR] at java.security.AccessController.doPrivileged(Native
> > Method)
> > [Default,ERROR] at
>sun.rmi.transport.Transport.serviceCall(Transport.java:148)
> > [Default,ERROR] at
>sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:465)
> > [Default,ERROR] at
>sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:706)
> > [Default,ERROR] at java.lang.Thread.run(Thread.java:484)
> >
> >
> >
> >
> > and the connectionClosed trace:
> >
> > [EntityInstanceInterceptor,ERROR] Store failed
> > java.rmi.ServerException: Store failed; nested exception is:
> > java.lang.NullPointerException
> > java.lang.NullPointerException
> > at
>org.jboss.pool.connector.BaseConnectionManager$SharedLocalConnectionListener.connectionClosed(BaseConnectionManager.java:450)
> > at
>org.jboss.pool.connector.jdbc.BaseManagedConnection.fireConnectionEvent(BaseManagedConnection.java:69)
> > at
>org.jboss.pool.connector.jdbc.JDBCManagedConnection$1.objectClosed(JDBCManagedConnection.java:48)
> > at
>org.jboss.pool.jdbc.ConnectionInPool.firePoolEvent(ConnectionInPool.java:222)
> > at org.jboss.pool.jdbc.ConnectionInPool.close(ConnectionInPool.java:324)
> > at
>org.jboss.ejb.plugins.jaws.jdbc.JDBCCommand.jdbcExecute(JDBCCommand.java:190)
> > at
>org.jboss.ejb.plugins.jaws.jdbc.JDBCStoreEntityCommand.execute(JDBCStoreEntityCommand.java:97)
> > at
>org.jboss.ejb.plugins.jaws.JAWSPersistenceManager.storeEntity(JAWSPersistenceManager.java:169)
> > at
>org.jboss.ejb.plugins.CMPPersistenceManager.storeEntity(CMPPersistenceManager.java:388)
> > at
>org.jboss.ejb.plugins.EntitySynchronizationInterceptor$InstanceSynchronization.beforeCompletion(EntitySynchronizationInterceptor.java:416)
> > at org.jboss.tm.TxCapsule.doBeforeCompletion(TxCapsule.java:1210)
> > at org.jboss.tm.TxCapsule.commit(TxCapsule.java:304)
> > at org.jboss.tm.TransactionImpl.commit(TransactionImpl.java:76)
> > at
>org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:169)
> > at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:63)
> > at
>org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128)
> > at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:195)
> > at org.jboss.ejb.EntityContainer.invoke(EntityContainer.java:392)
> > at
>org.jboss.ejb.plugins.jrmp.server.JRMPContainerInvoker.invoke(JRMPContainerInvoker.java:445)
> > at
>org.jboss.ejb.plugins.jrmp.interfaces.GenericProxy.invokeContainer(GenericProxy.java:339)
> > at
>org.jboss.ejb.plugins.jrmp.interfaces.EntityProxy.invoke(EntityProxy.java:133)
> > at $Proxy28.deposit(Unknown Source)
> > at org.jboss.test.bank.ejb.TellerBean.transfer(TellerBean.java:38)
> > at java.lang.reflect.Method.invoke(Native Method)
> > at
>org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:572)
> > at
>org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:97)
> > at
>org.jboss.ejb.plugins.AbstractTxInterceptorBMT.invokeNext(AbstractTxInterceptorBMT.java:144)
> > at org.jboss.ejb.plugins.TxInterceptorBMT.invoke(TxInterceptorBMT.java:62)
> > at
>org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:67)
> > at
>org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128)
> > at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:195)
> > at
>org.jboss.ejb.StatelessSessionContainer.invoke(StatelessSessionContainer.java:282)
> > at
>org.jboss.ejb.plugins.jrmp.server.JRMPContainerInvoker.invoke(JRMPContainerInvoker.java:364)
> > at java.lang.reflect.Method.invoke(Native Method)
> > at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:241)
> > at sun.rmi.transport.Transport$1.run(Transport.java:152)
> > at java.security.AccessController.doPrivileged(Native Method)
> > at sun.rmi.transport.Transport.serviceCall(Transport.java:148)
> > at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:465)
> > at
>sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:706)
> > at java.lang.Thread.run(Thread.java:484)
> >
> >
> > The clear() comes from a doAfterCompletion call in txcapsule, and the
> > connectionClose later from a doBeforeCompletion call, presumably from the
> > same txcapsule. My first thought is that two transactions are sharing
> > the
> > same txcapsule simultaneously, although I haven't proved this.
> >
> >
> > Incidently, I experienced something perhaps related while working on my
> > firebird jca/jdbc driver. I had to set transaction isolation to snapshot
> > (more or less serializable) for banktest or I got a deadlock from the
> > database. In that case the problem occurred in testMultiThread2.
> >
> > So..
> >
> > Does this happen for other people?
> >
> > Does anyone have an immediate idea of how to fix it? (I'll keep looking)
> >
> >
> >
> > And as a final note....
> >
> > I find it hard to understand what is intended in the synchronization code
> > in this area of jboss. There is at least one special purpose language,
> > cool, designed explicitly for describing (more or less declaratively)
> > synchronization constraints on (unsynchronized) code. I believe it is
> > used
> > in AspectJ. I'm not sure it is worth actually using AspectJ to separate
> > the logic and synchronization aspects for jboss, but I think it might be
> > really helpful if the experts (marc) specified the intention of the
> > synchronization code in such a language. Here's an example of cool for a
> > multithreaded stack:
> >
> > coordinator Stack
> > { selfex push, pop;
> > mutex {push, pop};
> > condition full=false, empty=true;
> >
> > guard push:
> > requires !full;
> > onexit
> > { if (empty) empty=false;
> > if (top==max_top) full=true;
> > }
> > guard pop;
> > requires !empty;
> > onexit
> > { if (full) full=false;
> > if (top==empty_top) empty=true;
> > }
> > }
> >
> >
> > At least the selfex and mutex portions would be really handy for my
> > understanding.
> >
> >
> > Thanks
> >
> > david jencks
> >
> > and as a postscript here's how I got the traces:
> >
> > Index: BaseConnectionManager.java
> > ===================================================================
> > RCS file:
>/cvsroot/jboss/jbosspool/src/main/org/jboss/pool/connector/BaseConnectionManager.java,v
> > retrieving revision 1.1.1.1
> > diff -u -r1.1.1.1 BaseConnectionManager.java
> > --- BaseConnectionManager.java 2001/05/15 07:58:24 1.1.1.1
> > +++ BaseConnectionManager.java 2001/07/28 18:50:18
> > @@ -166,6 +166,8 @@
> > protected ObjectPool pool;
> > protected ManagedConnection con;
> >
> > + public Exception conclosedexc = null;
> > +
> > protected ConnectionListener(ObjectPool pool, ManagedConnection
> > con) {
> > this.pool = pool;
> > this.con = con;
> > @@ -235,6 +237,7 @@
> > } catch(Exception e) {}
> > pool = null;
> > con = null;
> > + conclosedexc = new Exception("clear called");
> > }
> > }
> >
> > @@ -407,6 +410,9 @@
> > * the connection is destroyed and this listener is cleared.
> > */
> > public void connectionErrorOccurred(ConnectionEvent evt) {
> > + System.out.println("===========================================");
> > + System.out.println("Connection Error Occurred");
> > + System.out.println("===========================================");
> > try {
> > local.rollback();
> > } catch(Exception e) {}
> > @@ -423,6 +429,17 @@
> > * was committed before the connection was closed.
> > */
> > public void connectionClosed(ConnectionEvent evt) {
> > + if (con == null) {
> > + System.out.println("===========================================");
> > + System.out.println("ConnectionClosed - null con");
> > + if (conclosedexc == null) {
> > + System.out.println("clear not called");
> > + }
> > + else {
> > + conclosedexc.printStackTrace();
> > + }
> > + System.out.println("===========================================");
> > + }
> > connectionHandleClosed(evt.getConnectionHandle());
> > if(removeHandle() <= 0) { // If this was the last handle...
> > if(trans == null) { // And the transaction is over...
> >
> >
> >
> >
> >
> > _______________________________________________
> > Jboss-development mailing list
> > [EMAIL PROTECTED]
> > http://lists.sourceforge.net/lists/listinfo/jboss-development
> >
> >
>
> _______________________________________________
> Jboss-development mailing list
> [EMAIL PROTECTED]
> http://lists.sourceforge.net/lists/listinfo/jboss-development
_______________________________________________
Jboss-development mailing list
[EMAIL PROTECTED]
http://lists.sourceforge.net/lists/listinfo/jboss-development
