为什么myBatis+postgresql 9.3 查询成功了还是回滚？

Question

我有一段 Java 使用 myBatis、postgresql 9.3 服务器和 postgresql-9.3-1100-jdbc41 JDBC 驱动程序的代码。我们还使用 mybatis-guice 来支持@Transactional。直到现在我们一直只使用可序列化的事务，现在我们想把只从数据库读取的查询放在一个不太严格的隔离级别，比如 'read committed'。所以，有些@Transactional 注解使用SERIALIZABLE，有些使用READ_COMMITTED。还有嵌套调用。

所以，我在 postgresql 服务器日志中有这个：

2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1268 txnId=0 pid=1949 appName=entity_manager LOG:  execute : SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL SERIALIZABLE
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=0 pid=1949 appName=entity_manager LOG:  execute : BEGIN
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=0 pid=1949 appName=entity_manager LOG:  execute : SELECT
                *
            FROM
                customer.accounts
            WHERE
--
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=0 pid=1949 appName=entity_manager LOG:  execute : UPDATE
                customer.cities
            SET
                name = ,
                ledger_id = ,
--
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=0 pid=1949 appName=entity_manager DETAIL:  parameters: ......
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=1726978 pid=1949 appName=entity_manager LOG:  execute : SELECT
                l.*
                 ,
                cc.id as cost_center_id,
                cc.description as cost_center_description,
--
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=1726978 pid=1949 appName=entity_manager DETAIL:  parameters:  = .....
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=1726978 pid=1949 appName=entity_manager LOG:  execute : UPDATE
                customer.ledgers
            SET
                internal_ledger_number = 
                 ,
--
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=1726978 pid=1949 appName=entity_manager DETAIL:  parameters:  = ...........
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=1726978 pid=1949 appName=entity_manager LOG:  execute : SELECT DISTINCT
                role
            FROM customer.user_roles ur INNER JOIN customer.user_to_accounts_to_user_roles uur ON (ur.id=uur.role_id)
            WHERE
                user_id=
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=1726978 pid=1949 appName=entity_manager DETAIL:  parameters:  = .......
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1269 txnId=1726978 pid=1949 appName=entity_manager LOG:  execute S_2: ROLLBACK
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1270 txnId=0 pid=1949 appName=entity_manager LOG:  execute : BEGIN
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1270 txnId=0 pid=1949 appName=entity_manager LOG:  execute : SELECT 
                id
            FROM
            customer.user_roles
            WHERE role=
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1270 txnId=0 pid=1949 appName=entity_manager DETAIL:  parameters:  = ......
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1270 txnId=0 pid=1949 appName=entity_manager LOG:  execute : INSERT INTO customer.user_to_accounts_to_user_roles 
            (user_id, account_id, role_id) 
            values 
            (, , )
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1270 txnId=0 pid=1949 appName=entity_manager DETAIL:  parameters:  = ........
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1270 txnId=1726979 pid=1949 appName=entity_manager LOG:  execute S_1: COMMIT



2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1271 txnId=0 pid=1949 appName=entity_manager LOG:  execute : SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1272 txnId=0 pid=1949 appName=entity_manager LOG:  execute : BEGIN
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1272 txnId=0 pid=1949 appName=entity_manager LOG:  execute : SELECT
                *
            FROM
                customer.cities
            WHERE
--
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1272 txnId=0 pid=1949 appName=entity_manager DETAIL:  parameters:  = ......
2016-02-09 15:27:47 CET sessionId=56b9f455.79d sessionStart=2016-02-09 15:14:45 CET vTxnId=12/1272 txnId=0 pid=1949 appName=entity_manager LOG:  execute S_1: COMMIT

（这是一个片段，通过 grepping sessionId 和使用 --after-context 进行过滤——这就是为什么有些查询似乎没有终止，但请相信我，它们是有效的查询）。所以我有一个成功查询的列表，并且在某个时候发出了 ROLLBACK。然后代码继续执行其余查询。所以我在代码中似乎没有任何异常。 ROLLBACK 似乎是突然发出的。

怎么会这样？
这种情况发生了 10 次中的 1 次，10 次中的 9 次一切正常（使用相同的数据）。代码是多线程的。

我可以提供其他细节，没问题。

Answer 1

同时我找到了原因。

事实证明，在一个用@Transactional 注释的方法（我们称之为方法A）中还有另一个方法也用@Transactional 注释（我们称之为方法B）。这个内部方法（methodB）抛出了一个异常，异常在 methodA 中被抛出，代码愉快地继续下去。但是，一旦 myBatis 看到异常，它就会回滚整个事务。

像这样：

methodA (@Transactional)
begin
select * ....
update .....
methodB: select .... 
methodB: throw exception -> myBatis calls rollback
methodA: catch exception, go on
methodA: other code

为什么myBatis+postgresql 9.3 查询成功了还是回滚？

Why does myBatis+postgresql 9.3 issue a ROLLBACK even if the query succeeds?

java

postgresql

mybatis

transactional