|
From: Dave B. <dba...@on...> - 2005-05-20 20:41:35
|
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></property>
</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
|
|
From: Juergen H. <ju...@in...> - 2005-05-21 21:26:42
|
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
|
|
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 > > > > |
|
From: Juergen H. <ju...@in...> - 2005-05-22 10:13:05
|
Dave, I've already finished the reworking: AbstractPlatformTransactionManager discriminated between a "local" and a "global" rollback-only flag now, which was fortunately straightforward to do. "local" refers to a TransactionStatus.setRollbackOnly() call by the application, which leads to a silent rollback (usually, the application will throw an appropriate exception). "global" refers to the UserTransaction or resource holder being marked as rollback-only, which can only happen through the transaction coordinator. One example for this is a transaction timeout. There is one side effect, though: If you have an outer and an inner transaction and call TransactionStatus.setRollbackOnly() on the inner transaction without throwing an exception, you got a silent rollback of the outer transaction before. Now, the outer transaction will throw an UnexpectedRollbackException instead. I guess it's more appropriate to throw an UnexpectedRollbackException here in any case, to avoid surprises for callers of the outer transaction. Usually, the inner transaction will throw an exception anyway, so the outer transaction will simply rollback and propagate that exception. In total, I'm happy with the new semantics. Rollbacks will always lead to an exception, unless the local TransactionStatus object received a setRollbackOnly() call from the application. The slight change in semantics should not be an issue, as I do not expect any application to rely on such silent rollbacks of outer transactions. I'll commit this today; it should be available in the next nightly build. Please give this refined behavior a try and let me know how it works for you! Juergen -----Original Message----- From: spr...@li... [mailto:spr...@li...]On Behalf Of Dave Ballard Sent: Sunday, May 22, 2005 1:22 AM To: spr...@li... Subject: Re: [Springframework-developer] Spring 1.2 Spring JTA tx timeout, tx rolls back, but no exception thrown (another race condition) 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></pro p >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 > > > > ------------------------------------------------------- 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 |
|
From: Dave B. <dba...@on...> - 2005-05-22 15:29:19
|
Hi Juergen , That's great. I will give it a try tomorrow. Dave Juergen Hoeller wrote: >Dave, > >I've already finished the reworking: AbstractPlatformTransactionManager >discriminated between a "local" and a "global" rollback-only flag now, which >was fortunately straightforward to do. > >"local" refers to a TransactionStatus.setRollbackOnly() call by the >application, which leads to a silent rollback (usually, the application will >throw an appropriate exception). > >"global" refers to the UserTransaction or resource holder being marked as >rollback-only, which can only happen through the transaction coordinator. >One example for this is a transaction timeout. > >There is one side effect, though: If you have an outer and an inner >transaction and call TransactionStatus.setRollbackOnly() on the inner >transaction without throwing an exception, you got a silent rollback of the >outer transaction before. Now, the outer transaction will throw an >UnexpectedRollbackException instead. > >I guess it's more appropriate to throw an UnexpectedRollbackException here >in any case, to avoid surprises for callers of the outer transaction. >Usually, the inner transaction will throw an exception anyway, so the outer >transaction will simply rollback and propagate that exception. > >In total, I'm happy with the new semantics. Rollbacks will always lead to an >exception, unless the local TransactionStatus object received a >setRollbackOnly() call from the application. The slight change in semantics >should not be an issue, as I do not expect any application to rely on such >silent rollbacks of outer transactions. > >I'll commit this today; it should be available in the next nightly build. >Please give this refined behavior a try and let me know how it works for >you! > >Juergen > > >-----Original Message----- >From: spr...@li... >[mailto:spr...@li...]On Behalf >Of Dave Ballard >Sent: Sunday, May 22, 2005 1:22 AM >To: spr...@li... >Subject: Re: [Springframework-developer] Spring 1.2 Spring JTA tx >timeout, tx rolls back, but no exception thrown (another race condition) > > >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></pro >> >> >p > > >>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 >> >> >> >> >> >> > > >------------------------------------------------------- >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 > > > > |
|
From: Dave B. <dba...@on...> - 2005-05-24 14:57:57
|
Hi Juergen, I've been testing with spring-framework-1.2.1-build.267-20050524.zip, and can't seem to recreate the problem, so it appears fixed. One thing that is bothering me, though, is that my scenario was a race condition. Basically, one of two things would happen on a timeout: 1) Tx rolls back and org.springframework.jdbc.UncategorizedSQLException(SQLException(TimeoutException) thrown by a call to hibernate session.flush() 2) Tx rolls back When using spring-framework-1.2.1-build.267-20050524, now, all I encounter is: 1) Tx rolls back and org.springframework.jdbc.UncategorizedSQLException(SQLException(TimeoutException) thrown by a call to hibernate session.flush() So it *appears* that with the fix, flush() is always called. This is fine with me, but is this what you would expect from your fix, or am I just getting lucky? Dave Dave Ballard wrote: > Hi Juergen , > > That's great. I will give it a try tomorrow. > > Dave > > Juergen Hoeller wrote: > >> Dave, >> >> I've already finished the reworking: AbstractPlatformTransactionManager >> discriminated between a "local" and a "global" rollback-only flag >> now, which >> was fortunately straightforward to do. >> >> "local" refers to a TransactionStatus.setRollbackOnly() call by the >> application, which leads to a silent rollback (usually, the >> application will >> throw an appropriate exception). >> >> "global" refers to the UserTransaction or resource holder being >> marked as >> rollback-only, which can only happen through the transaction >> coordinator. >> One example for this is a transaction timeout. >> >> There is one side effect, though: If you have an outer and an inner >> transaction and call TransactionStatus.setRollbackOnly() on the inner >> transaction without throwing an exception, you got a silent rollback >> of the >> outer transaction before. Now, the outer transaction will throw an >> UnexpectedRollbackException instead. >> >> I guess it's more appropriate to throw an UnexpectedRollbackException >> here >> in any case, to avoid surprises for callers of the outer transaction. >> Usually, the inner transaction will throw an exception anyway, so the >> outer >> transaction will simply rollback and propagate that exception. >> >> In total, I'm happy with the new semantics. Rollbacks will always >> lead to an >> exception, unless the local TransactionStatus object received a >> setRollbackOnly() call from the application. The slight change in >> semantics >> should not be an issue, as I do not expect any application to rely on >> such >> silent rollbacks of outer transactions. >> >> I'll commit this today; it should be available in the next nightly >> build. >> Please give this refined behavior a try and let me know how it works for >> you! >> >> Juergen >> >> >> -----Original Message----- >> From: spr...@li... >> [mailto:spr...@li...]On Behalf >> Of Dave Ballard >> Sent: Sunday, May 22, 2005 1:22 AM >> To: spr...@li... >> Subject: Re: [Springframework-developer] Spring 1.2 Spring JTA tx >> timeout, tx rolls back, but no exception thrown (another race condition) >> >> >> 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></pro >>> >>> >> >> p >> >> >>> 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 >>> >>> >>> >>> >>> >> >> >> >> ------------------------------------------------------- >> 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 >> >> >> >> > > > ------------------------------------------------------- > 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 > > |
|
From: Juergen H. <ju...@in...> - 2005-05-24 20:20:37
|
Indeed, since the change, flush should always be called. More generally speaking, a commit will be attempted instead of a rollback, even if the underlying transaction has been marked rollback-only (by something other than Spring's TransactionStatus object). The race condition appeared to have been in the JTA implementation, actually: depending on whether a parallel thread there marked the transaction rollback-only after a timeout, Spring would have attempted a rollback or commit. If you set the timeout sufficiently low and let your code sleep sufficiently long, you should almost always get a rollback-only marker, as the parallel thread will have enough time to kick in. If you want to double-check, you could try to reproduce the problem with an old spring.jar, then drop in the new spring.jar and see whether you're unable to reproduce it again. Juergen -----Original Message----- From: spr...@li... [mailto:spr...@li...]On Behalf Of Dave Ballard Sent: Tuesday, May 24, 2005 4:58 PM To: spr...@li... Subject: Re: [Springframework-developer] Spring 1.2 Spring JTA tx timeout, tx rolls back, but no exception thrown (another race condition) Hi Juergen, I've been testing with spring-framework-1.2.1-build.267-20050524.zip, and can't seem to recreate the problem, so it appears fixed. One thing that is bothering me, though, is that my scenario was a race condition. Basically, one of two things would happen on a timeout: 1) Tx rolls back and org.springframework.jdbc.UncategorizedSQLException(SQLException(TimeoutExcep tion) thrown by a call to hibernate session.flush() 2) Tx rolls back When using spring-framework-1.2.1-build.267-20050524, now, all I encounter is: 1) Tx rolls back and org.springframework.jdbc.UncategorizedSQLException(SQLException(TimeoutExcep tion) thrown by a call to hibernate session.flush() So it *appears* that with the fix, flush() is always called. This is fine with me, but is this what you would expect from your fix, or am I just getting lucky? Dave Dave Ballard wrote: > Hi Juergen , > > That's great. I will give it a try tomorrow. > > Dave > > Juergen Hoeller wrote: > >> Dave, >> >> I've already finished the reworking: AbstractPlatformTransactionManager >> discriminated between a "local" and a "global" rollback-only flag >> now, which >> was fortunately straightforward to do. >> >> "local" refers to a TransactionStatus.setRollbackOnly() call by the >> application, which leads to a silent rollback (usually, the >> application will >> throw an appropriate exception). >> >> "global" refers to the UserTransaction or resource holder being >> marked as >> rollback-only, which can only happen through the transaction >> coordinator. >> One example for this is a transaction timeout. >> >> There is one side effect, though: If you have an outer and an inner >> transaction and call TransactionStatus.setRollbackOnly() on the inner >> transaction without throwing an exception, you got a silent rollback >> of the >> outer transaction before. Now, the outer transaction will throw an >> UnexpectedRollbackException instead. >> >> I guess it's more appropriate to throw an UnexpectedRollbackException >> here >> in any case, to avoid surprises for callers of the outer transaction. >> Usually, the inner transaction will throw an exception anyway, so the >> outer >> transaction will simply rollback and propagate that exception. >> >> In total, I'm happy with the new semantics. Rollbacks will always >> lead to an >> exception, unless the local TransactionStatus object received a >> setRollbackOnly() call from the application. The slight change in >> semantics >> should not be an issue, as I do not expect any application to rely on >> such >> silent rollbacks of outer transactions. >> >> I'll commit this today; it should be available in the next nightly >> build. >> Please give this refined behavior a try and let me know how it works for >> you! >> >> Juergen >> >> >> -----Original Message----- >> From: spr...@li... >> [mailto:spr...@li...]On Behalf >> Of Dave Ballard >> Sent: Sunday, May 22, 2005 1:22 AM >> To: spr...@li... >> Subject: Re: [Springframework-developer] Spring 1.2 Spring JTA tx >> timeout, tx rolls back, but no exception thrown (another race condition) >> >> >> 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></pro >>> >>> >> >> p >> >> >>> 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 >>> >>> >>> >>> >>> >> >> >> >> ------------------------------------------------------- >> 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 >> >> >> >> > > > ------------------------------------------------------- > 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 Yahoo. Introducing Yahoo! Search Developer Network - Create apps using Yahoo! Search APIs Find out how you can build Yahoo! directly into your own Applications - visit http://developer.yahoo.net/?fr=offad-ysdn-ostg-q22005 _______________________________________________ Springframework-developer mailing list Spr...@li... https://lists.sourceforge.net/lists/listinfo/springframework-developer |