|
From: Dave B. <dba...@on...> - 2005-05-21 23:20:33
|
Hi Juergen, Thanks for checking into this. Does look a little ugly. Hopefully you'll find a way to tell the difference between the two different rollback situations (or to inquire if in fact a timeout has occurred). Currently this is a show-stopper for me. Although this type of timeout won't happen frequently, it will happen, and the consequences will be a little difficult to track down because of the lack of an exception. Thanks again for your help, Dave Juergen Hoeller wrote: >Good point - thanks for reporting this! JTA implementations seem to mark >transaction as rollback-only when they have timed out, without further >indication. So unless you attempt an actual resource operation after the >timeout, there is no guarantee than an exception gets thrown before commit. > >If Spring discovers a rollback-only status, it assumes that the application >has set the transaction to rollback-only and triggers a silent rollback. >This will usually happen when TransactionStatus.setRollbackOnly() has been >called, instead of configuring a rollback rule, with an application-level >exception getting thrown. > >In the case of a JTA timeout, the rollback-only marker comes from the JTA >subsystem, though. Spring effectively misinterprets that marker as driven by >the application, which leads to an inappropriate silent reaction. I'll fix >that for Spring 1.2.1, although it's unfortunately not that trivial for the >general case. > >Juergen > > >-----Original Message----- >From: spr...@li... >[mailto:spr...@li...]On Behalf >Of Dave Ballard >Sent: Friday, May 20, 2005 10:44 PM >To: spr...@li... >Subject: [Springframework-developer] Spring 1.2 Spring JTA tx timeout, >tx rolls back, but no exception thrown (another race condition) > > >Hi Juergen, > >Using unpatched Spring 1.2 on WebLogic 6.1. I've defined a >Spring-managed service bean, with the following transaction manager and >transaction interceptor beans: > > <bean id="MyTransactionManager" >class="org.springframework.transaction.jta.JtaTransactionManager"> > <property >name="transactionManagerName"><value>java:comp/UserTransaction</value></prop >erty> > </bean> > > <bean id="MyTransactionInterceptor" >class="org.springframework.transaction.interceptor.TransactionInterceptor"> > <property name="transactionManager"><ref >bean="MyTransactionManager"/></property> > <property name="transactionAttributeSource"> > <value> > PaymentService.commit=PROPAGATION_REQUIRED,-Exception > </value> > </property> > </bean> > >The transactional demarcation causes a commit when the method succeeds, >and causes a rollback when an exception is thrown (and throws the >exception), as expected. However, if I introduce a 40 second sleep in >the method, the transaction rolls back as expected, but sometimes no >exception is thrown. In the case where no exception is thrown, I can see >in the Spring log: > > WARN 14:45:03,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (EjbUtils.java:626) - START SLEEP 40: >PaymentServiceImpl.commit() 40 seconds...... > WARN 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (EjbUtils.java:633) - DONE SLEEP 40: >PaymentServiceImpl.commit() 40 seconds...... >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (TransactionAspectSupport.java:258) - Invoking commit for >transaction on PaymentService.commit >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (AbstractPlatformTransactionManager.java:382) - >Transactional code has requested rollback >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (AbstractPlatformTransactionManager.java:542) - Triggering >beforeCompletion synchronization >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (TransactionSynchronizationManager.java:177) - Removed >value [org.springframework.orm.hibernate.SessionHolder@57f820] for key >[net.sf.hibernate.impl.SessionFactoryImpl@39569e] from thread >[ExecuteThread: '30' for queue: 'default'] >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (SessionFactoryUtils.java:730) - Closing Hibernate Session >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (AbstractPlatformTransactionManager.java:463) - Initiating >transaction rollback >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (JtaTransactionManager.java:719) - Rolling back JTA transaction >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (AbstractPlatformTransactionManager.java:572) - Triggering >afterCompletion synchronization >DEBUG 14:45:43,156 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (TransactionSynchronizationManager.java:252) - Clearing >transaction synchronization > INFO 14:45:43,171 [ExecuteThread: '30' for queue: 'default'] >[edemo_acme] (PaymentCommit.java:167) - PERFORMANCE END PaymentCommit > >This is an intermittent problem that occurs in both 1.1.5 and 1.2. I run >the same test over and over, and while it always rolls back, it only >sometimes throws an exception. In the case where it does throw an >exception, the log is different: > > WARN 15:18:54,109 [ExecuteThread: '31' for queue: 'default'] >[edemo_acme] (EjbUtils.java:626) - START SLEEP 40: >PaymentServiceImpl.commit() 40 seconds...... > WARN 15:19:34,109 [ExecuteThread: '31' for queue: 'default'] >[edemo_acme] (EjbUtils.java:633) - DONE SLEEP 40: >PaymentServiceImpl.commit() 40 seconds...... >DEBUG 15:19:34,109 [ExecuteThread: '31' for queue: 'default'] >[edemo_acme] (TransactionAspectSupport.java:241) - Invoking commit for >transaction on method 'commit' in class [PaymentService] >DEBUG 15:19:34,109 [ExecuteThread: '31' for queue: 'default'] >[edemo_acme] (AbstractPlatformTransactionManager.java:523) - Triggering >beforeCommit synchronization >DEBUG 15:19:34,109 [ExecuteThread: '31' for queue: 'default'] >[edemo_acme] (SessionFactoryUtils.java:809) - Flushing Hibernate session >on transaction synchronization >DEBUG 15:19:34,109 [ExecuteThread: '31' for queue: 'default'] >[edemo_acme] (SQLErrorCodeSQLExceptionTranslator.java:225) - Unable to >translate SQLException with errorCode '0', will now try the fallback >translator >DEBUG 15:19:34,109 [ExecuteThread: '31' for queue: 'default'] >[edemo_acme] (SQLStateSQLExceptionTranslator.java:74) - Translating >SQLException with SQLState 'null' and errorCode '0' and message [The >transaction is no longer active (status = Rolled back. >[Reason=weblogic.transaction.internal.TimedOutException: Transaction >timed out after 28 seconds >[snip] > >This appears to be another race condition. In the case where the >exception is thrown, the transaction has not yet been flagged as >rollback-only. The code proceeds to attempt a hibernate flush(), and >this causes a SQLException(TimedOutException) to be thrown. > >In the first case where no exception is thrown, the transaction has >already been flagged rollback-only, so the code never calls hibernate >flush, and simply returns w/o an exception after rolling back the tx. > >This is a pretty serious problem for my application because the calling >code has no idea that the transaction rolled back. > >Thanks, >Dave > > > > > > >------------------------------------------------------- >This SF.Net email is sponsored by Oracle Space Sweepstakes >Want to be the first software developer in space? >Enter now for the Oracle Space Sweepstakes! >http://ads.osdn.com/?ad_id=7412&alloc_id=16344&op=click >_______________________________________________ >Springframework-developer mailing list >Spr...@li... >https://lists.sourceforge.net/lists/listinfo/springframework-developer > > > >------------------------------------------------------- >This SF.Net email is sponsored by Oracle Space Sweepstakes >Want to be the first software developer in space? >Enter now for the Oracle Space Sweepstakes! >http://ads.osdn.com/?ad_id=7412&alloc_id=16344&op=click >_______________________________________________ >Springframework-developer mailing list >Spr...@li... >https://lists.sourceforge.net/lists/listinfo/springframework-developer > > > > |