显示有关回滚过程的日志消息
Show log message about Rollback process
我正在使用 Spring 数据 JDBC 测试一些回滚功能，但是查看一次测试执行的日志，我没有看到该日志包含类似“Rollback for xxx”的内容
日志配置：
logging.level.org.springframework.data=INFO
logging.level.org.springframework.jdbc.core.JdbcTemplate=TRACE
logging.level.org.springframework.transaction=TRACE
logging.level.org.springframework.transaction.interceptor=TRACE
日志输出：
日志代表一个服务执行加上以串行方式执行的 2 个 EventListener 的执行。当最后一个事件监听器抛出异常时，我没有看到任何关于回滚过程的日志消息，但它以一种有效的方式在幕后执行了回滚过程。
2022-01-04 09:36:47.685 INFO 11820 --- [o-auto-2-exec-1] c.d.b.application.BalanceServiceImpl : Witdhdraw 10.00 for customer 1
2022-01-04 09:36:47.689 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 09:36:47.776 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL query
2022-01-04 09:36:47.777 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [SELECT "BALANCE"."BALANCE" AS "BALANCE", "BALANCE"."ID_BALANCE" AS "ID_BALANCE", "BALANCE"."ID_CUSTOMER" AS "ID_CUSTOMER", "BALANCE"."LAST_UPDATE" AS "LAST_UPDATE", "BALANCE"."WITHDRAW_LIMIT" AS "WITHDRAW_LIMIT" FROM "BALANCE" WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 09:36:47.850 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 09:36:47.853 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 09:36:47.899 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL update
2022-01-04 09:36:47.900 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [UPDATE "BALANCE" SET "BALANCE" = ?, "ID_CUSTOMER" = ?, "LAST_UPDATE" = ?, "WITHDRAW_LIMIT" = ? WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 09:36:47.913 TRACE 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : SQL update affected 1 rows
2022-01-04 09:36:47.918 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 09:36:47.919 INFO 11820 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener : New Event Received: MoneyWithDrewEvent Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 09:36:47.852322144, withdrawLimit=null]
2022-01-04 09:36:47.933 INFO 11820 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener2 : New Event Received: MoneyWithdrewEventStep2 Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 09:36:47.852322144, withdrawLimit=null]
2022-01-04 09:36:47.934 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [com.ddd.balance.application.BalanceServiceImpl.witdhdraw] after exception: java.lang.RuntimeException: Katakroker
测试：
//Initially the customer has a balance with 100
@Test
public void given_balanceController_when_withdraw_happy_path_Ok() {
//Given
String address2 = "http://localhost:" + port + "/api/withdraw";
BigDecimal amount = new BigDecimal("10.00");
WithdrawRequest widthDrawRequest = new WithdrawRequest(1L, amount);
HttpHeaders headers = new HttpHeaders();
HttpEntity<WithdrawRequest> request = new HttpEntity<>(widthDrawRequest, headers);
//When
ResponseEntity<String> result2 = this.restTemplate.postForEntity(address2, request, String.class);
//Then
WithdrawResponse expectedResponse = new WithdrawResponse(false);
then(result2.getStatusCode()).isEqualTo(HttpStatus.OK);
//then(result2.getBody()).contains(asJsonString(expectedResponse));
//Internally raise an Exception
//Step Verify
//Given
String address3 = "http://localhost:" + port + "/api/balance/1";
//When
ResponseEntity<BalanceResponse> result3 = this.restTemplate.getForEntity(address3, BalanceResponse.class);
//Then
then(result3.getStatusCode()).isEqualTo(HttpStatus.OK);
then(result3.getBody().amount()).isEqualTo(new BigDecimal("100.00"));
}
存储库示例：
Spring 数据 JDBC 在内部执行回滚，但我没有看到痕迹。
如何开启？
我能够看到具有以下配置的日志：
logging.level.org.springframework.jdbc.support.JdbcTransactionManager=TRACE
日志消息：
2022-01-04 10:59:08.417 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Creating new transaction with name [com.ddd.balance.application.BalanceServiceImpl.witdhdraw]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-01-04 10:59:08.418 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Acquired Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA] for JDBC transaction
2022-01-04 10:59:08.420 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Switching JDBC Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA] to manual commit
2022-01-04 10:59:08.421 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [com.ddd.balance.application.BalanceServiceImpl.witdhdraw]
2022-01-04 10:59:08.447 INFO 2951 --- [o-auto-2-exec-1] c.d.b.application.BalanceServiceImpl : Witdhdraw 10.00 for customer 1
2022-01-04 10:59:08.449 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Participating in existing transaction
2022-01-04 10:59:08.450 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 10:59:08.521 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL query
2022-01-04 10:59:08.522 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [SELECT "BALANCE"."BALANCE" AS "BALANCE", "BALANCE"."ID_BALANCE" AS "ID_BALANCE", "BALANCE"."ID_CUSTOMER" AS "ID_CUSTOMER", "BALANCE"."LAST_UPDATE" AS "LAST_UPDATE", "BALANCE"."WITHDRAW_LIMIT" AS "WITHDRAW_LIMIT" FROM "BALANCE" WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 10:59:08.585 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 10:59:08.587 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Participating in existing transaction
2022-01-04 10:59:08.588 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 10:59:08.628 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL update
2022-01-04 10:59:08.629 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [UPDATE "BALANCE" SET "BALANCE" = ?, "ID_CUSTOMER" = ?, "LAST_UPDATE" = ?, "WITHDRAW_LIMIT" = ? WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 10:59:08.648 TRACE 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : SQL update affected 1 rows
2022-01-04 10:59:08.653 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 10:59:08.655 INFO 2951 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener : New Event Received: MoneyWithDrewEvent Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 10:59:08.586936363, withdrawLimit=null]
2022-01-04 10:59:08.675 INFO 2951 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener2 : New Event Received: MoneyWithdrewEventStep2 Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 10:59:08.586936363, withdrawLimit=null]
2022-01-04 10:59:08.676 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [com.ddd.balance.application.BalanceServiceImpl.witdhdraw] after exception: java.lang.RuntimeException: Katakroker
2022-01-04 10:59:08.676 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Initiating transaction rollback
2022-01-04 10:59:08.676 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Rolling back JDBC transaction on Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA]
2022-01-04 10:59:08.678 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Releasing JDBC Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA] after transaction
我正在使用 Spring 数据 JDBC 测试一些回滚功能，但是查看一次测试执行的日志，我没有看到该日志包含类似“Rollback for xxx”的内容
日志配置：
logging.level.org.springframework.data=INFO
logging.level.org.springframework.jdbc.core.JdbcTemplate=TRACE
logging.level.org.springframework.transaction=TRACE
logging.level.org.springframework.transaction.interceptor=TRACE
日志输出：
日志代表一个服务执行加上以串行方式执行的 2 个 EventListener 的执行。当最后一个事件监听器抛出异常时，我没有看到任何关于回滚过程的日志消息，但它以一种有效的方式在幕后执行了回滚过程。
2022-01-04 09:36:47.685 INFO 11820 --- [o-auto-2-exec-1] c.d.b.application.BalanceServiceImpl : Witdhdraw 10.00 for customer 1
2022-01-04 09:36:47.689 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 09:36:47.776 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL query
2022-01-04 09:36:47.777 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [SELECT "BALANCE"."BALANCE" AS "BALANCE", "BALANCE"."ID_BALANCE" AS "ID_BALANCE", "BALANCE"."ID_CUSTOMER" AS "ID_CUSTOMER", "BALANCE"."LAST_UPDATE" AS "LAST_UPDATE", "BALANCE"."WITHDRAW_LIMIT" AS "WITHDRAW_LIMIT" FROM "BALANCE" WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 09:36:47.850 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 09:36:47.853 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 09:36:47.899 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL update
2022-01-04 09:36:47.900 DEBUG 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [UPDATE "BALANCE" SET "BALANCE" = ?, "ID_CUSTOMER" = ?, "LAST_UPDATE" = ?, "WITHDRAW_LIMIT" = ? WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 09:36:47.913 TRACE 11820 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : SQL update affected 1 rows
2022-01-04 09:36:47.918 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 09:36:47.919 INFO 11820 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener : New Event Received: MoneyWithDrewEvent Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 09:36:47.852322144, withdrawLimit=null]
2022-01-04 09:36:47.933 INFO 11820 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener2 : New Event Received: MoneyWithdrewEventStep2 Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 09:36:47.852322144, withdrawLimit=null]
2022-01-04 09:36:47.934 TRACE 11820 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [com.ddd.balance.application.BalanceServiceImpl.witdhdraw] after exception: java.lang.RuntimeException: Katakroker
测试：
//Initially the customer has a balance with 100
@Test
public void given_balanceController_when_withdraw_happy_path_Ok() {
//Given
String address2 = "http://localhost:" + port + "/api/withdraw";
BigDecimal amount = new BigDecimal("10.00");
WithdrawRequest widthDrawRequest = new WithdrawRequest(1L, amount);
HttpHeaders headers = new HttpHeaders();
HttpEntity<WithdrawRequest> request = new HttpEntity<>(widthDrawRequest, headers);
//When
ResponseEntity<String> result2 = this.restTemplate.postForEntity(address2, request, String.class);
//Then
WithdrawResponse expectedResponse = new WithdrawResponse(false);
then(result2.getStatusCode()).isEqualTo(HttpStatus.OK);
//then(result2.getBody()).contains(asJsonString(expectedResponse));
//Internally raise an Exception
//Step Verify
//Given
String address3 = "http://localhost:" + port + "/api/balance/1";
//When
ResponseEntity<BalanceResponse> result3 = this.restTemplate.getForEntity(address3, BalanceResponse.class);
//Then
then(result3.getStatusCode()).isEqualTo(HttpStatus.OK);
then(result3.getBody().amount()).isEqualTo(new BigDecimal("100.00"));
}
存储库示例：
Spring 数据 JDBC 在内部执行回滚，但我没有看到痕迹。 如何开启？
我能够看到具有以下配置的日志：
logging.level.org.springframework.jdbc.support.JdbcTransactionManager=TRACE
日志消息：
2022-01-04 10:59:08.417 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Creating new transaction with name [com.ddd.balance.application.BalanceServiceImpl.witdhdraw]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
2022-01-04 10:59:08.418 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Acquired Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA] for JDBC transaction
2022-01-04 10:59:08.420 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Switching JDBC Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA] to manual commit
2022-01-04 10:59:08.421 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [com.ddd.balance.application.BalanceServiceImpl.witdhdraw]
2022-01-04 10:59:08.447 INFO 2951 --- [o-auto-2-exec-1] c.d.b.application.BalanceServiceImpl : Witdhdraw 10.00 for customer 1
2022-01-04 10:59:08.449 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Participating in existing transaction
2022-01-04 10:59:08.450 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 10:59:08.521 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL query
2022-01-04 10:59:08.522 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [SELECT "BALANCE"."BALANCE" AS "BALANCE", "BALANCE"."ID_BALANCE" AS "ID_BALANCE", "BALANCE"."ID_CUSTOMER" AS "ID_CUSTOMER", "BALANCE"."LAST_UPDATE" AS "LAST_UPDATE", "BALANCE"."WITHDRAW_LIMIT" AS "WITHDRAW_LIMIT" FROM "BALANCE" WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 10:59:08.585 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.findById]
2022-01-04 10:59:08.587 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Participating in existing transaction
2022-01-04 10:59:08.588 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Getting transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 10:59:08.628 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL update
2022-01-04 10:59:08.629 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : Executing prepared SQL statement [UPDATE "BALANCE" SET "BALANCE" = ?, "ID_CUSTOMER" = ?, "LAST_UPDATE" = ?, "WITHDRAW_LIMIT" = ? WHERE "BALANCE"."ID_BALANCE" = ?]
2022-01-04 10:59:08.648 TRACE 2951 --- [o-auto-2-exec-1] o.s.jdbc.core.JdbcTemplate : SQL update affected 1 rows
2022-01-04 10:59:08.653 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [org.springframework.data.jdbc.repository.support.SimpleJdbcRepository.save]
2022-01-04 10:59:08.655 INFO 2951 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener : New Event Received: MoneyWithDrewEvent Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 10:59:08.586936363, withdrawLimit=null]
2022-01-04 10:59:08.675 INFO 2951 --- [o-auto-2-exec-1] c.d.s.application.BalanceEventListener2 : New Event Received: MoneyWithdrewEventStep2 Balance[balanceId=1, balance=90.00, customerId=null, lastUpdate=2022-01-04 10:59:08.586936363, withdrawLimit=null]
2022-01-04 10:59:08.676 TRACE 2951 --- [o-auto-2-exec-1] o.s.t.i.TransactionInterceptor : Completing transaction for [com.ddd.balance.application.BalanceServiceImpl.witdhdraw] after exception: java.lang.RuntimeException: Katakroker
2022-01-04 10:59:08.676 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Initiating transaction rollback
2022-01-04 10:59:08.676 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Rolling back JDBC transaction on Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA]
2022-01-04 10:59:08.678 DEBUG 2951 --- [o-auto-2-exec-1] o.s.jdbc.support.JdbcTransactionManager : Releasing JDBC Connection [HikariProxyConnection@1551466954 wrapping conn10: url=jdbc:h2:mem:cf10c02a-8c7f-4667-b14a-9de91f7651a9 user=SA] after transaction