Spring事务 REQUIRES_NEW、NESTED与NOT_SUPPORTED

手动创建一个异常,用来探究Spring事务处理机制。
transactionManager为DataSourceTransactionManager。
本次暂不讨论JTA <tx:jta-transaction-manager/> ,由于公司项目历史原因,不想在项目中使用Jta。

    <bean id="transactionManager" class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
        <property name="dataSource" ref="dataSource"></property>
    </bean>

分别使用Propagation.NESTED与 Propagation.REQUIRES_NEW测试发现,在一系列的操作中,两者的表现形式相同,都是Rollback了所有新增&更新操作。这是什么原因?查看spring doc发现,REQUIRES_NEW与NOT_SUPPORTED都有下面一句话,需要使用JtaTransactionManager。
Note: Actual transaction suspension will not work on out-of-the-box on all transaction managers. This in particular applies to JtaTransactionManager, which requires the javax.transaction.TransactionManager to be made available it to it (which is server-specific in standard J2EE).
但实际情况并非如此,在DataSourceTransactionManager下使用,REQUIRES_NEW没起任何作用,NOT_SUPPORTED则运行良好,正如doc所写:Execute non-transactionally, suspend the current transaction if one exists.
至于NESTED,应该是因为transaction整个都被rollback了,所以也没有commit更新。在日志中会出现如下片段:
DEBUG o.s.j.datasource.DataSourceTransactionManager - Creating nested transaction with name [com….OrderNo]
DEBUG o.s.j.datasource.DataSourceTransactionManager - Participating in existing transaction
……
DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing transaction savepoint

个人觉得在业务不是特别复杂的情况下,使用NOT_SUPPORTED更加简单一些。
在Service其中一个方法中加注解:@Transactional(propagation = Propagation.NOT_SUPPORTED)

logback日志:
10:21:38.107 [http-apr-8080-exec-6] DEBUG com.incito.logistics.common.SpecialCharFilter - process in /web/myorder/agreeRefund
10:21:38.109 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100785} Connection
10:21:38.110 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100785} Preparing Statement:      SELECT * FROM orders WHERE  id =?
10:21:38.110 [http-apr-8080-exec-6] DEBUG o.s.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
10:21:38.117 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100786} Executing Statement:      SELECT * FROM orders WHERE  id =?
10:21:38.117 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100786} Parameters: [930aebeae7c845c88bb15f985f3cde83]
10:21:38.117 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100786} Types: [java.lang.String]
10:21:38.138 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100787} ResultSet
10:21:38.139 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100787} Header: [id, completetime, generatetime, orderno, status, agentid, carid, goodsid, consigneeid, shipperid, photo, leavelocation, memo, signtime, type, refusal, ordercustom, priseid, weight, volume, goodscustom, refusalreason, refusalmemo, refusaltime, cancelreason, cancelmemo, arrstartcity]
10:21:38.139 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100787} Result: [930aebeae7c845c88bb15f985f3cde83, null, 2015-06-08 10:17:24.0, 04150608000001, 12, 36ff7818c242400db397075c87721db7, fb4db237da604688aeb1f369b5bfd45e, ad532d4b21184280bd0faec9685d1129, null, null, null, 32.08133,112.138352, null, null, 0, null, 0, null, null, null, 0, null, null, null, null, null, 0]
10:21:38.139 [http-apr-8080-exec-6] DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
10:21:38.139 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100788} Connection
10:21:38.139 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100788} Preparing Statement:    SELECT * FROM refundorders WHERE orderid=?
10:21:38.139 [http-apr-8080-exec-6] DEBUG o.s.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
10:21:38.142 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100789} Executing Statement:    SELECT * FROM refundorders WHERE orderid=?
10:21:38.142 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100789} Parameters: [930aebeae7c845c88bb15f985f3cde83]
10:21:38.143 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100789} Types: [java.lang.String]
10:21:38.147 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100790} ResultSet
10:21:38.148 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100790} Header: [id, orderid, applymoney, applytime, applyreason, applymemo, replytime, replyreason, replymemo, cancelflag, canceltime, reqthirdtime, arbitratetime, arbitrateon, arbitratememo]
10:21:38.148 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100790} Result: [614cee2768e24f7d82a5f90d6f7a58bd, 930aebeae7c845c88bb15f985f3cde83, null, 2015-06-08 10:17:54.0, 3, , null, null, null, null, null, null, null, null, null]
10:21:38.148 [http-apr-8080-exec-6] DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
10:21:38.148 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Creating new transaction with name [com.incito.logistics.service.OrderService.agreeRefund]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; '',-java.lang.Exception
10:21:38.152 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Acquired Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java] for JDBC transaction
10:21:38.155 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Switching JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java] to manual commit
10:21:38.157 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100791} Connection
10:21:38.158 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100791} Preparing Statement:      UPDATE     goods set completedate = null                               where id = ?
10:21:38.158 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100792} Executing Statement:      UPDATE     goods set completedate = null                               where id = ?
10:21:38.158 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100792} Parameters: [ad532d4b21184280bd0faec9685d1129]
10:21:38.158 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100792} Types: [java.lang.String]
10:21:38.162 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100793} Connection
10:21:38.163 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100793} Preparing Statement:      UPDATE     orders     SET        status = ?                                                        , completetime = now()                                                                                                                           WHERE     id = ?
10:21:38.163 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100794} Executing Statement:      UPDATE     orders     SET        status = ?                                                        , completetime = now()                                                                                                                           WHERE     id = ?
10:21:38.163 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100794} Parameters: [16, 930aebeae7c845c88bb15f985f3cde83]
10:21:38.163 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100794} Types: [java.lang.String, java.lang.String]
10:21:38.167 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100795} Connection
10:21:38.168 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100795} Preparing Statement:    UPDATE refundorders   SET     replytime = now()                                               WHERE id = ?
10:21:38.168 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100796} Executing Statement:    UPDATE refundorders   SET     replytime = now()                                               WHERE id = ?
10:21:38.168 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100796} Parameters: [614cee2768e24f7d82a5f90d6f7a58bd]
10:21:38.168 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100796} Types: [java.lang.String]
10:21:38.180 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100797} Connection
10:21:38.180 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100797} Preparing Statement:       SELECT count(1) FROM orders where carid = ? AND status not in (2,7,8,9,10,11,14)
10:21:38.180 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100798} Executing Statement:       SELECT count(1) FROM orders where carid = ? AND status not in (2,7,8,9,10,11,14)
10:21:38.180 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100798} Parameters: [fb4db237da604688aeb1f369b5bfd45e]
10:21:38.180 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100798} Types: [java.lang.String]
10:21:38.185 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100799} ResultSet
10:21:38.185 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100799} Header: [count(1)]
10:21:38.185 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100799} Result: [53]
10:21:38.186 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100800} Connection
10:21:38.186 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100800} Preparing Statement:      update car     SET                                                         carstatus = ?                                                                                                     where id = ?
10:21:38.187 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100801} Executing Statement:      update car     SET                                                         carstatus = ?                                                                                                     where id = ?
10:21:38.187 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100801} Parameters: [1, fb4db237da604688aeb1f369b5bfd45e]
10:21:38.187 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100801} Types: [java.lang.Integer, java.lang.String]
10:21:38.191 [http-apr-8080-exec-6] INFO  com.incito.logistics.service.OrderService - 调用银联接口退款 orderId: 930aebeae7c845c88bb15f985f3cde83
10:21:38.191 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Participating in existing transaction
10:21:38.192 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100802} Connection
10:21:38.192 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100802} Preparing Statement:      SELECT * FROM ums_paymentorder WHERE BizId=?
10:21:38.192 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100803} Executing Statement:      SELECT * FROM ums_paymentorder WHERE BizId=?
10:21:38.192 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100803} Parameters: [930aebeae7c845c88bb15f985f3cde83]
10:21:38.192 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100803} Types: [java.lang.String]
10:21:38.197 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100804} ResultSet
10:21:38.199 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100804} Header: [OrderNoMer, SrcReqId, SrcReqDate, TxnType, OrderNo, PyrUserIdMer, PyrUserType, PyeUserIdMer, PyeUserType, PyrUserId, PyeUserId, OrderAmt, OrderStatus, STATUS, StatusDesc, BizId, BizType, BizDesc, PaymentChannel, Priority, HashCode, GenerateTime, UpdateTime, OrgBizId, DrawStatus, DrawTime]
10:21:38.199 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100804} Result: [DE15060800000000000001, null, 2015-06-08 10:17:48.0, 01, 201506081017323258568, fb4db237da604688aeb1f369b5bfd45e, 02, 36ff7818c242400db397075c87721db7, 01, null, null, 23500, 03, 00, Success!, 930aebeae7c845c88bb15f985f3cde83, 02, 付信息费-矿产, 02, 5, null, 2015-06-08 10:17:28.0, 2015-06-08 10:17:48.0, null, 0, null]
10:21:38.199 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100805} Connection
10:21:38.199 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100805} Preparing Statement:      SELECT * FROM ums_paymentorder WHERE BizId=?
10:21:38.199 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100806} Executing Statement:      SELECT * FROM ums_paymentorder WHERE BizId=?
10:21:38.199 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100806} Parameters: [DE15060800000000000001]
10:21:38.199 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100806} Types: [java.lang.String]
10:21:38.208 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100807} ResultSet
10:21:38.209 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Suspending current transaction
10:21:38.209 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Creating new transaction with name [com.incito.logistics.service.SeqService.getNo]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; ''
10:21:38.214 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Acquired Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java] for JDBC transaction
10:21:38.218 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Switching JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java] to manual commit
10:21:38.220 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100808} Connection
10:21:38.220 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100808} Preparing Statement:       SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextvalue(?),?,0)) AS ordernum;
10:21:38.220 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100809} Executing Statement:       SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextvalue(?),?,0)) AS ordernum;
10:21:38.220 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100809} Parameters: [CP, %y%m%d, chinapayorder, 14]
10:21:38.221 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100809} Types: [java.lang.String, java.lang.String, java.lang.String, java.lang.Integer]
10:21:38.228 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100810} ResultSet
10:21:38.229 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100810} Header: [ordernum]
10:21:38.229 [http-apr-8080-exec-6] DEBUG java.sql.ResultSet - {rset-100810} Result: [CP15060800000000000003]
10:21:38.229 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Initiating transaction commit
10:21:38.231 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java]
10:21:38.238 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java] after transaction
10:21:38.238 [http-apr-8080-exec-6] DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
10:21:38.238 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Resuming suspended transaction after completion of inner transaction
10:21:38.238 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Resuming suspended transaction after completion of inner transaction
10:21:38.239 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100811} Connection
10:21:38.239 [http-apr-8080-exec-6] DEBUG java.sql.Connection - {conn-100811} Preparing Statement:      insert  into ums_paymentorder (       SrcReqId,       OrderNoMer,       OrderNo,       SrcReqDate,       TxnType,       PyrUserIdMer,       PyeUserIdMer,       PyrUserType,       PyeUserType,       PyrUserId,       PyeUserId,       OrderAmt,       STATUS,       StatusDesc,       BizId,       BizType,       BizDesc,       OrgBizId,       PaymentChannel,       OrderStatus,       Priority,       HashCode,       GenerateTime,       UpdateTime     )     value (       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       now(),now()     )
10:21:38.240 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100812} Executing Statement:      insert  into ums_paymentorder (       SrcReqId,       OrderNoMer,       OrderNo,       SrcReqDate,       TxnType,       PyrUserIdMer,       PyeUserIdMer,       PyrUserType,       PyeUserType,       PyrUserId,       PyeUserId,       OrderAmt,       STATUS,       StatusDesc,       BizId,       BizType,       BizDesc,       OrgBizId,       PaymentChannel,       OrderStatus,       Priority,       HashCode,       GenerateTime,       UpdateTime     )     value (       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       now(),now()     )
10:21:38.240 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100812} Parameters: [null, CP15060800000000000003, null, 2015-06-08 10:21:38.238, 04, 36ff7818c242400db397075c87721db7, fb4db237da604688aeb1f369b5bfd45e, 01, 02, null, null, 23500, null, 已发送, DE15060800000000000001, 04, 退信息费DE15060800000000000001, 930aebeae7c845c88bb15f985f3cde83, 02, 01, 5, null]
10:21:38.240 [http-apr-8080-exec-6] DEBUG java.sql.PreparedStatement - {pstm-100812} Types: [null, java.lang.String, null, java.sql.Timestamp, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.String, null, null, java.lang.Long, null, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.String, java.lang.Integer, null]
10:21:38.245 [http-apr-8080-exec-6] INFO  c.i.logistics.chinapay.ChinaPayOrderService - 创建退货订单 success, refundOrder: PaymentOrder{OrderNoMer='CP15060800000000000003', SrcReqId='null', SrcReqDate=Mon Jun 08 10:21:38 CST 2015, OrderNo='null', TxnType='04', OrderAmt=23500, OrderStatus='01', PyrUserIdMer='36ff7818c242400db397075c87721db7', PyeUserIdMer='fb4db237da604688aeb1f369b5bfd45e', PyrUserType='01', PyeUserType='02', PyrUserId='null', PyeUserId='null', Status='null', StatusDesc='已发送', BizId='DE15060800000000000001', BizType='04', BizDesc='退信息费DE15060800000000000001', Priority=5, HashCode='null', GenerateTime=null, UpdateTime=null, PaymentChannel='02'}
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - txnType-->04
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - frontUrl-->http://192.168.81.24:8080/web/chinapay/callback
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - channelType-->08
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - currencyCode-->156
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - merId-->777290058111285
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - txnSubType-->00
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - txnAmt-->23500
10:21:38.245 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - version-->5.0.0
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - signMethod-->01
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - backUrl-->http://58.51.36.100:60001/chinapay/callback
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - origQryId-->201506081017323258568
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - encoding-->UTF-8
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - bizType-->000201
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - orderId-->CP15060800000000000003
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - txnTime-->20150608102138
10:21:38.246 [http-apr-8080-exec-6] DEBUG c.i.logistics.chinapay.utils.ChinaPayUtil - accessType-->0
......
    at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:1852) [tomcat-coyote.jar:7.0.42]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_40]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_40]
    at java.lang.Thread.run(Thread.java:724) [na:1.7.0_40]
10:21:38.502 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Participating transaction failed - marking existing transaction as rollback-only
10:21:38.504 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Setting JDBC transaction [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java] rollback-only
10:21:38.505 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Initiating transaction rollback
10:21:38.510 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Rolling back JDBC transaction on Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java]
10:21:38.523 [http-apr-8080-exec-6] DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoReconnect=true&useUnicode=true&characterEncoding=utf8, UserName=root@172.16.0.3, MySQL Connector Java] after transaction
10:21:38.523 [http-apr-8080-exec-6] DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
Caused by: java.lang.RuntimeException: test db exception ...
    at com.incito.logistics.service.ChinaPayOrderService.refund(ChinaPayOrderService.java:700) ~[logistic-server-0.0.1-SNAPSHOT.jar:na]
    ... 69 common frames omitted
10:21:38.530 [http-apr-8080-exec-6] DEBUG com.incito.logistics.common.SpecialCharFilter - process out /web/myorder/agreeRefund

可以看到,不管方法的注解是什么,select语句并不会打开事务。只有insert\update出现时,才Creating new transaction。之后调用其它service方法时都是参与到当前的事务中Participating in existing transaction。最后commit或rollback。
(NOT_SUPPORTED与REQUIRES_NEW的日志被提取了出去,后面会看到,而他们之外的事务处理流程都一样)
DEBUG o.s.j.datasource.DataSourceTransactionManager - Creating new transaction with name
DEBUG o.s.j.datasource.DataSourceTransactionManager - Acquired Connection [jdbc:mysql://。。。
DEBUG o.s.j.datasource.DataSourceTransactionManager - Switching JDBC Connection [jdbc:mysql://。。。]to manual commit
。。。
DEBUG o.s.j.datasource.DataSourceTransactionManager - Participating in existing transaction
。。。
DEBUG o.s.j.datasource.DataSourceTransactionManager - Participating transaction failed - marking existing transaction as rollback-only
DEBUG o.s.j.datasource.DataSourceTransactionManager - Setting JDBC transaction [jdbc:mysql://192.168。。。
DEBUG o.s.j.datasource.DataSourceTransactionManager - Initiating transaction rollback
DEBUG o.s.j.datasource.DataSourceTransactionManager - Rolling back JDBC transaction on Connection [jdbc:mysql://19。。。
DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing JDBC Connection [jdbc:mysql://192.1。。。
DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource

如果其中的一个方法中使用了PROPAGATION_NOT_SUPPORTED,那么上面的流程中会出现下面日志,进入方法前先挂起当前事务且创建新事务,在NOT_SUPPORTED方法范围内,每执行一次就要commit一次,退出方法时提交新事务且恢复被挂起的事务。从日志中可看出NOT_SUPPORTED的行为。如下:执行了两次查询SELECT orderno,每次执行完后都commit了。
DEBUG o.s.j.datasource.DataSourceTransactionManager - Suspending current transaction
DEBUG o.s.j.datasource.DataSourceTransactionManager - Creating new transaction with name [com.incito.logistics.service.SeqSer
DEBUG o.s.j.datasource.DataSourceTransactionManager - Acquired Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoRe
DEBUG o.s.j.datasource.DataSourceTransactionManager - Switching JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?
DEBUG java.sql.Connection - {conn-100158} Connection
DEBUG java.sql.Connection - {conn-100158} Preparing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextvalue(?),
DEBUG java.sql.PreparedStatement - {pstm-100159} Executing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextva
DEBUG java.sql.PreparedStatement - {pstm-100159} Parameters: [CP, %y%m%d, chinapayorder, 14]
DEBUG java.sql.PreparedStatement - {pstm-100159} Types: [java.lang.String, java.lang.String, java.lang.String, java.lang.Inte
DEBUG java.sql.ResultSet - {rset-100160} ResultSet
DEBUG java.sql.ResultSet - {rset-100160} Header: [ordernum]
DEBUG java.sql.ResultSet - {rset-100160} Result: [CP15060800000000000006]
DEBUG o.s.j.datasource.DataSourceTransactionManager - Initiating transaction commit
DEBUG o.s.j.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [jdbc:mysql://192.168.11.140:
DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?
DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
DEBUG o.s.j.datasource.DataSourceTransactionManager - Resuming suspended transaction after completion of inner transaction
DEBUG o.s.j.datasource.DataSourceTransactionManager - Creating new transaction with name [com.incito.logistics.service.SeqSer
DEBUG o.s.j.datasource.DataSourceTransactionManager - Acquired Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoRe
DEBUG o.s.j.datasource.DataSourceTransactionManager - Switching JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?
DEBUG java.sql.Connection - {conn-100161} Connection
DEBUG java.sql.Connection - {conn-100161} Preparing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextvalue(?),
DEBUG java.sql.PreparedStatement - {pstm-100162} Executing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextva
DEBUG java.sql.PreparedStatement - {pstm-100162} Parameters: [CP, %y%m%d, chinapayorder, 14]
DEBUG java.sql.PreparedStatement - {pstm-100162} Types: [java.lang.String, java.lang.String, java.lang.String, java.lang.Inte
DEBUG java.sql.ResultSet - {rset-100163} ResultSet
DEBUG java.sql.ResultSet - {rset-100163} Header: [ordernum]
DEBUG java.sql.ResultSet - {rset-100163} Result: [CP15060800000000000007]
DEBUG o.s.j.datasource.DataSourceTransactionManager - Initiating transaction commit
DEBUG o.s.j.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [jdbc:mysql://192.168.11.140:
DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?
DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
DEBUG o.s.j.datasource.DataSourceTransactionManager - Resuming suspended transaction after completion of inner transaction
DEBUG o.s.j.datasource.DataSourceTransactionManager - Resuming suspended transaction after completion of inner transaction

如果其中的一个方法中使用了PROPAGATION_REQUIRES_NEW,与NOT_SUPPORTED相比只有一点区别,就是REQUIRES_NEW只commit了一次。之后处理步骤就相同了Resuming suspended transaction。。。

DEBUG o.s.j.datasource.DataSourceTransactionManager - Suspending current transaction, creating new transaction with name [co
DEBUG o.s.j.datasource.DataSourceTransactionManager - Acquired Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev?autoR
DEBUG o.s.j.datasource.DataSourceTransactionManager - Switching JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev
DEBUG o.s.j.datasource.DataSourceTransactionManager - Participating in existing transaction
DEBUG java.sql.Connection - {conn-100195} Connection
DEBUG java.sql.Connection - {conn-100195} Preparing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextvalue(?)
DEBUG java.sql.PreparedStatement - {pstm-100196} Executing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextv
DEBUG java.sql.PreparedStatement - {pstm-100196} Parameters: [CP, %y%m%d, chinapayorder, 14]
DEBUG java.sql.PreparedStatement - {pstm-100196} Types: [java.lang.String, java.lang.String, java.lang.String, java.lang.Int
DEBUG java.sql.ResultSet - {rset-100197} ResultSet
DEBUG java.sql.ResultSet - {rset-100197} Header: [ordernum]
DEBUG java.sql.ResultSet - {rset-100197} Result: [CP15060800000000000010]
DEBUG o.s.j.datasource.DataSourceTransactionManager - Participating in existing transaction
DEBUG java.sql.Connection - {conn-100198} Connection
DEBUG java.sql.Connection - {conn-100198} Preparing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextvalue(?)
DEBUG java.sql.PreparedStatement - {pstm-100199} Executing Statement: SELECT CONCAT(?,DATE_FORMAT(NOW(), ?),LPAD(nextv
DEBUG java.sql.PreparedStatement - {pstm-100199} Parameters: [CP, %y%m%d, chinapayorder, 14]
DEBUG java.sql.PreparedStatement - {pstm-100199} Types: [java.lang.String, java.lang.String, java.lang.String, java.lang.Int
DEBUG java.sql.ResultSet - {rset-100200} ResultSet
DEBUG java.sql.ResultSet - {rset-100200} Header: [ordernum]
DEBUG java.sql.ResultSet - {rset-100200} Result: [CP15060800000000000011]
DEBUG o.s.j.datasource.DataSourceTransactionManager - Initiating transaction commit
DEBUG o.s.j.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [jdbc:mysql://192.168.11.140
DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing JDBC Connection [jdbc:mysql://192.168.11.140:3306/smartdbdev
DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
DEBUG o.s.j.datasource.DataSourceTransactionManager - Resuming suspended transaction after completion of inner transaction

==============================================================================================
测试时,遇到了另外一种现象:
假设在同一个XXXService中,有下面两个方法:
@Transactional
method_One(){…method_Two()…}

@Transactional(propagation = Propagation.REQUIRES_NEW)
method_Two(){…}

问method_Two()会不会创建一个新事务?
答:不会创建。仔细查看了日志,没有找到类似creating new transaction的输出,应该是因为在同一个Service类中,spring并不重新创建新事务,如果是两不同的Service,就会创建新事务了。
那么为什么spring只对跨Service的方法才生效?
Debug代码发现跨Service调用方法时,都会经过org.springframework.aop.framework.CglibAopProxy.DynamicAdvisedInterceptor.intercept()方法,只有经过此处,才能对事务进行控制。
如果你要问此方法又是如何控制事务的?下次有机会再研究。。。嘿嘿

==============================================================================================

DEBUG o.s.j.datasource.DataSourceTransactionManager - Global transaction is marked as rollback-only but transactional code requested commit
DEBUG o.s.j.datasource.DataSourceTransactionManager - Initiating transaction rollback
DEBUG o.s.j.datasource.DataSourceTransactionManager - Rolling back JDBC transaction on Connection [jdbc:mysql://。。。, MySQL Connector Java]
DEBUG o.s.j.datasource.DataSourceTransactionManager - Releasing JDBC Connection [jdbc:mysql://。。。,  ] after transaction
DEBUG o.s.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
org.springframework.transaction.UnexpectedRollbackException: Transaction rolled back because it has been marked as rollback-only

Propagation.REQUIRES_NEW 与 Propagation.REQUIRED 比较
method_XX(){
      //创建退货订单
      try {
        refundOrder.setOrderNoMer(seqService.nextOrderNo());//跨Service调用方法时
      } catch (Exception e) {//catch后不抛出
        refundOrder.setOrderNoMer("11111111111111112");//商户端订单号
        logger.info("catch后不抛出", e);
      }
}

跨Service调用方法时:
**如果被调用方法是Propagation.REQUIRES_NEW,被catch后不抛出,事务可以正常提交;
如果被调用方法是Propagation.REQUIRED,被catch后不抛出,后面的代码虽然可以执行下去,但最终还是会分出rollback-only异常:**Global transaction is marked as rollback-only but transactional code requested commit
如果是在同一个Service中调用方法时:
不论注解是REQUIRES_NEW还是REQUIRED,其结果都是一样的,就是都被忽略掉了,等于没写。当其抛出异常时,只需catch住不抛出,事务就可以正常提交。

==============================================================================================

  • 2
    点赞
  • 2
    收藏
    觉得还不错? 一键收藏
  • 0
    评论

“相关推荐”对你有帮助么?

  • 非常没帮助
  • 没帮助
  • 一般
  • 有帮助
  • 非常有帮助
提交
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值