Announcement Announcement Module
Collapse
No announcement yet.
Transactions not propogating Page Title Module
Move Remove Collapse
X
Conversation Detail Module
Collapse
  • Filter
  • Time
  • Show
Clear All
new posts

  • Transactions not propogating

    I've got a DAO that I've configured with declarative transactions as read-only, default propogation (progation required). When I call the getter on that DAO I get no propagation, a new transaction is created with each call even if another transaction exists.

    This is a problem for us because we're using OpenSessionInView and transactions are alive for the length of the page call. When we're preparing a page with large number of entities that each require a "get" from our DAO the end result is a large number of independent transactions are created and alive at the same time.

    DBCP is allocating one connection per transaction and the end result is that we quickly exceed the DBCP maxActive setting and the system hangs.

    I had thought that the first "get" call would create a new transaction and all other "get" calls would simply participate in that same transaction.

    This is definitely not the behavior I'm seeing.

    I'd appreciate it if someone could explain where I'm going wrong.

    Thanks much!

    - Gary

    P.S. Here's an abbreviate version of my ApplicationContext.xml...

    Code:
    	<bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
    		<property name="driverClassName" value="${jdbc.driverClassName}"/>
    		<property name="url" value="${jdbc.url}"/>
    		<property name="username" value="${jdbc.username}"/>
    		<property name="password" value="${jdbc.password}"/>
    		
    		<!-- TODO:
    			The question DAO is creating a new transaction with each "get" call.  The DBCP
    			datasource will allocate a connection for each transaction.  The DBCP default
    			for maxActive is 8.  Some questionnaire pages have more than 8 question per page.
    			We leave transactions (and thus connections) open for the duration of the page.
    			This yields a situation where some questionnaire pages are opening more
    			connections than are available and this results in a hang.  The maxActive increase
    			below fixes this as long as no more than 16 questions appear on a page at a time.
    			A better solution would be for the questionDao to *not* create a transaction
    			with each call but to participate in the existing transaction. -->			
    		<property name="maxActive" value="16"/>
    	</bean>
    	
    	<bean id="hibernateSessionFactory" class="org.springframework.orm.hibernate3.LocalSessionFactoryBean">
    		<property name="dataSource" ref="dataSource"/>
    		<property name="mappingResources">
    			<list>
    				<value>abhto/abhc/core/Question.hbm.xml</value>
    			</list>
    		</property>
    		
    		<property name="hibernateProperties">
    			<props>
    				<prop key="hibernate.dialect">org.hibernate.dialect.Oracle9Dialect</prop>
    				<prop key="hibernate.default_schema">abhc_data</prop>
    				
    				<!-- the SingletonEhCacheProvider is temporary, see: http://gabrito.com/post/upgrading-to-spring-20-and-hibernate-32 -->
    				<prop key="hibernate.cache.provider_class">net.sf.ehcache.hibernate.SingletonEhCacheProvider</prop>
    				<prop key="hibernate.cache.use_second_level_cache">true</prop>
    			</props>
    		</property>
    	</bean>
    	
    	<bean id="questionDao" class="abhto.abhc.dao.QuestionDaoImpl">
    		<property name="sessionFactory" ref="hibernateSessionFactory"/>
    	</bean>	
    
    	
    
    	<!-- Declare the transaction manager that handles the transactions -->
    	<bean id="transactionManager" class="org.springframework.orm.hibernate3.HibernateTransactionManager">
    		<property name="sessionFactory" ref="hibernateSessionFactory" />
    	</bean>
    
    	<!-- Declare the objects that we want transaction support for (our DAO's and Services, above) -->
    	<aop:config>
    		<aop:advisor pointcut="execution(* abhto.abhc.service.*Service.*(..))" advice-ref="txAdvice"/>
    		<aop:advisor pointcut="execution(* abhto.abhc.dao.*Dao.*(..))" advice-ref="txAdvice"/>
    	</aop:config>
    
    	<!-- Declare how the methods within those objects behave within a transaction -->
    	<tx:advice id="txAdvice" transaction-manager="transactionManager">
    		<tx:attributes>
    			<!-- methods with "get" in their name are read-only -->
    			<tx:method name="get*" read-only="true"/>
    			<tx:method name="is*" read-only="true"/>
    			
    			<!-- all other methods use the default transaction settings -->
    			<!-- (propogation required, default isolation, read-only=false ) --> 
    			<tx:method name="*"/>
    		</tx:attributes>
    	</tx:advice>

  • #2
    Is it possible to see the DEBUG logs?
    Last edited by karldmoore; Aug 27th, 2007, 04:32 PM.

    Comment


    • #3
      Karl,

      Sorry for the delay in replying to this, our hack-fix let us limp along awhile. But I would like to figure out what's going on.

      I'm going to post snippets of the debug log in separate posts since the forum-system won't let me create posts over 10000 characters.

      Here's the first snippet where we see Spring handle the transaction for getSiteById. It's doing everything right here.

      Code:
      AbstractPlatformTransactionManager:getTransaction: Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@17cd18d]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      AbstractPlatformTransactionManager:getTransaction: Creating new transaction with name [abhto.abhc.dao.SiteDaoImpl.getSiteById]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      HibernateTransactionManager:doBegin: Opened new Session [org.hibernate.impl.SessionImpl@1a183d2] for Hibernate transaction    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      HibernateTransactionManager:doBegin: Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@1a183d2]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      DataSourceUtils:prepareConnectionForTransaction: Setting JDBC Connection [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver] read-only    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      HibernateTransactionManager:doBegin: Exposing Hibernate transaction as JDBC transaction [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:bindResource: Bound value [org.springframework.jdbc.datasource.ConnectionHolder@d55a0f] for key [org.apache.commons.dbcp.BasicDataSource@2dce4e] to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:bindResource: Bound value [org.springframework.orm.hibernate3.SessionHolder@10bb83e] for key [org.hibernate.impl.SessionFactoryImpl@41f871] to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:initSynchronization: Initializing transaction synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionAspectSupport:prepareTransactionInfo: Getting transaction for [abhto.abhc.dao.SiteDaoImpl.getSiteById]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:getResource: Retrieved value [org.springframework.orm.hibernate3.SessionHolder@10bb83e] for key [org.hibernate.impl.SessionFactoryImpl@41f871] bound to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:getResource: Retrieved value [org.springframework.orm.hibernate3.SessionHolder@10bb83e] for key [org.hibernate.impl.SessionFactoryImpl@41f871] bound to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      HibernateTemplate:execute: Found thread-bound Session for HibernateTemplate    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      HibernateTemplate:execute: Not closing pre-bound Hibernate Session after HibernateTemplate    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionAspectSupport:commitTransactionAfterReturning: Completing transaction for [abhto.abhc.dao.SiteDaoImpl.getSiteById]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      AbstractPlatformTransactionManager:triggerBeforeCommit: Triggering beforeCommit synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      AbstractPlatformTransactionManager:triggerBeforeCompletion: Triggering beforeCompletion synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      AbstractPlatformTransactionManager:processCommit: Initiating transaction commit    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      HibernateTransactionManager:doCommit: Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@1a183d2]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      AbstractPlatformTransactionManager:triggerAfterCommit: Triggering afterCommit synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      AbstractPlatformTransactionManager:triggerAfterCompletion: Triggering afterCompletion synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:clearSynchronization: Clearing transaction synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:unbindResource: Removed value [org.springframework.orm.hibernate3.SessionHolder@10bb83e] for key [org.hibernate.impl.SessionFactoryImpl@41f871] from thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      TransactionSynchronizationManager:unbindResource: Removed value [org.springframework.jdbc.datasource.ConnectionHolder@d55a0f] for key [org.apache.commons.dbcp.BasicDataSource@2dce4e] from thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      DataSourceUtils:resetConnectionAfterTransaction: Resetting read-only flag of JDBC Connection [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      HibernateTransactionManager:doCleanupAfterCompletion: Closing Hibernate Session [org.hibernate.impl.SessionImpl@1a183d2] after transaction    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
      SessionFactoryUtils:closeSessionOrRegisterDeferredClose: Registering Hibernate Session for deferred close    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})

      Comment


      • #4
        Here's the next section where we see Spring handle the transaction for getGeneratedKey.

        The transaction setup is all good here, the problem is that it's a *new* transaction, not a participant in the previous getSiteId transaction.

        And since we're using deferred close (via Spring's OpenSessionInViewFilter) we now have two connections to the DB open (one for the getSiteById transaction and now a new one for this getGeneratedKey transaction).

        Code:
        AbstractPlatformTransactionManager:getTransaction: Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@326074]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        AbstractPlatformTransactionManager:getTransaction: Creating new transaction with name [abhto.abhc.service.QuestionServiceImpl.getGeneratedKey]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        HibernateTransactionManager:doBegin: Opened new Session [org.hibernate.impl.SessionImpl@15a64e6] for Hibernate transaction    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        HibernateTransactionManager:doBegin: Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@15a64e6]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        DataSourceUtils:prepareConnectionForTransaction: Setting JDBC Connection [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver] read-only    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        HibernateTransactionManager:doBegin: Exposing Hibernate transaction as JDBC transaction [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionSynchronizationManager:bindResource: Bound value [org.springframework.jdbc.datasource.ConnectionHolder@196722d] for key [org.apache.commons.dbcp.BasicDataSource@2dce4e] to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionSynchronizationManager:bindResource: Bound value [org.springframework.orm.hibernate3.SessionHolder@221c75] for key [org.hibernate.impl.SessionFactoryImpl@41f871] to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionSynchronizationManager:initSynchronization: Initializing transaction synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionAspectSupport:prepareTransactionInfo: Getting transaction for [abhto.abhc.service.QuestionServiceImpl.getGeneratedKey]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionAspectSupport:commitTransactionAfterReturning: Completing transaction for [abhto.abhc.service.QuestionServiceImpl.getGeneratedKey]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        AbstractPlatformTransactionManager:triggerBeforeCommit: Triggering beforeCommit synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        AbstractPlatformTransactionManager:triggerBeforeCompletion: Triggering beforeCompletion synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        AbstractPlatformTransactionManager:processCommit: Initiating transaction commit    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        HibernateTransactionManager:doCommit: Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@15a64e6]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        AbstractPlatformTransactionManager:triggerAfterCommit: Triggering afterCommit synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        AbstractPlatformTransactionManager:triggerAfterCompletion: Triggering afterCompletion synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionSynchronizationManager:clearSynchronization: Clearing transaction synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionSynchronizationManager:unbindResource: Removed value [org.springframework.orm.hibernate3.SessionHolder@221c75] for key [org.hibernate.impl.SessionFactoryImpl@41f871] from thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        TransactionSynchronizationManager:unbindResource: Removed value [org.springframework.jdbc.datasource.ConnectionHolder@196722d] for key [org.apache.commons.dbcp.BasicDataSource@2dce4e] from thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        DataSourceUtils:resetConnectionAfterTransaction: Resetting read-only flag of JDBC Connection [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        HibernateTransactionManager:doCleanupAfterCompletion: Closing Hibernate Session [org.hibernate.impl.SessionImpl@15a64e6] after transaction    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
        SessionFactoryUtils:closeSessionOrRegisterDeferredClose: Registering Hibernate Session for deferred close    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})

        Comment


        • #5
          Here's the next transaction. Another call to getGeneratedKey. This is, again, a new transaction (not a participant in the previous transactions).

          And we now have connection #3 open.

          Code:
          AbstractPlatformTransactionManager:getTransaction: Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@17a82f1]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          AbstractPlatformTransactionManager:getTransaction: Creating new transaction with name [abhto.abhc.service.QuestionServiceImpl.getGeneratedKey]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          HibernateTransactionManager:doBegin: Opened new Session [org.hibernate.impl.SessionImpl@2aa00c] for Hibernate transaction    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          HibernateTransactionManager:doBegin: Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@2aa00c]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          DataSourceUtils:prepareConnectionForTransaction: Setting JDBC Connection [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver] read-only    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          HibernateTransactionManager:doBegin: Exposing Hibernate transaction as JDBC transaction [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionSynchronizationManager:bindResource: Bound value [org.springframework.jdbc.datasource.ConnectionHolder@71b383] for key [org.apache.commons.dbcp.BasicDataSource@2dce4e] to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionSynchronizationManager:bindResource: Bound value [org.springframework.orm.hibernate3.SessionHolder@c087be] for key [org.hibernate.impl.SessionFactoryImpl@41f871] to thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionSynchronizationManager:initSynchronization: Initializing transaction synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionAspectSupport:prepareTransactionInfo: Getting transaction for [abhto.abhc.service.QuestionServiceImpl.getGeneratedKey]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionAspectSupport:commitTransactionAfterReturning: Completing transaction for [abhto.abhc.service.QuestionServiceImpl.getGeneratedKey]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          AbstractPlatformTransactionManager:triggerBeforeCommit: Triggering beforeCommit synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          AbstractPlatformTransactionManager:triggerBeforeCompletion: Triggering beforeCompletion synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          AbstractPlatformTransactionManager:processCommit: Initiating transaction commit    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          HibernateTransactionManager:doCommit: Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@2aa00c]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          AbstractPlatformTransactionManager:triggerAfterCommit: Triggering afterCommit synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          AbstractPlatformTransactionManager:triggerAfterCompletion: Triggering afterCompletion synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionSynchronizationManager:clearSynchronization: Clearing transaction synchronization    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionSynchronizationManager:unbindResource: Removed value [org.springframework.orm.hibernate3.SessionHolder@c087be] for key [org.hibernate.impl.SessionFactoryImpl@41f871] from thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          TransactionSynchronizationManager:unbindResource: Removed value [org.springframework.jdbc.datasource.ConnectionHolder@71b383] for key [org.apache.commons.dbcp.BasicDataSource@2dce4e] from thread [http-443-Processor25]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          DataSourceUtils:resetConnectionAfterTransaction: Resetting read-only flag of JDBC Connection [jdbc:oracle:thin:@amedapmamc51:1521:gary, UserName=ABHC_APP, Oracle JDBC driver]    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          HibernateTransactionManager:doCleanupAfterCompletion: Closing Hibernate Session [org.hibernate.impl.SessionImpl@2aa00c] after transaction    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
          SessionFactoryUtils:closeSessionOrRegisterDeferredClose: Registering Hibernate Session for deferred close    (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})

          Comment


          • #6
            And it goes on like that. We're calling getGeneratedKey in a loop and since each call starts a new transaction (and correspondingly a new connection) our available connections are eventually exhausted.

            Which, if you're using DBCP as your connection pool, is a viciously opaque bug to catch. DBCP simply hangs with no error, warning, etc.

            It gets a little better if you make DBCP's maxActive value ridiculously large (we have ours set to 900). That way the actual constraint will be the database and its ability to maintain open connections. With this setting we at least don't get the "hang" we get get

            Code:
            JDBCExceptionReporter:logExceptions: Listener refused the connection with the following error:
            ORA-12519, TNS:no appropriate service handler found
            The Connection descriptor used by the client was:
            amedapmamc51:1521:gary
                (/questionnaire/questionnaire_initialize.action | {PatientId=5538941})
            JDBCExceptionReporter:logExceptions: Listener refused the connection with the following error:
            ORA-12519, TNS:no appropriate service handler found
            followed by a stacktrace.

            Any help is most appreciated.

            - Gary

            Comment

            Working...
            X