janh
- 浏览: 18144 次
- 性别:
-
最新评论
探讨一下spring拦截器中的数据库操作和事务管理。
大家知道spring中的事务管理是通过AOP代理来实现的，对被代理对象的每个方法进行拦截，在方法执行前启动事务，方法执行完后根据是否有异常和异常的种类进行提交或回滚。
如果要在方法执行前或后或抛出异常后加上一个自己的拦截器，或者一个环绕拦截器，在拦截器中执行一些操作，比如执行一些数据库操作，记录一些信息，这些操作通过调用一个服务类的方法来执行，这个方法也在spring事务管理拦截器的管理之下，那么这个记录方法需要在另一个事务中进行，而不是与被拦截方法在同一个事务中，不然如果被拦截方法抛出异常需要回滚时，所作的记录也会被回滚，当然有时候确实需要同时回滚，那就要放在同一个事务中。
这和自己的拦截器和事务管理的拦截器的执行顺序有一定关系，spring事务管理拦截器是一个环绕通知，在被拦截方法执行前启动事务，执行后完成事务，如果自己的拦截器被spring事务管理拦截器包围在里面，那么在自己的拦截器运行时，spring已经启动了一个事务，如果你的记录信息方法需要与被拦截方法同在一个事务中，将你的记录信息方法的事务传播属性设为默认的REQUIRED就可以了；
如果你记录信息的方法需要单独的一个事务环境，那就要把事务传播属性设为REQUIRES_NEW了，这样spring事务管理器会新建一个事务，并且新建一个session连接，因为一个数据库连接不可能同时有两个事务，记录信息完了提交事务并且把新建的session连接关闭，自己的拦截器退出后继续执行被拦截的方法或它的事务处理。
相反如果自己的拦截器在spring事务管理拦截器的外面，那么记录信息的方法会在一个单独的事务中执行，并提交，不管它的事务传播属性是REQUIRES_NEW还是REQUIRED，因为与被拦截方法的事务处理没有交叉，并且可以使用同一个session连接如果是OpenSessionInViewFilter。
所以如果记录信息和被拦截方法要在不同事务中执行，分别提交，那么最好将自己的拦截器设在spring事务管理器拦截器的外面；如果需要将记录信息和被拦截方法在同一个事务中处理，必须将自己的拦截器被包围在spring事务管理拦截器中，并且记录信息方法的事务传播属性为默认的REQUIRED。
设置拦截器的执行顺序可以让拦截器处理类实现org.springframework.core.Ordered接口，在spring配置文件的AOP设置中设定自己的拦截器和spring事务管理拦截器的执行顺序，将自己的拦截的序号排在spring事务管理的前面，就可以将该拦截器放到事务管理拦截器的外面执行了，对于before通知方式会先于事务管理拦截器执行，对于after returning和after和after throwing通知方式会后于事务管理拦截器的执行，对于arount通知方式会包围事务管理拦截器执行。
下面是一个异常拦截器的例子。
有位朋友提到在spring异常拦截器中更新数据不能够提交，做了一下测试，测试环境基本是这样：一个用户登录的功能，spring对service中的每个方法进行事务管理，在用户检测的service方法上同时加上一个异常拦截器，当用户不存在或密码不正确时用户检测方法会抛出异常，异常拦截器捕获到该异常，同时记录一些日志。
spring配置文件相关：
拦截器类：
service方法中的事务传播属性都设为要求新建事务，spring事务管理切面拦截器的order设为1，而log拦截器的order设为2，这意味着这两个要同时执行时，先执行事务拦截器，后执行log拦截器，由于事务管理是一个环绕通知（around），实际上是log拦截器被包围在事务管理拦截器中。
一个不正确的用户登录时，打印的日志：
03:35:16,562 DEBUG OpenSessionInViewFilter:253 - Using SessionFactory 'sessionFactory' for OpenSessionInViewFilter
03:35:16,562 DEBUG OpenSessionInViewFilter:196 - Opening single Hibernate Session in OpenSessionInViewFilter
03:35:16,562 DEBUG SessionFactoryUtils:333 - Opening Hibernate Session
03:35:16,562 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] to thread [http-8088-Processor25]
03:35:16,562 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,562 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@dfbabd] for Hibernate transaction
03:35:16,578 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@5cd7f9]
03:35:16,578 DEBUG HibernateTransactionManager:320 - Creating new transaction with name [com.hbs.customer.CustomerService.customerLogin]
03:35:16,578 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@dfbabd]
03:35:16,578 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@1501026]
03:35:16,578 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:35:16,578 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:35:16,578 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.customer.CustomerService.customerLogin]
用户登录
03:35:16,578 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,578 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,578 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:35:16,578 DEBUG SQL:393 - select this_.CUSTOMER_ID as CUSTOMER1_5_0_, this_.CUSTOMER_GROUP_ID as CUSTOMER2_5_0_, this_.CUSTOMER_PASSWORD as CUSTOMER3_5_0_, this_.CUSTOMER_NAME as CUSTOMER4_5_0_, this_.CUSTOMER_DESCRIPTION as CUSTOMER5_5_0_, this_.CUSTOMER_KIND as CUSTOMER6_5_0_, this_.CUSTOMER_SEX as CUSTOMER7_5_0_, this_.PHONE as PHONE5_0_, this_.MOBILE as MOBILE5_0_, this_.ADDRESS as ADDRESS5_0_, this_.EMAIL as EMAIL5_0_, this_.CONFIRM_TYPE as CONFIRM12_5_0_, this_.CREATE_TIME as CREATE13_5_0_, this_.GROUP_TIME as GROUP14_5_0_, this_.FIRST_TIME as FIRST15_5_0_, this_.LAST_TIME as LAST16_5_0_, this_.LOGIN_COUNT as LOGIN17_5_0_, this_.CREDIT_VALUE as CREDIT18_5_0_, this_.CUMULATE_VALUE as CUMULATE19_5_0_, this_.STATUS as STATUS5_0_, this_.NOTES as NOTES5_0_ from hbs.hbs_customer this_ where this_.CUSTOMER_ID=? and this_.CUSTOMER_PASSWORD=?
03:35:16,593 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
记录日志开始
03:35:16,593 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,593 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@dfbabd] for Hibernate transaction
03:35:16,593 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] bound to thread [http-8088-Processor25]
03:35:16,593 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@5ec940]
03:35:16,593 DEBUG HibernateTransactionManager:358 - Suspending current transaction, creating new transaction with name [com.hbs.eventlog.EventLogService.eventLog]
03:35:16,593 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:35:16,593 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] from thread [http-8088-Processor25]
03:35:16,609 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:35:16,609 DEBUG HibernateTransactionManager:428 - Opened new Session [org.hibernate.impl.SessionImpl@eeb406] for Hibernate transaction
03:35:16,609 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@eeb406]
03:35:16,609 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@8543aa]
03:35:16,609 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@16d03ba] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:35:16,609 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] to thread [http-8088-Processor25]
03:35:16,609 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:35:16,609 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:35:16,625 DEBUG SQL:393 - select hotel0_.HOTEL_ID as HOTEL1_3_0_, hotel0_.HOTEL_NAME as HOTEL2_3_0_, hotel0_.DESCRIPTION as DESCRIPT3_3_0_, hotel0_.CHARACTERISTIC as CHARACTE4_3_0_, hotel0_.STAR_CLASS as STAR5_3_0_, hotel0_.ESTABLISH_DATE as ESTABLISH6_3_0_, hotel0_.BUSINESS_LICENSE as BUSINESS7_3_0_, hotel0_.LEGAL_PERSON as LEGAL8_3_0_, hotel0_.ADDRESS as ADDRESS3_0_, hotel0_.PHONE as PHONE3_0_, hotel0_.EMAIL as EMAIL3_0_, hotel0_.INTERNET_ADDRESS as INTERNET12_3_0_, hotel0_.HOTEL_LOG as HOTEL13_3_0_, hotel0_.COPYRIGHT as COPYRIGHT3_0_, hotel0_.NOTES as NOTES3_0_, hotel0_.CUR_ORDERFORM_ID as CUR16_3_0_ from hbs.hbs_hotel hotel0_ where hotel0_.HOTEL_ID=?
03:35:16,625 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:35:16,625 DEBUG SQL:393 - update hbs.hbs_hotel set HOTEL_NAME=?, DESCRIPTION=?, CHARACTERISTIC=?, STAR_CLASS=?, ESTABLISH_DATE=?, BUSINESS_LICENSE=?, LEGAL_PERSON=?, ADDRESS=?, PHONE=?, EMAIL=?, INTERNET_ADDRESS=?, HOTEL_LOG=?, COPYRIGHT=?, NOTES=?, CUR_ORDERFORM_ID=? where HOTEL_ID=?
03:35:16,640 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:35:16,640 DEBUG TransactionInterceptor:305 - Completing transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:35:16,640 DEBUG HibernateTransactionManager:776 - Triggering beforeCommit synchronization
03:35:16,640 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:35:16,640 DEBUG HibernateTransactionManager:609 - Initiating transaction commit
03:35:16,640 DEBUG HibernateTransactionManager:557 - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@eeb406]
03:35:16,671 DEBUG HibernateTransactionManager:802 - Triggering afterCommit synchronization
03:35:16,671 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:35:16,671 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:35:16,671 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] from thread [http-8088-Processor25]
03:35:16,671 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@16d03ba] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:35:16,671 DEBUG HibernateTransactionManager:636 - Closing Hibernate Session [org.hibernate.impl.SessionImpl@eeb406] after transaction
03:35:16,671 DEBUG SessionFactoryUtils:781 - Closing Hibernate Session
03:35:16,671 DEBUG HibernateTransactionManager:870 - Resuming suspended transaction
03:35:16,671 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] to thread [http-8088-Processor25]
03:35:16,671 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:35:16,671 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
记录日志结束
03:35:16,671 DEBUG TransactionInterceptor:320 - Completing transaction for [com.hbs.customer.CustomerService.customerLogin] after exception: com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:35:16,671 DEBUG RuleBasedTransactionAttribute:130 - Applying rules to determine whether transaction should rollback on com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:35:16,687 DEBUG RuleBasedTransactionAttribute:148 - Winning rollback rule is: RollbackRuleAttribute with pattern [Exception]
03:35:16,687 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:35:16,687 DEBUG HibernateTransactionManager:700 - Initiating transaction rollback
03:35:16,687 DEBUG HibernateTransactionManager:576 - Rolling back Hibernate transaction on Session [org.hibernate.impl.SessionImpl@dfbabd]
03:35:16,687 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:35:16,687 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:35:16,687 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:35:16,687 DEBUG HibernateTransactionManager:643 - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@dfbabd] after transaction
03:35:16,687 WARN ActionMapping:74 - Unable to find 'null' forward.
03:35:16,687 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] from thread [http-8088-Processor25]
03:35:16,687 DEBUG OpenSessionInViewFilter:221 - Closing single Hibernate Session in OpenSessionInViewFilter
03:35:16,687 DEBUG SessionFactoryUtils:781 - Closing Hibernate Session
从中可以看出，log异常拦截器在用户登录的事务回滚之前截获异常，在记录日志时，日志记录的service方法也在spring的事务管理之下，用户登录的事务还没有结束，根据REQUIRES_NEW特性，spring会新开一个事务，这时原来的数据库连接已经在一个事务中，一个连接不可能同时有两个事务，所以同时新创建一个session连接（虽然我使用了OpenSessionInViewFilter，并且session是单例的），日志记录就在新建的事务和session中进行，完了提交，并且会把新建的session连接关闭。
然后继续进行被中断的用户登录的事务管理操作，由于抛异常spring将用户登录的事务回滚。
这样能够实现预想的功能，但是如果我去掉指定的REQUIRES_NEW，那么log记录的操作会继续在用户登录的事务中进行，最后会被一起回滚。
如果我把事务管理的order设为2，log拦截器的order设为1，也就是log拦截器在事务管理拦截器的外面，会在事务管理拦截器前后执行完了再执行log的异常拦截器，打印信息如下：
03:53:46,125 DEBUG OpenSessionInViewFilter:253 - Using SessionFactory 'sessionFactory' for OpenSessionInViewFilter
03:53:46,156 DEBUG OpenSessionInViewFilter:196 - Opening single Hibernate Session in OpenSessionInViewFilter
03:53:46,156 DEBUG SessionFactoryUtils:333 - Opening Hibernate Session
03:53:46,265 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] to thread [http-8088-Processor25]
03:53:46,296 INFO ComposableRequestProcessor:144 - Initializing composable request processor for module prefix ''
03:53:46,375 INFO CreateAction:65 - Initialize action of type: org.springframework.web.struts.DelegatingActionProxy
03:53:46,406 INFO JdbcTransactionObjectSupport:60 - JDBC 3.0 Savepoint class is available
03:53:46,406 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,406 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@c21d01] for Hibernate transaction
03:53:46,406 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@1fe6783]
03:53:46,406 DEBUG HibernateTransactionManager:320 - Creating new transaction with name [com.hbs.customer.CustomerService.customerLogin]
03:53:46,421 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,468 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@16c02df]
03:53:46,468 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@30803a] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:53:46,468 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:53:46,484 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.customer.CustomerService.customerLogin]
用户登录
03:53:46,500 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,500 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,515 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:53:46,531 DEBUG SQL:393 - select this_.CUSTOMER_ID as CUSTOMER1_5_0_, this_.CUSTOMER_GROUP_ID as CUSTOMER2_5_0_, this_.CUSTOMER_PASSWORD as CUSTOMER3_5_0_, this_.CUSTOMER_NAME as CUSTOMER4_5_0_, this_.CUSTOMER_DESCRIPTION as CUSTOMER5_5_0_, this_.CUSTOMER_KIND as CUSTOMER6_5_0_, this_.CUSTOMER_SEX as CUSTOMER7_5_0_, this_.PHONE as PHONE5_0_, this_.MOBILE as MOBILE5_0_, this_.ADDRESS as ADDRESS5_0_, this_.EMAIL as EMAIL5_0_, this_.CONFIRM_TYPE as CONFIRM12_5_0_, this_.CREATE_TIME as CREATE13_5_0_, this_.GROUP_TIME as GROUP14_5_0_, this_.FIRST_TIME as FIRST15_5_0_, this_.LAST_TIME as LAST16_5_0_, this_.LOGIN_COUNT as LOGIN17_5_0_, this_.CREDIT_VALUE as CREDIT18_5_0_, this_.CUMULATE_VALUE as CUMULATE19_5_0_, this_.STATUS as STATUS5_0_, this_.NOTES as NOTES5_0_ from hbs.hbs_customer this_ where this_.CUSTOMER_ID=? and this_.CUSTOMER_PASSWORD=?
03:53:46,593 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:53:46,593 DEBUG TransactionInterceptor:320 - Completing transaction for [com.hbs.customer.CustomerService.customerLogin] after exception: com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:53:46,609 DEBUG RuleBasedTransactionAttribute:130 - Applying rules to determine whether transaction should rollback on com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:53:46,609 DEBUG RuleBasedTransactionAttribute:148 - Winning rollback rule is: RollbackRuleAttribute with pattern [Exception]
03:53:46,609 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:53:46,609 DEBUG HibernateTransactionManager:700 - Initiating transaction rollback
03:53:46,609 DEBUG HibernateTransactionManager:576 - Rolling back Hibernate transaction on Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,609 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:53:46,609 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:53:46,609 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@30803a] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:53:46,625 DEBUG HibernateTransactionManager:643 - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@c21d01] after transaction
记录日志开始
03:53:46,640 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,640 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@c21d01] for Hibernate transaction
03:53:46,640 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@1f68336]
03:53:46,640 DEBUG HibernateTransactionManager:320 - Creating new transaction with name [com.hbs.eventlog.EventLogService.eventLog]
03:53:46,640 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,640 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@16c02df]
03:53:46,640 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@1205042] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:53:46,656 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:53:46,656 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:53:46,656 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,656 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,656 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:53:46,656 DEBUG SQL:393 - select hotel0_.HOTEL_ID as HOTEL1_3_0_, hotel0_.HOTEL_NAME as HOTEL2_3_0_, hotel0_.DESCRIPTION as DESCRIPT3_3_0_, hotel0_.CHARACTERISTIC as CHARACTE4_3_0_, hotel0_.STAR_CLASS as STAR5_3_0_, hotel0_.ESTABLISH_DATE as ESTABLISH6_3_0_, hotel0_.BUSINESS_LICENSE as BUSINESS7_3_0_, hotel0_.LEGAL_PERSON as LEGAL8_3_0_, hotel0_.ADDRESS as ADDRESS3_0_, hotel0_.PHONE as PHONE3_0_, hotel0_.EMAIL as EMAIL3_0_, hotel0_.INTERNET_ADDRESS as INTERNET12_3_0_, hotel0_.HOTEL_LOG as HOTEL13_3_0_, hotel0_.COPYRIGHT as COPYRIGHT3_0_, hotel0_.NOTES as NOTES3_0_, hotel0_.CUR_ORDERFORM_ID as CUR16_3_0_ from hbs.hbs_hotel hotel0_ where hotel0_.HOTEL_ID=?
03:53:46,718 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:53:46,734 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,734 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,734 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:53:46,812 DEBUG SQL:393 - update hbs.hbs_hotel set HOTEL_NAME=?, DESCRIPTION=?, CHARACTERISTIC=?, STAR_CLASS=?, ESTABLISH_DATE=?, BUSINESS_LICENSE=?, LEGAL_PERSON=?, ADDRESS=?, PHONE=?, EMAIL=?, INTERNET_ADDRESS=?, HOTEL_LOG=?, COPYRIGHT=?, NOTES=?, CUR_ORDERFORM_ID=? where HOTEL_ID=?
03:53:46,812 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:53:46,812 DEBUG TransactionInterceptor:305 - Completing transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:53:46,812 DEBUG HibernateTransactionManager:776 - Triggering beforeCommit synchronization
03:53:46,812 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:53:46,812 DEBUG HibernateTransactionManager:609 - Initiating transaction commit
03:53:46,812 DEBUG HibernateTransactionManager:557 - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,859 DEBUG HibernateTransactionManager:802 - Triggering afterCommit synchronization
03:53:46,859 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:53:46,859 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:53:46,859 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@1205042] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:53:46,859 DEBUG HibernateTransactionManager:643 - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@c21d01] after transaction
记录日志结束
03:53:46,859 WARN ActionMapping:74 - Unable to find 'null' forward.
03:53:46,859 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] from thread [http-8088-Processor25]
03:53:46,859 DEBUG OpenSessionInViewFilter:221 - Closing single Hibernate Session in OpenSessionInViewFilter
03:53:46,875 DEBUG SessionFactoryUtils:781 - Closing Hibernate Session
可以看出，用户登录的事务和日志记录的事务是前后两个不相关的事务，并且在日志记录事务中并不需要新建session连接，而是直接用在OpenSessionInViewFilter中创建的session。实际上这时也并不需要将propagation设为REQUIRES_NEW，使用默认的REQUIRES也照样能够正常工作。
所以应该将该异常拦截器设在事务管理拦截器的外面，即使用Order接口排在前面。
大家知道spring中的事务管理是通过AOP代理来实现的，对被代理对象的每个方法进行拦截，在方法执行前启动事务，方法执行完后根据是否有异常和异常的种类进行提交或回滚。
如果要在方法执行前或后或抛出异常后加上一个自己的拦截器，或者一个环绕拦截器，在拦截器中执行一些操作，比如执行一些数据库操作，记录一些信息，这些操作通过调用一个服务类的方法来执行，这个方法也在spring事务管理拦截器的管理之下，那么这个记录方法需要在另一个事务中进行，而不是与被拦截方法在同一个事务中，不然如果被拦截方法抛出异常需要回滚时，所作的记录也会被回滚，当然有时候确实需要同时回滚，那就要放在同一个事务中。
这和自己的拦截器和事务管理的拦截器的执行顺序有一定关系，spring事务管理拦截器是一个环绕通知，在被拦截方法执行前启动事务，执行后完成事务，如果自己的拦截器被spring事务管理拦截器包围在里面，那么在自己的拦截器运行时，spring已经启动了一个事务，如果你的记录信息方法需要与被拦截方法同在一个事务中，将你的记录信息方法的事务传播属性设为默认的REQUIRED就可以了；
如果你记录信息的方法需要单独的一个事务环境，那就要把事务传播属性设为REQUIRES_NEW了，这样spring事务管理器会新建一个事务，并且新建一个session连接，因为一个数据库连接不可能同时有两个事务，记录信息完了提交事务并且把新建的session连接关闭，自己的拦截器退出后继续执行被拦截的方法或它的事务处理。
相反如果自己的拦截器在spring事务管理拦截器的外面，那么记录信息的方法会在一个单独的事务中执行，并提交，不管它的事务传播属性是REQUIRES_NEW还是REQUIRED，因为与被拦截方法的事务处理没有交叉，并且可以使用同一个session连接如果是OpenSessionInViewFilter。
所以如果记录信息和被拦截方法要在不同事务中执行，分别提交，那么最好将自己的拦截器设在spring事务管理器拦截器的外面；如果需要将记录信息和被拦截方法在同一个事务中处理，必须将自己的拦截器被包围在spring事务管理拦截器中，并且记录信息方法的事务传播属性为默认的REQUIRED。
设置拦截器的执行顺序可以让拦截器处理类实现org.springframework.core.Ordered接口，在spring配置文件的AOP设置中设定自己的拦截器和spring事务管理拦截器的执行顺序，将自己的拦截的序号排在spring事务管理的前面，就可以将该拦截器放到事务管理拦截器的外面执行了，对于before通知方式会先于事务管理拦截器执行，对于after returning和after和after throwing通知方式会后于事务管理拦截器的执行，对于arount通知方式会包围事务管理拦截器执行。
下面是一个异常拦截器的例子。
有位朋友提到在spring异常拦截器中更新数据不能够提交，做了一下测试，测试环境基本是这样：一个用户登录的功能，spring对service中的每个方法进行事务管理，在用户检测的service方法上同时加上一个异常拦截器，当用户不存在或密码不正确时用户检测方法会抛出异常，异常拦截器捕获到该异常，同时记录一些日志。
spring配置文件相关：
<!-- 事务管理 --> <bean id="transactionManager" class="org.springframework.orm.hibernate3.HibernateTransactionManager"> <property name="sessionFactory" ref="sessionFactory"></property> </bean> <!-- 事务通知 --> <tx:advice id="txAdvice" transaction-manager="transactionManager"> <tx:attributes> <tx:method name="get*" read-only="true"/> <tx:method name="*" propagation="REQUIRES_NEW" rollback-for="Exception"/> </tx:attributes> </tx:advice> <!-- aop代理设置 --> <aop:config proxy-target-class="true"> <aop:pointcut id="txPointcut" expression="execution(* com.hbs..*Service.*(..))"/> <aop:pointcut id="logPointcut" expression="execution(* com.hbs.customer..*Service.*(..))"/> <aop:advisor advice-ref="txAdvice" pointcut-ref="txPointcut" order="1"/> <aop:aspect id="logAspect" ref="logInterceptor" order="2" > <aop:after-throwing pointcut-ref="logPointcut" method="serviceIntercept" /> </aop:aspect> </aop:config> <!-- log拦截器类 --> <bean id="logInterceptor" class="com.hbs.eventlog.EventLogInterceptor"> <property name="service" ref="logService"></property> </bean>
拦截器类：
public class EventLogInterceptor implements Ordered {
private int order = 1;
private EventLogService service;
public Object serviceIntercept(ProceedingJoinPoint point) throws Throwable{
if(point instanceof MethodInvocationProceedingJoinPoint){
MethodInvocationProceedingJoinPoint mpoint = (MethodInvocationProceedingJoinPoint)point;
//
}
try {
System.out.println("记录日志开始");
service.eventLog();
System.out.println("记录日志结束");
}catch(Exception ex) {
ex.printStackTrace();
}
return null;
}
public void setOrder(int order){
this.order = order;
}
public int getOrder() {
return order;
}
public EventLogService getService() {
return service;
}
public void setService(EventLogService service) {
this.service = service;
}
}
service方法中的事务传播属性都设为要求新建事务，spring事务管理切面拦截器的order设为1，而log拦截器的order设为2，这意味着这两个要同时执行时，先执行事务拦截器，后执行log拦截器，由于事务管理是一个环绕通知（around），实际上是log拦截器被包围在事务管理拦截器中。
一个不正确的用户登录时，打印的日志：
03:35:16,562 DEBUG OpenSessionInViewFilter:253 - Using SessionFactory 'sessionFactory' for OpenSessionInViewFilter
03:35:16,562 DEBUG OpenSessionInViewFilter:196 - Opening single Hibernate Session in OpenSessionInViewFilter
03:35:16,562 DEBUG SessionFactoryUtils:333 - Opening Hibernate Session
03:35:16,562 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] to thread [http-8088-Processor25]
03:35:16,562 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,562 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@dfbabd] for Hibernate transaction
03:35:16,578 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@5cd7f9]
03:35:16,578 DEBUG HibernateTransactionManager:320 - Creating new transaction with name [com.hbs.customer.CustomerService.customerLogin]
03:35:16,578 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@dfbabd]
03:35:16,578 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@1501026]
03:35:16,578 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:35:16,578 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:35:16,578 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.customer.CustomerService.customerLogin]
用户登录
03:35:16,578 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,578 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,578 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:35:16,578 DEBUG SQL:393 - select this_.CUSTOMER_ID as CUSTOMER1_5_0_, this_.CUSTOMER_GROUP_ID as CUSTOMER2_5_0_, this_.CUSTOMER_PASSWORD as CUSTOMER3_5_0_, this_.CUSTOMER_NAME as CUSTOMER4_5_0_, this_.CUSTOMER_DESCRIPTION as CUSTOMER5_5_0_, this_.CUSTOMER_KIND as CUSTOMER6_5_0_, this_.CUSTOMER_SEX as CUSTOMER7_5_0_, this_.PHONE as PHONE5_0_, this_.MOBILE as MOBILE5_0_, this_.ADDRESS as ADDRESS5_0_, this_.EMAIL as EMAIL5_0_, this_.CONFIRM_TYPE as CONFIRM12_5_0_, this_.CREATE_TIME as CREATE13_5_0_, this_.GROUP_TIME as GROUP14_5_0_, this_.FIRST_TIME as FIRST15_5_0_, this_.LAST_TIME as LAST16_5_0_, this_.LOGIN_COUNT as LOGIN17_5_0_, this_.CREDIT_VALUE as CREDIT18_5_0_, this_.CUMULATE_VALUE as CUMULATE19_5_0_, this_.STATUS as STATUS5_0_, this_.NOTES as NOTES5_0_ from hbs.hbs_customer this_ where this_.CUSTOMER_ID=? and this_.CUSTOMER_PASSWORD=?
03:35:16,593 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
记录日志开始
03:35:16,593 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,593 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@dfbabd] for Hibernate transaction
03:35:16,593 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] bound to thread [http-8088-Processor25]
03:35:16,593 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@5ec940]
03:35:16,593 DEBUG HibernateTransactionManager:358 - Suspending current transaction, creating new transaction with name [com.hbs.eventlog.EventLogService.eventLog]
03:35:16,593 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:35:16,593 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] from thread [http-8088-Processor25]
03:35:16,609 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:35:16,609 DEBUG HibernateTransactionManager:428 - Opened new Session [org.hibernate.impl.SessionImpl@eeb406] for Hibernate transaction
03:35:16,609 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@eeb406]
03:35:16,609 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@8543aa]
03:35:16,609 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@16d03ba] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:35:16,609 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] to thread [http-8088-Processor25]
03:35:16,609 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:35:16,609 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:35:16,625 DEBUG SQL:393 - select hotel0_.HOTEL_ID as HOTEL1_3_0_, hotel0_.HOTEL_NAME as HOTEL2_3_0_, hotel0_.DESCRIPTION as DESCRIPT3_3_0_, hotel0_.CHARACTERISTIC as CHARACTE4_3_0_, hotel0_.STAR_CLASS as STAR5_3_0_, hotel0_.ESTABLISH_DATE as ESTABLISH6_3_0_, hotel0_.BUSINESS_LICENSE as BUSINESS7_3_0_, hotel0_.LEGAL_PERSON as LEGAL8_3_0_, hotel0_.ADDRESS as ADDRESS3_0_, hotel0_.PHONE as PHONE3_0_, hotel0_.EMAIL as EMAIL3_0_, hotel0_.INTERNET_ADDRESS as INTERNET12_3_0_, hotel0_.HOTEL_LOG as HOTEL13_3_0_, hotel0_.COPYRIGHT as COPYRIGHT3_0_, hotel0_.NOTES as NOTES3_0_, hotel0_.CUR_ORDERFORM_ID as CUR16_3_0_ from hbs.hbs_hotel hotel0_ where hotel0_.HOTEL_ID=?
03:35:16,625 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] bound to thread [http-8088-Processor25]
03:35:16,625 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:35:16,625 DEBUG SQL:393 - update hbs.hbs_hotel set HOTEL_NAME=?, DESCRIPTION=?, CHARACTERISTIC=?, STAR_CLASS=?, ESTABLISH_DATE=?, BUSINESS_LICENSE=?, LEGAL_PERSON=?, ADDRESS=?, PHONE=?, EMAIL=?, INTERNET_ADDRESS=?, HOTEL_LOG=?, COPYRIGHT=?, NOTES=?, CUR_ORDERFORM_ID=? where HOTEL_ID=?
03:35:16,640 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:35:16,640 DEBUG TransactionInterceptor:305 - Completing transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:35:16,640 DEBUG HibernateTransactionManager:776 - Triggering beforeCommit synchronization
03:35:16,640 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:35:16,640 DEBUG HibernateTransactionManager:609 - Initiating transaction commit
03:35:16,640 DEBUG HibernateTransactionManager:557 - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@eeb406]
03:35:16,671 DEBUG HibernateTransactionManager:802 - Triggering afterCommit synchronization
03:35:16,671 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:35:16,671 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:35:16,671 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@fbfa2] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] from thread [http-8088-Processor25]
03:35:16,671 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@16d03ba] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:35:16,671 DEBUG HibernateTransactionManager:636 - Closing Hibernate Session [org.hibernate.impl.SessionImpl@eeb406] after transaction
03:35:16,671 DEBUG SessionFactoryUtils:781 - Closing Hibernate Session
03:35:16,671 DEBUG HibernateTransactionManager:870 - Resuming suspended transaction
03:35:16,671 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] to thread [http-8088-Processor25]
03:35:16,671 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:35:16,671 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
记录日志结束
03:35:16,671 DEBUG TransactionInterceptor:320 - Completing transaction for [com.hbs.customer.CustomerService.customerLogin] after exception: com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:35:16,671 DEBUG RuleBasedTransactionAttribute:130 - Applying rules to determine whether transaction should rollback on com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:35:16,687 DEBUG RuleBasedTransactionAttribute:148 - Winning rollback rule is: RollbackRuleAttribute with pattern [Exception]
03:35:16,687 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:35:16,687 DEBUG HibernateTransactionManager:700 - Initiating transaction rollback
03:35:16,687 DEBUG HibernateTransactionManager:576 - Rolling back Hibernate transaction on Session [org.hibernate.impl.SessionImpl@dfbabd]
03:35:16,687 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:35:16,687 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:35:16,687 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@1672c01] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:35:16,687 DEBUG HibernateTransactionManager:643 - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@dfbabd] after transaction
03:35:16,687 WARN ActionMapping:74 - Unable to find 'null' forward.
03:35:16,687 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@1fee2db] for key [org.hibernate.impl.SessionFactoryImpl@1fe3238] from thread [http-8088-Processor25]
03:35:16,687 DEBUG OpenSessionInViewFilter:221 - Closing single Hibernate Session in OpenSessionInViewFilter
03:35:16,687 DEBUG SessionFactoryUtils:781 - Closing Hibernate Session
从中可以看出，log异常拦截器在用户登录的事务回滚之前截获异常，在记录日志时，日志记录的service方法也在spring的事务管理之下，用户登录的事务还没有结束，根据REQUIRES_NEW特性，spring会新开一个事务，这时原来的数据库连接已经在一个事务中，一个连接不可能同时有两个事务，所以同时新创建一个session连接（虽然我使用了OpenSessionInViewFilter，并且session是单例的），日志记录就在新建的事务和session中进行，完了提交，并且会把新建的session连接关闭。
然后继续进行被中断的用户登录的事务管理操作，由于抛异常spring将用户登录的事务回滚。
这样能够实现预想的功能，但是如果我去掉指定的REQUIRES_NEW，那么log记录的操作会继续在用户登录的事务中进行，最后会被一起回滚。
如果我把事务管理的order设为2，log拦截器的order设为1，也就是log拦截器在事务管理拦截器的外面，会在事务管理拦截器前后执行完了再执行log的异常拦截器，打印信息如下：
03:53:46,125 DEBUG OpenSessionInViewFilter:253 - Using SessionFactory 'sessionFactory' for OpenSessionInViewFilter
03:53:46,156 DEBUG OpenSessionInViewFilter:196 - Opening single Hibernate Session in OpenSessionInViewFilter
03:53:46,156 DEBUG SessionFactoryUtils:333 - Opening Hibernate Session
03:53:46,265 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] to thread [http-8088-Processor25]
03:53:46,296 INFO ComposableRequestProcessor:144 - Initializing composable request processor for module prefix ''
03:53:46,375 INFO CreateAction:65 - Initialize action of type: org.springframework.web.struts.DelegatingActionProxy
03:53:46,406 INFO JdbcTransactionObjectSupport:60 - JDBC 3.0 Savepoint class is available
03:53:46,406 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,406 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@c21d01] for Hibernate transaction
03:53:46,406 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@1fe6783]
03:53:46,406 DEBUG HibernateTransactionManager:320 - Creating new transaction with name [com.hbs.customer.CustomerService.customerLogin]
03:53:46,421 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,468 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@16c02df]
03:53:46,468 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@30803a] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:53:46,468 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:53:46,484 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.customer.CustomerService.customerLogin]
用户登录
03:53:46,500 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,500 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,515 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:53:46,531 DEBUG SQL:393 - select this_.CUSTOMER_ID as CUSTOMER1_5_0_, this_.CUSTOMER_GROUP_ID as CUSTOMER2_5_0_, this_.CUSTOMER_PASSWORD as CUSTOMER3_5_0_, this_.CUSTOMER_NAME as CUSTOMER4_5_0_, this_.CUSTOMER_DESCRIPTION as CUSTOMER5_5_0_, this_.CUSTOMER_KIND as CUSTOMER6_5_0_, this_.CUSTOMER_SEX as CUSTOMER7_5_0_, this_.PHONE as PHONE5_0_, this_.MOBILE as MOBILE5_0_, this_.ADDRESS as ADDRESS5_0_, this_.EMAIL as EMAIL5_0_, this_.CONFIRM_TYPE as CONFIRM12_5_0_, this_.CREATE_TIME as CREATE13_5_0_, this_.GROUP_TIME as GROUP14_5_0_, this_.FIRST_TIME as FIRST15_5_0_, this_.LAST_TIME as LAST16_5_0_, this_.LOGIN_COUNT as LOGIN17_5_0_, this_.CREDIT_VALUE as CREDIT18_5_0_, this_.CUMULATE_VALUE as CUMULATE19_5_0_, this_.STATUS as STATUS5_0_, this_.NOTES as NOTES5_0_ from hbs.hbs_customer this_ where this_.CUSTOMER_ID=? and this_.CUSTOMER_PASSWORD=?
03:53:46,593 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:53:46,593 DEBUG TransactionInterceptor:320 - Completing transaction for [com.hbs.customer.CustomerService.customerLogin] after exception: com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:53:46,609 DEBUG RuleBasedTransactionAttribute:130 - Applying rules to determine whether transaction should rollback on com.hbs.common.ResultException: 登录失败！用户名或密码不正确
03:53:46,609 DEBUG RuleBasedTransactionAttribute:148 - Winning rollback rule is: RollbackRuleAttribute with pattern [Exception]
03:53:46,609 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:53:46,609 DEBUG HibernateTransactionManager:700 - Initiating transaction rollback
03:53:46,609 DEBUG HibernateTransactionManager:576 - Rolling back Hibernate transaction on Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,609 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:53:46,609 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:53:46,609 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@30803a] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:53:46,625 DEBUG HibernateTransactionManager:643 - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@c21d01] after transaction
记录日志开始
03:53:46,640 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,640 DEBUG HibernateTransactionManager:390 - Found thread-bound Session [org.hibernate.impl.SessionImpl@c21d01] for Hibernate transaction
03:53:46,640 DEBUG HibernateTransactionManager:292 - Using transaction object [org.springframework.orm.hibernate3.HibernateTransactionManager$HibernateTransactionObject@1f68336]
03:53:46,640 DEBUG HibernateTransactionManager:320 - Creating new transaction with name [com.hbs.eventlog.EventLogService.eventLog]
03:53:46,640 DEBUG HibernateTransactionManager:440 - Preparing JDBC Connection of Hibernate Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,640 DEBUG HibernateTransactionManager:510 - Exposing Hibernate transaction as JDBC transaction [org.apache.commons.dbcp.PoolableConnection@16c02df]
03:53:46,640 DEBUG TransactionSynchronizationManager:166 - Bound value [org.springframework.jdbc.datasource.ConnectionHolder@1205042] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] to thread [http-8088-Processor25]
03:53:46,656 DEBUG TransactionSynchronizationManager:219 - Initializing transaction synchronization
03:53:46,656 DEBUG TransactionInterceptor:275 - Getting transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:53:46,656 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,656 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,656 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:53:46,656 DEBUG SQL:393 - select hotel0_.HOTEL_ID as HOTEL1_3_0_, hotel0_.HOTEL_NAME as HOTEL2_3_0_, hotel0_.DESCRIPTION as DESCRIPT3_3_0_, hotel0_.CHARACTERISTIC as CHARACTE4_3_0_, hotel0_.STAR_CLASS as STAR5_3_0_, hotel0_.ESTABLISH_DATE as ESTABLISH6_3_0_, hotel0_.BUSINESS_LICENSE as BUSINESS7_3_0_, hotel0_.LEGAL_PERSON as LEGAL8_3_0_, hotel0_.ADDRESS as ADDRESS3_0_, hotel0_.PHONE as PHONE3_0_, hotel0_.EMAIL as EMAIL3_0_, hotel0_.INTERNET_ADDRESS as INTERNET12_3_0_, hotel0_.HOTEL_LOG as HOTEL13_3_0_, hotel0_.COPYRIGHT as COPYRIGHT3_0_, hotel0_.NOTES as NOTES3_0_, hotel0_.CUR_ORDERFORM_ID as CUR16_3_0_ from hbs.hbs_hotel hotel0_ where hotel0_.HOTEL_ID=?
03:53:46,718 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:53:46,734 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,734 DEBUG TransactionSynchronizationManager:139 - Retrieved value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] bound to thread [http-8088-Processor25]
03:53:46,734 DEBUG HibernateTemplate:354 - Found thread-bound Session for HibernateTemplate
03:53:46,812 DEBUG SQL:393 - update hbs.hbs_hotel set HOTEL_NAME=?, DESCRIPTION=?, CHARACTERISTIC=?, STAR_CLASS=?, ESTABLISH_DATE=?, BUSINESS_LICENSE=?, LEGAL_PERSON=?, ADDRESS=?, PHONE=?, EMAIL=?, INTERNET_ADDRESS=?, HOTEL_LOG=?, COPYRIGHT=?, NOTES=?, CUR_ORDERFORM_ID=? where HOTEL_ID=?
03:53:46,812 DEBUG HibernateTemplate:378 - Not closing pre-bound Hibernate Session after HibernateTemplate
03:53:46,812 DEBUG TransactionInterceptor:305 - Completing transaction for [com.hbs.eventlog.EventLogService.eventLog]
03:53:46,812 DEBUG HibernateTransactionManager:776 - Triggering beforeCommit synchronization
03:53:46,812 DEBUG HibernateTransactionManager:789 - Triggering beforeCompletion synchronization
03:53:46,812 DEBUG HibernateTransactionManager:609 - Initiating transaction commit
03:53:46,812 DEBUG HibernateTransactionManager:557 - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@c21d01]
03:53:46,859 DEBUG HibernateTransactionManager:802 - Triggering afterCommit synchronization
03:53:46,859 DEBUG HibernateTransactionManager:818 - Triggering afterCompletion synchronization
03:53:46,859 DEBUG TransactionSynchronizationManager:272 - Clearing transaction synchronization
03:53:46,859 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.jdbc.datasource.ConnectionHolder@1205042] for key [org.apache.commons.dbcp.BasicDataSource@54cbb9] from thread [http-8088-Processor25]
03:53:46,859 DEBUG HibernateTransactionManager:643 - Not closing pre-bound Hibernate Session [org.hibernate.impl.SessionImpl@c21d01] after transaction
记录日志结束
03:53:46,859 WARN ActionMapping:74 - Unable to find 'null' forward.
03:53:46,859 DEBUG TransactionSynchronizationManager:190 - Removed value [org.springframework.orm.hibernate3.SessionHolder@889c4e] for key [org.hibernate.impl.SessionFactoryImpl@cdf872] from thread [http-8088-Processor25]
03:53:46,859 DEBUG OpenSessionInViewFilter:221 - Closing single Hibernate Session in OpenSessionInViewFilter
03:53:46,875 DEBUG SessionFactoryUtils:781 - Closing Hibernate Session
可以看出，用户登录的事务和日志记录的事务是前后两个不相关的事务，并且在日志记录事务中并不需要新建session连接，而是直接用在OpenSessionInViewFilter中创建的session。实际上这时也并不需要将propagation设为REQUIRES_NEW，使用默认的REQUIRES也照样能够正常工作。
所以应该将该异常拦截器设在事务管理拦截器的外面，即使用Order接口排在前面。
分享到：
发表评论
相关推荐
内含有mybatis 拦截器实现的分页代码，spring 的事务和aop 测试、和反射工具类
springMVC+Mybatis3.1+spring3.1.2（包含事务详解,代码诠释，含数据库文件...展示了增、删、改、查、注解、拦截器、spring事务配置(亲测成功)，sql文 件！！赶紧来下载给好评！！！ web project 完全可以跑起来！！！
spring事务管理几种方式代码实例：涉及编程式事务，声明式事务之拦截器代理方式、AOP切面通知方式、AspectJ注解方式，通过不同方式实例代码展现，总结spring事务管理的一般规律，从宏观上加深理解spring事务管理特性...
在Spring中，事务管理是通过一系列的拦截器和事务管理器来实现的。当一个被@Transactional注解的方法被调用时，Spring会创建一个代理来包装该方法，确保事务的正确开始和结束。这种代理机制基于Spring AOP实现，能够...
Spring配置文件中关于事务配置总是由三个组成部分，分别是DataSource、TransactionManager和代理机制这三部分，无论哪种配置方式，一般变化的只是代理机制这部分。 DataSource、TransactionManager这两部分只是会...
Spring源代码解析（七）：Spring AOP中对拦截器调用的实现 Spring源代码解析（八）：Spring驱动Hibernate的实现 Spring源代码解析（九）：Spring Acegi框架鉴权的实现 Spring源代码解析（十）：Spring Acegi框架授权...
这是在java里使用到spring的配置文件里，添加事务处理过程，以至于可以回滚事务，当中使用到拦截器。
一、 XML，使用tx标签配置拦截器实现事务 一、 Annotation方式 以下所使用环境为Spring4.0.3、Hibernate4.3.5
Spring源代码解析（七）：Spring AOP中对拦截器调用的实现 8. Spring源代码解析（八）：Spring驱动Hibernate的实现 9.Spring源代码解析（九）：Spring Acegi框架鉴权的实现 10. Spring源代码解析（十）：Spring ...
XWork 拦截器体系 输入校验 国际化支持 Webwork2 in Spring Struts in Spring 数据持久层 事务管理 持久层封装 JDBC Hibernate in Spring ibatis in Spring Aspect Oriented Programming AOP 概念 ...
-- 事务拦截器bean需要依赖注入一个事务管理器 --> <!-- 下面定义事务传播属性 [ bus* 事务的方法名]--> *">PROPAGATION_REQUIRED <!-- 定义BeanNameAutoProxyCreator,该bean是个bean后...
13.4.3. 拦截器（HandlerInterceptor） 13.5. 视图与视图解析 13.5.1. 视图解析器 13.5.2. 视图解析链 13.5.3. 重定向(Rediret)到另一个视图 13.5.3.1. RedirectView 13.5.3.2. redirect:前缀 13.5.3.3. forward:...
Spring源代码解析（七）：Spring AOP中对拦截器调用的实现 Spring源代码解析（八）：Spring驱动Hibernate的实现 Spring源代码解析（九）：Spring Acegi框架鉴权的实现 Spring源代码解析（十）：Spring Acegi框架授权...
Spring源代码解析（七）：Spring AOP中对拦截器调用的实现.doc Spring源代码解析（八）：Spring驱动Hibernate的实现.doc Spring源代码解析（九）：Spring Acegi框架鉴权的实现.doc Spring源代码解析（十）：Spring ...
14.5.1.理解Spring.NET声明式事务管理的实现 14.5.2.第一个例子 14.5.3.Transaction特性的设置 14.5.4.通过AutoProxyCreator使用声明式事务 14.5.5.通过TransactionProxyFactoryObject使用声明式事务 14.5.6. 通过...
13.4.3. 拦截器（HandlerInterceptor） 13.5. 视图与视图解析 13.5.1. 视图解析器（ViewResolver） 13.5.2. 视图解析链 13.5.3. 重定向（Rediret）到另一个视图 13.6. 本地化解析器 13.6.1. ...
SSM后台整合（Spring+SpringMvc+Mybtis+事务+Rest风格+统一结果封装+统一异常处理+拦截器） 适合新手练习，熟悉ssm框架 也适合需要进行ssm框架开发的同学，直接无需搭建框架，拿来即用哦
2）、事务拦截器： TransactionInterceptor；保存了事务属性信息，事务管理器； 他是一个 MethodInterceptor； 在目标方法执行的时候； 执行拦截器链； 事务拦截器： 1）、先获取事务相关的属性 2）、再获取...
Spring 支持可插拔的事务管理器，可以给您的事务处理提供更广泛的选择范围。它集成了领先的持久性框架，并且提供一个一致的异常层次结构。Spring 还提供了一种使用面向方面代码代替正常的面向对象代码的简单机制。 ...
Spring源代码解析7：Spring AOP中对拦截器调用的实现 .doc Spring源代码解析8：Spring驱动Hibernate的实现.doc Spring源代码解析9：Spring Acegi框架鉴权的实现.doc Spring源代码解析10：Spring Acegi框架授权的实现...