tonglsh opened a new issue, #7590: URL: https://github.com/apache/incubator-seata/issues/7590
### Check Ahead - [x] I have searched the [issues](https://github.com/seata/seata/issues) of this repository and believe that this is not a duplicate. - [ ] I am willing to try to fix this bug myself. ### Ⅰ. Issue Description 您好，我使用incubator-seata-samples-master/at-sample/springboot-mybatis-seata 在模拟全局锁竞争，以排查这种场景对数据库本地锁的持有时间情况 seata-server 1.8 seata-spring-boot-starter 1.8 即使使用默认配置 retry-interval: 10ms、retry-times: 30 在查看了本地的全局事务锁日志，发现从开始重试到抛出重试timeout 之间共消耗了2025-08-21 23:14:36.087 ～2025-08-21 23:14:40.280 共4秒多，请问这是正常的现象吗，按照一般理解应该重试的时间为300ms左右 ### Ⅱ. Describe what happened /Users/mac/import/amazon-corretto-17.jdk/Contents/Home/bin/java -Ddm.jdbc.log.file=./dm_jdbc.log -javaagent:/Users/mac/Applications/IntelliJ IDEA Community Edition.app/Contents/lib/idea_rt.jar=59031:/Users/mac/Applications/IntelliJ IDEA Community Edition.app/Contents/bin -Dfile.encoding=UTF-8 -classpath /Users/mac/Desktop/微服务框架/xc-idc-frame/seata/验证/incubator-seata-samples-master/at-sample/springboot-mybatis-seata/target/classes:/Users/mac/.m2/repository/org/springframework/boot/spring-boot-starter/3.1.12/spring-boot-starter-3.1.12.jar:/Users/mac/.m2/repository/org/springframework/boot/spring-boot/3.1.12/spring-boot-3.1.12.jar:/Users/mac/.m2/repository/org/springframework/spring-context/6.0.21/spring-context-6.0.21.jar:/Users/mac/.m2/repository/org/springframework/spring-expression/6.0.21/spring-expression-6.0.21.jar:/Users/mac/.m2/repository/org/springframework/boot/spring-boot-autoconfigure/3.1.12/spring-boot-autoconfigure-3.1.12.jar:/Users/mac/.m2/repository/org/s pringframework/boot/spring-boot-starter-logging/3.1.12/spring-boot-starter-logging-3.1.12.jar:/Users/mac/.m2/repository/ch/qos/logback/logback-classic/1.4.14/logback-classic-1.4.14.jar:/Users/mac/.m2/repository/ch/qos/logback/logback-core/1.4.14/logback-core-1.4.14.jar:/Users/mac/.m2/repository/org/apache/logging/log4j/log4j-to-slf4j/2.20.0/log4j-to-slf4j-2.20.0.jar:/Users/mac/.m2/repository/org/apache/logging/log4j/log4j-api/2.20.0/log4j-api-2.20.0.jar:/Users/mac/.m2/repository/org/slf4j/jul-to-slf4j/2.0.13/jul-to-slf4j-2.0.13.jar:/Users/mac/.m2/repository/jakarta/annotation/jakarta.annotation-api/2.1.1/jakarta.annotation-api-2.1.1.jar:/Users/mac/.m2/repository/org/springframework/spring-core/6.0.21/spring-core-6.0.21.jar:/Users/mac/.m2/repository/org/springframework/spring-jcl/6.0.21/spring-jcl-6.0.21.jar:/Users/mac/.m2/repository/org/yaml/snakeyaml/1.33/snakeyaml-1.33.jar:/Users/mac/.m2/repository/org/slf4j/slf4j-api/2.0.13/slf4j-api-2.0.13.jar:/Users/mac/.m2/repository/jakarta/x ml/bind/jakarta.xml.bind-api/4.0.2/jakarta.xml.bind-api-4.0.2.jar:/Users/mac/.m2/repository/jakarta/activation/jakarta.activation-api/2.1.3/jakarta.activation-api-2.1.3.jar:/Users/mac/.m2/repository/com/chinatower/cloud/spring-cloud-starter-chinatower-seata/3.1.5.0/spring-cloud-starter-chinatower-seata-3.1.5.0.jar:/Users/mac/.m2/repository/com/alibaba/cloud/spring-cloud-starter-alibaba-seata/2022.0.0.2/spring-cloud-starter-alibaba-seata-2022.0.0.2.jar:/Users/mac/.m2/repository/org/springframework/boot/spring-boot-starter-aop/3.1.12/spring-boot-starter-aop-3.1.12.jar:/Users/mac/.m2/repository/org/aspectj/aspectjweaver/1.9.22/aspectjweaver-1.9.22.jar:/Users/mac/.m2/repository/p6spy/p6spy/3.9.1/p6spy-3.9.1.jar:/Users/mac/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.15.4/jackson-databind-2.15.4.jar:/Users/mac/.m2/repository/com/fasterxml/jackson/core/jackson-annotations/2.15.4/jackson-annotations-2.15.4.jar:/Users/mac/.m2/repository/com/fasterxml/jackson/core/jackson-cor e/2.15.4/jackson-core-2.15.4.jar:/Users/mac/.m2/repository/org/springframework/boot/spring-boot-starter-jdbc/3.1.12/spring-boot-starter-jdbc-3.1.12.jar:/Users/mac/.m2/repository/com/zaxxer/HikariCP/5.0.1/HikariCP-5.0.1.jar:/Users/mac/.m2/repository/org/springframework/spring-jdbc/6.0.21/spring-jdbc-6.0.21.jar:/Users/mac/.m2/repository/org/springframework/spring-beans/6.0.21/spring-beans-6.0.21.jar:/Users/mac/.m2/repository/org/springframework/spring-tx/6.0.21/spring-tx-6.0.21.jar:/Users/mac/.m2/repository/mysql/mysql-connector-java/8.0.22/mysql-connector-java-8.0.22.jar:/Users/mac/.m2/repository/com/google/protobuf/protobuf-java/3.11.4/protobuf-java-3.11.4.jar:/Users/mac/.m2/repository/com/dameng/DmJdbcDriver8/8.1.4.6/DmJdbcDriver8-8.1.4.6.jar:/Users/mac/.m2/repository/com/chinatower/cloud/spring-cloud-starter-chinatower-mybatis/3.1.5.0/spring-cloud-starter-chinatower-mybatis-3.1.5.0.jar:/Users/mac/.m2/repository/org/mybatis/mybatis/3.5.16/mybatis-3.5.16.jar:/Users/mac/.m2/repositor y/com/github/pagehelper/pagehelper-spring-boot-starter/2.1.0/pagehelper-spring-boot-starter-2.1.0.jar:/Users/mac/.m2/repository/com/github/pagehelper/pagehelper-spring-boot-autoconfigure/2.1.0/pagehelper-spring-boot-autoconfigure-2.1.0.jar:/Users/mac/.m2/repository/com/github/pagehelper/pagehelper/6.1.0/pagehelper-6.1.0.jar:/Users/mac/.m2/repository/com/github/jsqlparser/jsqlparser/4.7/jsqlparser-4.7.jar:/Users/mac/.m2/repository/org/mybatis/spring/boot/mybatis-spring-boot-starter/3.0.3/mybatis-spring-boot-starter-3.0.3.jar:/Users/mac/.m2/repository/org/mybatis/spring/boot/mybatis-spring-boot-autoconfigure/3.0.3/mybatis-spring-boot-autoconfigure-3.0.3.jar:/Users/mac/.m2/repository/org/mybatis/mybatis-spring/3.0.3/mybatis-spring-3.0.3.jar:/Users/mac/.m2/repository/com/alibaba/druid-spring-boot-starter/1.2.23/druid-spring-boot-starter-1.2.23.jar:/Users/mac/.m2/repository/com/alibaba/druid/1.2.23/druid-1.2.23.jar:/Users/mac/.m2/repository/org/glassfish/jaxb/jaxb-runtime/4.0.5/jaxb-runt ime-4.0.5.jar:/Users/mac/.m2/repository/org/glassfish/jaxb/jaxb-core/4.0.5/jaxb-core-4.0.5.jar:/Users/mac/.m2/repository/org/eclipse/angus/angus-activation/2.0.2/angus-activation-2.0.2.jar:/Users/mac/.m2/repository/org/glassfish/jaxb/txw2/4.0.5/txw2-4.0.5.jar:/Users/mac/.m2/repository/com/sun/istack/istack-commons-runtime/4.1.2/istack-commons-runtime-4.1.2.jar:/Users/mac/.m2/repository/io/seata/seata-spring-boot-starter/1.8.0/seata-spring-boot-starter-1.8.0.jar:/Users/mac/.m2/repository/io/seata/seata-spring-autoconfigure-client/1.8.0/seata-spring-autoconfigure-client-1.8.0.jar:/Users/mac/.m2/repository/io/seata/seata-spring-autoconfigure-core/1.8.0/seata-spring-autoconfigure-core-1.8.0.jar:/Users/mac/.m2/repository/io/seata/seata-all/1.8.0/seata-all-1.8.0.jar:/Users/mac/.m2/repository/org/springframework/spring-aop/6.0.21/spring-aop-6.0.21.jar:/Users/mac/.m2/repository/org/springframework/spring-webmvc/6.0.21/spring-webmvc-6.0.21.jar:/Users/mac/.m2/repository/org/springframework/sp ring-web/6.0.21/spring-web-6.0.21.jar:/Users/mac/.m2/repository/io/micrometer/micrometer-observation/1.11.12/micrometer-observation-1.11.12.jar:/Users/mac/.m2/repository/io/micrometer/micrometer-commons/1.11.12/micrometer-commons-1.11.12.jar:/Users/mac/.m2/repository/io/netty/netty-all/4.1.110.Final/netty-all-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-buffer/4.1.110.Final/netty-buffer-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec/4.1.110.Final/netty-codec-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-dns/4.1.110.Final/netty-codec-dns-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-haproxy/4.1.110.Final/netty-codec-haproxy-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-http/4.1.110.Final/netty-codec-http-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-http2/4.1.110.Final/netty-codec-http2-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-memcache/4.1.110.Final/nett y-codec-memcache-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-mqtt/4.1.110.Final/netty-codec-mqtt-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-redis/4.1.110.Final/netty-codec-redis-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-smtp/4.1.110.Final/netty-codec-smtp-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-socks/4.1.110.Final/netty-codec-socks-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-stomp/4.1.110.Final/netty-codec-stomp-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-codec-xml/4.1.110.Final/netty-codec-xml-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-common/4.1.110.Final/netty-common-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-handler/4.1.110.Final/netty-handler-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport-native-unix-common/4.1.110.Final/netty-transport-native-unix-common-4.1.110.Final.jar:/Users/mac/.m2/repository/i o/netty/netty-handler-proxy/4.1.110.Final/netty-handler-proxy-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-handler-ssl-ocsp/4.1.110.Final/netty-handler-ssl-ocsp-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-resolver/4.1.110.Final/netty-resolver-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-resolver-dns/4.1.110.Final/netty-resolver-dns-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport/4.1.110.Final/netty-transport-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport-rxtx/4.1.110.Final/netty-transport-rxtx-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport-sctp/4.1.110.Final/netty-transport-sctp-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport-udt/4.1.110.Final/netty-transport-udt-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport-classes-epoll/4.1.110.Final/netty-transport-classes-epoll-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport- classes-kqueue/4.1.110.Final/netty-transport-classes-kqueue-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-resolver-dns-classes-macos/4.1.110.Final/netty-resolver-dns-classes-macos-4.1.110.Final.jar:/Users/mac/.m2/repository/io/netty/netty-transport-native-epoll/4.1.110.Final/netty-transport-native-epoll-4.1.110.Final-linux-x86_64.jar:/Users/mac/.m2/repository/io/netty/netty-transport-native-epoll/4.1.110.Final/netty-transport-native-epoll-4.1.110.Final-linux-aarch_64.jar:/Users/mac/.m2/repository/io/netty/netty-transport-native-epoll/4.1.110.Final/netty-transport-native-epoll-4.1.110.Final-linux-riscv64.jar:/Users/mac/.m2/repository/io/netty/netty-transport-native-kqueue/4.1.110.Final/netty-transport-native-kqueue-4.1.110.Final-osx-x86_64.jar:/Users/mac/.m2/repository/io/netty/netty-transport-native-kqueue/4.1.110.Final/netty-transport-native-kqueue-4.1.110.Final-osx-aarch_64.jar:/Users/mac/.m2/repository/io/netty/netty-resolver-dns-native-macos/4.1.110.Final/netty-reso lver-dns-native-macos-4.1.110.Final-osx-x86_64.jar:/Users/mac/.m2/repository/io/netty/netty-resolver-dns-native-macos/4.1.110.Final/netty-resolver-dns-native-macos-4.1.110.Final-osx-aarch_64.jar:/Users/mac/.m2/repository/org/antlr/antlr4/4.8/antlr4-4.8.jar:/Users/mac/.m2/repository/org/antlr/antlr4-runtime/4.8/antlr4-runtime-4.8.jar:/Users/mac/.m2/repository/org/antlr/antlr-runtime/3.5.2/antlr-runtime-3.5.2.jar:/Users/mac/.m2/repository/org/antlr/ST4/4.3/ST4-4.3.jar:/Users/mac/.m2/repository/org/abego/treelayout/org.abego.treelayout.core/1.0.3/org.abego.treelayout.core-1.0.3.jar:/Users/mac/.m2/repository/org/glassfish/javax.json/1.0.4/javax.json-1.0.4.jar:/Users/mac/.m2/repository/com/ibm/icu/icu4j/61.1/icu4j-61.1.jar:/Users/mac/.m2/repository/com/alibaba/fastjson/1.2.83/fastjson-1.2.83.jar:/Users/mac/.m2/repository/com/typesafe/config/1.2.1/config-1.2.1.jar:/Users/mac/.m2/repository/commons-lang/commons-lang/2.6/commons-lang-2.6.jar:/Users/mac/.m2/repository/org/apache/commons/comm ons-pool2/2.11.1/commons-pool2-2.11.1.jar:/Users/mac/.m2/repository/commons-pool/commons-pool/1.6/commons-pool-1.6.jar:/Users/mac/.m2/repository/org/apache/dubbo/extensions/dubbo-filter-seata/1.0.2/dubbo-filter-seata-1.0.2.jar:/Users/mac/.m2/repository/aopalliance/aopalliance/1.0/aopalliance-1.0.jar:/Users/mac/.m2/repository/com/google/guava/guava/30.1-jre/guava-30.1-jre.jar:/Users/mac/.m2/repository/com/google/guava/failureaccess/1.0.1/failureaccess-1.0.1.jar:/Users/mac/.m2/repository/com/google/code/findbugs/jsr305/3.0.2/jsr305-3.0.2.jar:/Users/mac/.m2/repository/org/checkerframework/checker-qual/3.5.0/checker-qual-3.5.0.jar:/Users/mac/.m2/repository/com/google/errorprone/error_prone_annotations/2.3.4/error_prone_annotations-2.3.4.jar:/Users/mac/.m2/repository/com/google/j2objc/j2objc-annotations/1.3/j2objc-annotations-1.3.jar:/Users/mac/.m2/repository/com/github/ben-manes/caffeine/caffeine/3.1.8/caffeine-3.1.8.jar org.apache.seata.SpringbootSeataApplication . ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v3.1.12) 2025-08-21 23:14:32.277 [main] INFO o.a.seata.SpringbootSeataApplication - Starting SpringbootSeataApplication using Java 17.0.3 with PID 45921 (/Users/mac/Desktop/微服务框架/xc-idc-frame/seata/验证/incubator-seata-samples-master/at-sample/springboot-mybatis-seata/target/classes started by mac in /Users/mac/Desktop/微服务框架/xc-idc-frame/seata/验证/incubator-seata-samples-master) 2025-08-21 23:14:32.281 [main] INFO o.a.seata.SpringbootSeataApplication - No active profile set, falling back to 1 default profile: "default" 2025-08-21 23:14:33.395 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'io.seata.spring.boot.autoconfigure.SeataCoreAutoConfiguration' of type [io.seata.spring.boot.autoconfigure.SeataCoreAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2025-08-21 23:14:33.397 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'springApplicationContextProvider' of type [io.seata.spring.boot.autoconfigure.provider.SpringApplicationContextProvider] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2025-08-21 23:14:33.397 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'io.seata.spring.boot.autoconfigure.SeataAutoConfiguration' of type [io.seata.spring.boot.autoconfigure.SeataAutoConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2025-08-21 23:14:33.460 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'failureHandler' of type [io.seata.tm.api.DefaultFailureHandlerImpl] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2025-08-21 23:14:33.479 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'springCloudAlibabaConfiguration' of type [io.seata.spring.boot.autoconfigure.properties.SpringCloudAlibabaConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2025-08-21 23:14:33.484 [main] INFO o.s.c.s.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'seataProperties' of type [io.seata.spring.boot.autoconfigure.properties.SeataProperties] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2025-08-21 23:14:33.485 [main] INFO i.s.s.b.a.SeataAutoConfiguration - Automatically configure Seata 2025-08-21 23:14:33.554 [main] INFO i.seata.config.ConfigurationFactory - load Configuration from :Spring Configuration 2025-08-21 23:14:33.566 [main] INFO i.seata.config.ConfigurationFactory - load Configuration from :Spring Configuration 2025-08-21 23:14:33.577 [main] INFO i.s.s.a.GlobalTransactionScanner - Initializing Global Transaction Clients ... 2025-08-21 23:14:33.662 [main] INFO i.s.c.rpc.netty.NettyClientBootstrap - NettyClientBootstrap has started 2025-08-21 23:14:33.663 [main] INFO i.s.d.registry.RegistryFactory - use registry center type: file 2025-08-21 23:14:33.670 [main] INFO i.s.c.r.n.NettyClientChannelManager - will connect to 10.180.22.20:61111 2025-08-21 23:14:33.698 [main] INFO i.s.c.rpc.netty.NettyPoolableFactory - NettyPool create channel to transactionRole:TMROLE,address:10.180.22.20:61111,msg:< RegisterTMRequest{version='1.8.0', applicationId='springboot-mybatis-seata', transactionServiceGroup='seata-framework-group', extraData='ak=null digest=seata-framework-group,100.103.26.86,1755789273696 timestamp=1755789273696 authVersion=V4 vgroup=seata-framework-group ip=100.103.26.86 '} > 2025-08-21 23:14:33.963 [NettyClientSelector_TMROLE_1_1] WARN i.s.c.l.EnhancedServiceLoader$InnerEnhancedServiceLoader - Load [io.seata.serializer.hessian.HessianSerializer] class fail: com/caucho/hessian/io/AbstractHessianOutput 2025-08-21 23:14:34.001 [main] INFO i.s.c.r.netty.TmNettyRemotingClient - register TM success. client version:1.8.0, server version:2.4.0,channel:[id: 0x1444ad38, L:/100.103.26.86:59034 - R:/10.180.22.20:61111] 2025-08-21 23:14:34.009 [main] INFO i.s.c.rpc.netty.NettyPoolableFactory - register success, cost 74 ms, version:2.4.0,role:TMROLE,channel:[id: 0x1444ad38, L:/100.103.26.86:59034 - R:/10.180.22.20:61111] 2025-08-21 23:14:34.009 [main] INFO i.s.s.a.GlobalTransactionScanner - Transaction Manager Client is initialized. applicationId[springboot-mybatis-seata] txServiceGroup[seata-framework-group] 2025-08-21 23:14:34.020 [main] INFO io.seata.rm.datasource.AsyncWorker - Async Commit Buffer Limit: 1000 2025-08-21 23:14:34.021 [main] INFO i.s.r.d.xa.ResourceManagerXA - ResourceManagerXA init ... 2025-08-21 23:14:34.026 [main] INFO i.s.c.rpc.netty.NettyClientBootstrap - NettyClientBootstrap has started 2025-08-21 23:14:34.026 [main] INFO i.s.s.a.GlobalTransactionScanner - Resource Manager is initialized. applicationId[springboot-mybatis-seata] txServiceGroup[seata-framework-group] 2025-08-21 23:14:34.026 [main] INFO i.s.s.a.GlobalTransactionScanner - Global Transaction Clients are initialized. 2025-08-21 23:14:34.172 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting... 2025-08-21 23:14:34.600 [main] INFO com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection com.p6spy.engine.wrapper.ConnectionWrapper@6003ad65 2025-08-21 23:14:34.602 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed. 2025-08-21 23:14:34.673 [main] WARN i.s.rm.datasource.DataSourceProxy - support for the dameng database is currently an experimental feature 2025-08-21 23:14:34.673 [main] INFO i.s.c.r.n.NettyClientChannelManager - will connect to 10.180.22.20:61111 2025-08-21 23:14:34.673 [main] INFO i.s.c.r.netty.RmNettyRemotingClient - RM will register :jdbc:dm://10.180.22.120:5236/TEST_AUTH 2025-08-21 23:14:34.673 [main] INFO i.s.c.rpc.netty.NettyPoolableFactory - NettyPool create channel to transactionRole:RMROLE,address:10.180.22.20:61111,msg:< RegisterRMRequest{resourceIds='jdbc:dm://10.180.22.120:5236/TEST_AUTH', version='1.8.0', applicationId='springboot-mybatis-seata', transactionServiceGroup='seata-framework-group', extraData='null'} > 2025-08-21 23:14:34.705 [main] INFO i.s.c.r.netty.RmNettyRemotingClient - register RM success. client version:1.8.0, server version:2.4.0,channel:[id: 0x4c3756e7, L:/100.103.26.86:59038 - R:/10.180.22.20:61111] 2025-08-21 23:14:34.705 [main] INFO i.s.c.rpc.netty.NettyPoolableFactory - register success, cost 17 ms, version:2.4.0,role:RMROLE,channel:[id: 0x4c3756e7, L:/100.103.26.86:59038 - R:/10.180.22.20:61111] 2025-08-21 23:14:34.708 [main] INFO i.s.s.a.d.SeataAutoDataSourceProxyCreator - Auto proxy data source 'dataSource' by 'AT' mode. 2025-08-21 23:14:35.118 [main] INFO i.s.s.a.GlobalTransactionScanner - Bean [org.apache.seata.service.impl.BusinessServiceImpl] with name [businessServiceImpl] would use interceptor [io.seata.spring.annotation.GlobalTransactionalInterceptor] 2025-08-21 23:14:35.380 [main] INFO o.a.seata.SpringbootSeataApplication - Started SpringbootSeataApplication in 3.672 seconds (process running for 4.601) 2025-08-21 23:14:35.389 [Thread-2] INFO i.seata.tm.TransactionManagerHolder - TransactionManager Singleton io.seata.tm.DefaultTransactionManager@3547b54c 2025-08-21 23:14:35.423 [Thread-2] INFO i.s.tm.api.DefaultGlobalTransaction - Begin new global transaction [10.180.22.20:61111:9690021082162052] 2025-08-21 23:14:35.423 [Thread-2] INFO o.a.seata.service.BusinessService - purchase begin ... xid: 10.180.22.20:61111:9690021082162052 2025-08-21 23:14:35.423 [Thread-2] INFO o.a.seata.service.StorageService - Stock Service Begin ... xid: 10.180.22.20:61111:9690021082162052 2025-08-21 23:14:35.423 [Thread-2] INFO o.a.seata.service.StorageService - Deducting inventory SQL: update stock_tbl set count = count - 1 where commodity_code = C00321 2025-08-21 23:14:35.747 [Thread-2] INFO p6spy - 1755789275747 | 13ms | statement | connection 0 | select id, commodity_code commodityCode, count from stock_tbl WHERE commodity_code = 'C00321' 2025-08-21 23:14:36.087 [Thread-2] INFO p6spy - 1755789276086 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.107 [Thread-2] INFO p6spy - 1755789276107 | 17ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:36.149 [Thread-2] INFO p6spy - 1755789276149 | 27ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:36.183 [Thread-2] INFO p6spy - 1755789276182 | 12ms | rollback | connection 0 | 2025-08-21 23:14:36.244 [Thread-2] INFO p6spy - 1755789276243 | 13ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.258 [Thread-2] INFO p6spy - 1755789276257 | 13ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:36.285 [Thread-2] INFO p6spy - 1755789276284 | 13ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:36.312 [Thread-2] INFO p6spy - 1755789276312 | 11ms | rollback | connection 0 | 2025-08-21 23:14:36.366 [Thread-2] INFO p6spy - 1755789276366 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.378 [Thread-2] INFO p6spy - 1755789276378 | 11ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:36.404 [Thread-2] INFO p6spy - 1755789276404 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:36.433 [Thread-2] INFO p6spy - 1755789276432 | 12ms | rollback | connection 0 | 2025-08-21 23:14:36.469 [Thread-2] INFO p6spy - 1755789276469 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.482 [Thread-2] INFO p6spy - 1755789276482 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:36.525 [Thread-2] INFO p6spy - 1755789276525 | 30ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:36.554 [Thread-2] INFO p6spy - 1755789276554 | 12ms | rollback | connection 0 | 2025-08-21 23:14:36.610 [Thread-2] INFO p6spy - 1755789276610 | 30ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.623 [Thread-2] INFO p6spy - 1755789276623 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:36.649 [Thread-2] INFO p6spy - 1755789276649 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:36.678 [Thread-2] INFO p6spy - 1755789276677 | 12ms | rollback | connection 0 | 2025-08-21 23:14:36.715 [Thread-2] INFO p6spy - 1755789276715 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.728 [Thread-2] INFO p6spy - 1755789276728 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:36.754 [Thread-2] INFO p6spy - 1755789276754 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:36.782 [Thread-2] INFO p6spy - 1755789276782 | 12ms | rollback | connection 0 | 2025-08-21 23:14:36.838 [Thread-2] INFO p6spy - 1755789276838 | 31ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.851 [Thread-2] INFO p6spy - 1755789276851 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:36.878 [Thread-2] INFO p6spy - 1755789276877 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:36.922 [Thread-2] INFO p6spy - 1755789276921 | 28ms | rollback | connection 0 | 2025-08-21 23:14:36.960 [Thread-2] INFO p6spy - 1755789276960 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:36.989 [Thread-2] INFO p6spy - 1755789276989 | 28ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:37.020 [Thread-2] INFO p6spy - 1755789277020 | 17ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:37.049 [Thread-2] INFO p6spy - 1755789277049 | 12ms | rollback | connection 0 | 2025-08-21 23:14:37.085 [Thread-2] INFO p6spy - 1755789277085 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:37.098 [Thread-2] INFO p6spy - 1755789277097 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:37.141 [Thread-2] INFO p6spy - 1755789277141 | 30ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:37.168 [Thread-2] INFO p6spy - 1755789277168 | 11ms | rollback | connection 0 | 2025-08-21 23:14:37.206 [Thread-2] INFO p6spy - 1755789277205 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:37.218 [Thread-2] INFO p6spy - 1755789277218 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:37.244 [Thread-2] INFO p6spy - 1755789277244 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:37.272 [Thread-2] INFO p6spy - 1755789277272 | 11ms | rollback | connection 0 | 2025-08-21 23:14:37.326 [Thread-2] INFO p6spy - 1755789277325 | 30ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:37.338 [Thread-2] INFO p6spy - 1755789277338 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:37.364 [Thread-2] INFO p6spy - 1755789277364 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:37.422 [Thread-2] INFO p6spy - 1755789277421 | 11ms | rollback | connection 0 | 2025-08-21 23:14:37.457 [Thread-2] INFO p6spy - 1755789277457 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:37.471 [Thread-2] INFO p6spy - 1755789277470 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:37.496 [Thread-2] INFO p6spy - 1755789277496 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:37.541 [Thread-2] INFO p6spy - 1755789277541 | 28ms | rollback | connection 0 | 2025-08-21 23:14:37.580 [Thread-2] INFO p6spy - 1755789277580 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:37.593 [Thread-2] INFO p6spy - 1755789277593 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:37.618 [Thread-2] INFO p6spy - 1755789277618 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:37.665 [Thread-2] INFO p6spy - 1755789277665 | 31ms | rollback | connection 0 | 2025-08-21 23:14:37.701 [Thread-2] INFO p6spy - 1755789277701 | 11ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:37.729 [Thread-2] INFO p6spy - 1755789277729 | 27ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:37.755 [Thread-2] INFO p6spy - 1755789277755 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:37.804 [Thread-2] INFO p6spy - 1755789277803 | 32ms | rollback | connection 0 | 2025-08-21 23:14:37.841 [Thread-2] INFO p6spy - 1755789277841 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:37.853 [Thread-2] INFO p6spy - 1755789277853 | 11ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.106 [Thread-2] INFO p6spy - 1755789278105 | 239ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.136 [Thread-2] INFO p6spy - 1755789278136 | 14ms | rollback | connection 0 | 2025-08-21 23:14:38.175 [Thread-2] INFO p6spy - 1755789278175 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:38.206 [Thread-2] INFO p6spy - 1755789278206 | 30ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.250 [Thread-2] INFO p6spy - 1755789278250 | 30ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.278 [Thread-2] INFO p6spy - 1755789278278 | 12ms | rollback | connection 0 | 2025-08-21 23:14:38.339 [Thread-2] INFO p6spy - 1755789278339 | 35ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:38.352 [Thread-2] INFO p6spy - 1755789278352 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.378 [Thread-2] INFO p6spy - 1755789278378 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.406 [Thread-2] INFO p6spy - 1755789278406 | 12ms | rollback | connection 0 | 2025-08-21 23:14:38.441 [Thread-2] INFO p6spy - 1755789278441 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:38.454 [Thread-2] INFO p6spy - 1755789278454 | 11ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.478 [Thread-2] INFO p6spy - 1755789278478 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.504 [Thread-2] INFO p6spy - 1755789278504 | 11ms | rollback | connection 0 | 2025-08-21 23:14:38.540 [Thread-2] INFO p6spy - 1755789278540 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:38.570 [Thread-2] INFO p6spy - 1755789278570 | 29ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.595 [Thread-2] INFO p6spy - 1755789278595 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.624 [Thread-2] INFO p6spy - 1755789278624 | 11ms | rollback | connection 0 | 2025-08-21 23:14:38.681 [Thread-2] INFO p6spy - 1755789278681 | 33ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:38.693 [Thread-2] INFO p6spy - 1755789278693 | 11ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.718 [Thread-2] INFO p6spy - 1755789278718 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.745 [Thread-2] INFO p6spy - 1755789278745 | 11ms | rollback | connection 0 | 2025-08-21 23:14:38.780 [Thread-2] INFO p6spy - 1755789278780 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:38.792 [Thread-2] INFO p6spy - 1755789278792 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.827 [Thread-2] INFO p6spy - 1755789278827 | 14ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.854 [Thread-2] INFO p6spy - 1755789278854 | 11ms | rollback | connection 0 | 2025-08-21 23:14:38.891 [Thread-2] INFO p6spy - 1755789278891 | 11ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:38.904 [Thread-2] INFO p6spy - 1755789278904 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:38.945 [Thread-2] INFO p6spy - 1755789278945 | 11ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:38.974 [Thread-2] INFO p6spy - 1755789278974 | 14ms | rollback | connection 0 | 2025-08-21 23:14:39.010 [Thread-2] INFO p6spy - 1755789279010 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:39.024 [Thread-2] INFO p6spy - 1755789279024 | 13ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:39.075 [Thread-2] INFO p6spy - 1755789279075 | 21ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:39.104 [Thread-2] INFO p6spy - 1755789279104 | 12ms | rollback | connection 0 | 2025-08-21 23:14:39.141 [Thread-2] INFO p6spy - 1755789279141 | 13ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:39.154 [Thread-2] INFO p6spy - 1755789279154 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:39.179 [Thread-2] INFO p6spy - 1755789279179 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:39.207 [Thread-2] INFO p6spy - 1755789279207 | 12ms | rollback | connection 0 | 2025-08-21 23:14:39.244 [Thread-2] INFO p6spy - 1755789279244 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:39.257 [Thread-2] INFO p6spy - 1755789279257 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:39.301 [Thread-2] INFO p6spy - 1755789279301 | 30ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:39.533 [Thread-2] INFO p6spy - 1755789279533 | 12ms | rollback | connection 0 | 2025-08-21 23:14:39.571 [Thread-2] INFO p6spy - 1755789279571 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:39.583 [Thread-2] INFO p6spy - 1755789279583 | 11ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:39.632 [Thread-2] INFO p6spy - 1755789279632 | 36ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:39.659 [Thread-2] INFO p6spy - 1755789279658 | 11ms | rollback | connection 0 | 2025-08-21 23:14:39.695 [Thread-2] INFO p6spy - 1755789279695 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:39.708 [Thread-2] INFO p6spy - 1755789279708 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:39.735 [Thread-2] INFO p6spy - 1755789279735 | 13ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:39.762 [Thread-2] INFO p6spy - 1755789279761 | 11ms | rollback | connection 0 | 2025-08-21 23:14:39.929 [Thread-2] INFO p6spy - 1755789279928 | 142ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:39.941 [Thread-2] INFO p6spy - 1755789279941 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:39.966 [Thread-2] INFO p6spy - 1755789279966 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:39.994 [Thread-2] INFO p6spy - 1755789279994 | 12ms | rollback | connection 0 | 2025-08-21 23:14:40.031 [Thread-2] INFO p6spy - 1755789280031 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:40.044 [Thread-2] INFO p6spy - 1755789280044 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:40.069 [Thread-2] INFO p6spy - 1755789280069 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:40.112 [Thread-2] INFO p6spy - 1755789280112 | 14ms | rollback | connection 0 | 2025-08-21 23:14:40.149 [Thread-2] INFO p6spy - 1755789280149 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:40.162 [Thread-2] INFO p6spy - 1755789280162 | 12ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:40.210 [Thread-2] INFO p6spy - 1755789280209 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:40.242 [Thread-2] INFO p6spy - 1755789280242 | 12ms | rollback | connection 0 | 2025-08-21 23:14:40.280 [Thread-2] INFO p6spy - 1755789280280 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE id = 116 FOR UPDATE 2025-08-21 23:14:40.293 [Thread-2] INFO p6spy - 1755789280293 | 11ms | statement | connection 0 | update stock_tbl set count = 99 WHERE id = 116 2025-08-21 23:14:40.319 [Thread-2] INFO p6spy - 1755789280319 | 12ms | statement | connection 0 | SELECT "id", "count" FROM stock_tbl WHERE ("id") in ( (116) ) 2025-08-21 23:14:40.347 [Thread-2] INFO p6spy - 1755789280347 | 12ms | rollback | connection 0 | 2025-08-21 23:14:40.347 [Thread-2] ERROR i.s.r.d.exec.AbstractDMLBaseExecutor - execute executeAutoCommitTrue error:Global lock wait timeout io.seata.rm.datasource.exec.LockWaitTimeoutException: Global lock wait timeout at io.seata.rm.datasource.exec.LockRetryController.sleep(LockRetryController.java:66) at io.seata.rm.datasource.ConnectionProxy$LockRetryPolicy.doRetryOnLockConflict(ConnectionProxy.java:364) at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor$LockRetryPolicy.execute(AbstractDMLBaseExecutor.java:188) at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor.executeAutoCommitTrue(AbstractDMLBaseExecutor.java:144) at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor.doExecute(AbstractDMLBaseExecutor.java:83) at io.seata.rm.datasource.exec.BaseTransactionalExecutor.execute(BaseTransactionalExecutor.java:124) at io.seata.rm.datasource.exec.ExecuteTemplate.execute(ExecuteTemplate.java:153) at io.seata.rm.datasource.exec.ExecuteTemplate.execute(ExecuteTemplate.java:60) at io.seata.rm.datasource.PreparedStatementProxy.execute(PreparedStatementProxy.java:55) at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:48) at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:75) at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:50) at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117) at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.apache.ibatis.plugin.Plugin.invoke(Plugin.java:61) at jdk.proxy2/jdk.proxy2.$Proxy79.update(Unknown Source) at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:197) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:425) at jdk.proxy2/jdk.proxy2.$Proxy61.update(Unknown Source) at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:288) at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:67) at org.apache.ibatis.binding.MapperProxy$PlainMethodInvoker.invoke(MapperProxy.java:141) at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:86) at jdk.proxy2/jdk.proxy2.$Proxy67.updateById(Unknown Source) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:244) at jdk.proxy2/jdk.proxy2.$Proxy68.updateById(Unknown Source) at org.apache.seata.service.impl.StorageServiceImpl.deduct(StorageServiceImpl.java:49) at org.apache.seata.service.impl.BusinessServiceImpl.purchase(BusinessServiceImpl.java:59) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343) at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:196) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:751) at io.seata.spring.annotation.GlobalTransactionalInterceptor$2.execute(GlobalTransactionalInterceptor.java:208) at io.seata.tm.api.TransactionalTemplate.execute(TransactionalTemplate.java:128) at io.seata.spring.annotation.GlobalTransactionalInterceptor.handleGlobalTransaction(GlobalTransactionalInterceptor.java:205) at io.seata.spring.annotation.GlobalTransactionalInterceptor.invoke(GlobalTransactionalInterceptor.java:175) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:751) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:703) at org.apache.seata.service.impl.BusinessServiceImpl$$SpringCGLIB$$0.purchase(<generated>) at org.apache.seata.SpringbootSeataApplication.lambda$main$0(SpringbootSeataApplication.java:40) at java.base/java.lang.Thread.run(Thread.java:833) Caused by: io.seata.rm.datasource.exec.LockConflictException: get global lock fail, xid:10.180.22.20:61111:9690021082162052, lockKeys:stock_tbl:116 at io.seata.rm.datasource.ConnectionProxy.recognizeLockKeyConflictException(ConnectionProxy.java:159) at io.seata.rm.datasource.ConnectionProxy.processGlobalTransactionCommit(ConnectionProxy.java:252) at io.seata.rm.datasource.ConnectionProxy.doCommit(ConnectionProxy.java:230) at io.seata.rm.datasource.ConnectionProxy.lambda$commit$0(ConnectionProxy.java:188) at io.seata.rm.datasource.ConnectionProxy$LockRetryPolicy.execute(ConnectionProxy.java:344) at io.seata.rm.datasource.ConnectionProxy.commit(ConnectionProxy.java:187) at io.seata.rm.datasource.exec.AbstractDMLBaseExecutor.lambda$executeAutoCommitTrue$2(AbstractDMLBaseExecutor.java:146) at io.seata.rm.datasource.ConnectionProxy$LockRetryPolicy.doRetryOnLockConflict(ConnectionProxy.java:356) ... 61 common frames omitted 2025-08-21 23:14:40.396 [Thread-2] INFO i.s.tm.api.DefaultGlobalTransaction - transaction 10.180.22.20:61111:9690021082162052 will be rollback 2025-08-21 23:14:40.424 [Thread-2] INFO i.s.tm.api.DefaultGlobalTransaction - transaction end, xid = 10.180.22.20:61111:9690021082162052 2025-08-21 23:14:40.424 [Thread-2] INFO i.s.tm.api.DefaultGlobalTransaction - [10.180.22.20:61111:9690021082162052] rollback status: Rollbacked 2025-08-21 23:17:15.184 [SpringContextShutdownHook] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated... 2025-08-21 23:17:15.186 [SpringContextShutdownHook] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed. 2025-08-21 23:17:15.187 [NettyClientSelector_TMROLE_1_1] INFO i.s.c.r.n.AbstractNettyRemotingClient - channel inactive: [id: 0x1444ad38, L:/100.103.26.86:59034 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.188 [NettyClientSelector_TMROLE_1_1] INFO i.s.c.r.n.NettyClientChannelManager - return to pool, rm channel:[id: 0x1444ad38, L:/100.103.26.86:59034 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.188 [NettyClientSelector_TMROLE_1_1] INFO i.s.c.rpc.netty.NettyPoolableFactory - channel valid false,channel:[id: 0x1444ad38, L:/100.103.26.86:59034 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.188 [NettyClientSelector_TMROLE_1_1] INFO i.s.c.rpc.netty.NettyPoolableFactory - will destroy channel:[id: 0x1444ad38, L:/100.103.26.86:59034 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.188 [NettyClientSelector_TMROLE_1_1] INFO i.s.c.r.n.AbstractNettyRemotingClient - ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x1444ad38, L:/100.103.26.86:59034 ! R:/10.180.22.20:61111]) will closed 2025-08-21 23:17:15.188 [NettyClientSelector_TMROLE_1_1] INFO i.s.c.r.n.AbstractNettyRemotingClient - ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x1444ad38, L:/100.103.26.86:59034 ! R:/10.180.22.20:61111]) will closed 2025-08-21 23:17:15.189 [NettyClientSelector_RMROLE_1_1] INFO i.s.c.r.n.AbstractNettyRemotingClient - channel inactive: [id: 0x4c3756e7, L:/100.103.26.86:59038 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.189 [NettyClientSelector_RMROLE_1_1] INFO i.s.c.r.n.NettyClientChannelManager - return to pool, rm channel:[id: 0x4c3756e7, L:/100.103.26.86:59038 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.189 [NettyClientSelector_RMROLE_1_1] INFO i.s.c.rpc.netty.NettyPoolableFactory - channel valid false,channel:[id: 0x4c3756e7, L:/100.103.26.86:59038 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.189 [NettyClientSelector_RMROLE_1_1] INFO i.s.c.rpc.netty.NettyPoolableFactory - will destroy channel:[id: 0x4c3756e7, L:/100.103.26.86:59038 ! R:/10.180.22.20:61111] 2025-08-21 23:17:15.189 [NettyClientSelector_RMROLE_1_1] INFO i.s.c.r.n.AbstractNettyRemotingClient - ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x4c3756e7, L:/100.103.26.86:59038 ! R:/10.180.22.20:61111]) will closed 2025-08-21 23:17:15.189 [NettyClientSelector_RMROLE_1_1] INFO i.s.c.r.n.AbstractNettyRemotingClient - ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x4c3756e7, L:/100.103.26.86:59038 ! R:/10.180.22.20:61111]) will closed 进程已结束，退出代码为 137 (interrupted by signal 9:SIGKILL) ### Ⅲ. Describe what you expected to happen 按照一般理解应该重试的时间为300ms左右，想询问这里的实现机制 ### Ⅳ. How to reproduce it (as minimally and precisely as possible) 使用incubator-seata-samples-master/at-sample/springboot-mybatis-seata 仓库，并提前注入全局锁，模拟获取全局锁失败的场景 ### Ⅴ. Anything else we need to know? 我们正在排查慢sql的问题，发现很多select ...for update ,这是seata at 模式在查询前镜像时执行的，想确认在并发高的情况下 全局锁竞争最多持有本地行锁的时间 ### Ⅵ. Environment 客户端 jdk17 mac、服务端jdk8 centos 单节点 -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
