glassfish
  1. glassfish
  2. GLASSFISH-11094

SessionContext objects are caching resources that have been destroyed by the resource pool

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Incomplete
    • Affects Version/s: 9.1peur2
    • Fix Version/s: 9.1peur2
    • Component/s: jca
    • Labels:
      None
    • Environment:

      Operating System: All
      Platform: Linux

    • Issuezilla Id:
      11,094
    • Status Whiteboard:
      Hide

      v3_exclude

      Show
      v3_exclude

      Description

      The short story :

      I believe the pool of SessionContext(SessionContextImpl) objects are caching
      resources(via the EJBContextImpl base class) that have been destroyed by the
      resource pool

      The long story :

      we use sjsas 9.1 update 2 and get the following warning intermittedly in our
      server.log file :

      [#|2009-11-18T07:42:40.131+0200|WARNING|sun-appserver9.1|javax.enterprise.system.core.transaction|_ThreadID=763;_ThreadName=p:
      thread-pool-1; w:
      34472;_RequestID=cb02a7e8-2b02-4436-9dd8-1a3fb3e36923;|JTS5041: The resource
      manager is doing work outside a global transaction
      javax.transaction.xa.XAException
      at
      com.ibm.as400.access.AS400JDBCXAResource.throwXAException(AS400JDBCXAResource.java:970)
      at
      com.ibm.as400.access.AS400JDBCXAResource.start(AS400JDBCXAResource.java:938)
      at com.sun.gjc.spi.XAResourceImpl.start(XAResourceImpl.java:222)
      at
      com.sun.jts.jta.TransactionState.startAssociation(TransactionState.java:305)
      at com.sun.jts.jta.TransactionImpl.enlistResource(TransactionImpl.java:205)
      at
      com.sun.enterprise.distributedtx.J2EETransaction.enlistResource(J2EETransaction.java:562)
      at
      com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.enlistResource(J2EETransactionManagerImpl.java:372)
      at
      com.sun.enterprise.distributedtx.J2EETransactionManagerOpt.enlistResource(J2EETransactionManagerOpt.java:144)
      at
      com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.enlistComponentResources(J2EETransactionManagerImpl.java:563)
      at
      com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.enlistComponentResources(J2EETransactionManagerImpl.java:404)
      at com.sun.ejb.containers.BaseContainer.startNewTx(BaseContainer.java:3350)
      at com.sun.ejb.containers.BaseContainer.preInvokeTx(BaseContainer.java:3270)
      at com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:1244)
      at
      com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:202)
      at
      com.sun.ejb.containers.EJBObjectInvocationHandlerDelegate.invoke(EJBObjectInvocationHandlerDelegate.java:77)
      at $Proxy199.execDroid(Unknown Source)
      at sun.reflect.GeneratedMethodAccessor246.invoke(Unknown Source)
      at
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:597)
      at
      com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:154)
      at
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatchToServant(CorbaServerRequestDispatcherImpl.java:687)
      at
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatch(CorbaServerRequestDispatcherImpl.java:227)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequestRequest(CorbaMessageMediatorImpl.java:1846)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:1706)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleInput(CorbaMessageMediatorImpl.java:1088)
      at
      com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:223)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:806)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.dispatch(CorbaMessageMediatorImpl.java:563)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.doWork(CorbaMessageMediatorImpl.java:2567)
      at
      com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)

      which is always followed by

      [#|2009-11-18T07:42:40.424+0200|INFO|sun-appserver9.1|javax.enterprise.system.container.ejb|_ThreadID=763;_ThreadName=p:
      thread-pool-1; w: 34472;|
      javax.ejb.EJBException: Unable to complete container-managed transaction.;
      nested exception is: javax.transaction.SystemException: org.omg.CORBA.INTERNAL:
      JTS5031: Exception [org.omg.CORBA.INTERNAL: vmcid: 0x0 minor code: 0
      completed: Maybe] on Resource [rollback] operation. vmcid: 0x0 minor code: 0
      completed:
      No
      javax.transaction.SystemException: org.omg.CORBA.INTERNAL: JTS5031: Exception
      [org.omg.CORBA.INTERNAL: vmcid: 0x0 minor code: 0 completed: Maybe] on
      Resource [rollback] operation. vmcid: 0x0 minor code: 0 completed: No
      at
      com.sun.jts.jta.TransactionManagerImpl.commit(TransactionManagerImpl.java:321)
      at
      com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.commit(J2EETransactionManagerImpl.java:1004)
      at
      com.sun.enterprise.distributedtx.J2EETransactionManagerOpt.commit(J2EETransactionManagerOpt.java:397)
      at
      com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:3792)
      at
      com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3571)
      at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1354)
      at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1316)
      at
      com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:210)
      at
      com.sun.ejb.containers.EJBObjectInvocationHandlerDelegate.invoke(EJBObjectInvocationHandlerDelegate.java:77)
      at $Proxy199.execDroid(Unknown Source)
      at sun.reflect.GeneratedMethodAccessor246.invoke(Unknown Source)
      at
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:597)
      at
      com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:154)
      at
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatchToServant(CorbaServerRequestDispatcherImpl.java:687)
      at
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatch(CorbaServerRequestDispatcherImpl.java:227)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequestRequest(CorbaMessageMediatorImpl.java:1846)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:1706)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleInput(CorbaMessageMediatorImpl.java:1088)
      at
      com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:223)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:806)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.dispatch(CorbaMessageMediatorImpl.java:563)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.doWork(CorbaMessageMediatorImpl.java:2567)
      at
      com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
      javax.ejb.EJBException: Unable to complete container-managed transaction.;
      nested exception is: javax.transaction.SystemException: org.omg.CORBA.INTERNAL:
      JTS5031: Exception [org.omg.CORBA.INTERNAL: vmcid: 0x0 minor code: 0
      completed: Maybe] on Resource [rollback] operation. vmcid: 0x0 minor code: 0
      completed:
      No
      at
      com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:3803)
      at
      com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:3571)
      at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1354)
      at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1316)
      at
      com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:210)
      at
      com.sun.ejb.containers.EJBObjectInvocationHandlerDelegate.invoke(EJBObjectInvocationHandlerDelegate.java:77)
      at $Proxy199.execDroid(Unknown Source)
      at sun.reflect.GeneratedMethodAccessor246.invoke(Unknown Source)
      at
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:597)
      at
      com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:154)
      at
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatchToServant(CorbaServerRequestDispatcherImpl.java:687)
      at
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatch(CorbaServerRequestDispatcherImpl.java:227)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequestRequest(CorbaMessageMediatorImpl.java:1846)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:1706)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleInput(CorbaMessageMediatorImpl.java:1088)
      at
      com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:223)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:806)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.dispatch(CorbaMessageMediatorImpl.java:563)
      at
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.doWork(CorbaMessageMediatorImpl.java:2567)
      at
      com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)

      #]

      This causes some of our ejb calls to break. The way it breaks is interesting -
      we use a remote client, the remote client immediately gets a RemoteException, but
      the ejb business method continues and seems to complete without a problem.

      We access a db2 database on an iSeries mainframe using the jtopen jdbc driver.
      We use the connection pool via both jdbc and jpa.
      To troubleshoot the first stack trace/warning I wrote a btrace script to trace
      into the jdbc driver and found that it throws an XAException.XAER_RMFAIL exception
      because the connection to the database has been closed (I'm not sure why the
      appserver translates this to a XAException.XAER_OUTSIDE).

      Then I wrote another btrace program to find out why the connection was being
      closed and I came up with this (filtered) output :

      close==============
      com.ibm.as400.access.AS400JDBCConnection@1c2f978.close
      as400_=com.ibm.as400.access.AS400ThreadedServer@12c0c8a
      com.ibm.as400.access.AS400JDBCPooledConnection.close(AS400JDBCPooledConnection.java:150)
      com.sun.gjc.spi.ManagedConnection.destroy(ManagedConnection.java:275)
      com.sun.enterprise.resource.ConnectorAllocator.destroyResource(ConnectorAllocator.java:175)
      com.sun.enterprise.resource.AbstractResourcePool.destroyResource(AbstractResourcePool.java:924)
      com.sun.enterprise.resource.AbstractResourcePool.resizePool(AbstractResourcePool.java:1384)
      com.sun.enterprise.resource.AbstractResourcePool$Resizer.run(AbstractResourcePool.java:1532)
      java.util.TimerThread.mainLoop(Timer.java:512)
      java.util.TimerThread.run(Timer.java:462)

      throw=============

      {connection_=com.ibm.as400.access.AS400JDBCConnection@1c2f978, resourceManagerID_=50815, started_=null, allXids=[], transactionManager_=com.ibm.as400.access.JDTransactionManager@333db0, transactionTimeout_=0, lockWait_=-1, }

      java.sql.SQLException: The connection does not exist.
      com.ibm.as400.access.JDError.throwSQLException(JDError.java:384)
      com.ibm.as400.access.AS400JDBCConnection.checkOpen(AS400JDBCConnection.java:418)
      com.ibm.as400.access.AS400JDBCConnection.sendAndReceive(AS400JDBCConnection.java:2836)
      com.ibm.as400.access.AS400JDBCConnection.sendAndReceive(AS400JDBCConnection.java:2796)
      com.ibm.as400.access.AS400JDBCXAResource.start(AS400JDBCXAResource.java:913)
      com.sun.gjc.spi.XAResourceImpl.start(XAResourceImpl.java:222)
      com.sun.jts.jta.TransactionState.startAssociation(TransactionState.java:305)
      com.sun.jts.jta.TransactionImpl.enlistResource(TransactionImpl.java:205)
      com.sun.enterprise.distributedtx.J2EETransaction.enlistResource(J2EETransaction.java:562)
      com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.enlistResource(J2EETransactionManagerImpl.java:372)
      com.sun.enterprise.distributedtx.J2EETransactionManagerOpt.enlistResource(J2EETransactionManagerOpt.java:144)
      com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.enlistComponentResources(J2EETransactionManagerImpl.java:563)
      com.sun.enterprise.distributedtx.J2EETransactionManagerImpl.enlistComponentResources(J2EETransactionManagerImpl.java:404)
      com.sun.ejb.containers.BaseContainer.startNewTx(BaseContainer.java:3350)
      com.sun.ejb.containers.BaseContainer.preInvokeTx(BaseContainer.java:3270)
      com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:1244)
      com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:202)
      com.sun.ejb.containers.EJBObjectInvocationHandlerDelegate.invoke(EJBObjectInvocationHandlerDelegate.java:77)
      $Proxy199.execDroid(Unknown Source)
      sun.reflect.GeneratedMethodAccessor246.invoke(Unknown Source)
      sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      java.lang.reflect.Method.invoke(Method.java:597)
      com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:154)
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatchToServant(CorbaServerRequestDispatcherImpl.java:687)
      com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatch(CorbaServerRequestDispatcherImpl.java:227)
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequestRequest(CorbaMessageMediatorImpl.java:1846)
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:1706)
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleInput(CorbaMessageMediatorImpl.java:1088)
      com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:223)
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:806)
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.dispatch(CorbaMessageMediatorImpl.java:563)
      com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.doWork(CorbaMessageMediatorImpl.java:2567)
      com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:555)
      ============

      As you can see the connection gets closed when the pool gets resized, and then
      some time afterwards the connection gets used again, which in my opinion is a
      bug because it
      has been destroyed previously.
      One thing I should mention is that the AS400JDBCXAResource keeps a reference to
      the connection, I don't know if it is supposed to (based on some spec/contract)
      acquire
      a new connection if it's current one is closed.

      I then tried to see where the appserver was getting the destroyed resource from
      by analyzing the last stack trace above and using btrace. And I came up with this :
      As you can see (J2EETransactionManagerImpl.java:563) gets called when a new
      transaction is started. Before that point in the code it calls
      getExistingResourceList which
      gets resources from ctx.getResourceList() where ctx is an instance of
      SessionContextImpl. Looking at the source it seems that
      StatelessSessionContainer keeps a pool of
      SessionContextImpl objects and allocates one to each ejb call. If you look as
      SessionContextImpl, I can't see where it's cached resources in the
      EJBContextImpl base class
      will be invalidated/released when they are destroyed, although there might be
      calls to unregisterResource or some listener mechanism that I don't know about.

      The fact remains that the appserver should not try to reuse the destroyed
      connection, this I believe is a bug.

        Activity

        No work has yet been logged on this issue.

          People

          • Assignee:
            Jagadish
            Reporter:
            eduardp
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: