You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@seata.apache.org by "tonglsh (via GitHub)" <gi...@apache.org> on 2025/08/21 15:39:25 UTC
[I] 客户端配置的retry-interval 好像并不准确 [incubator-seata]
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: notifications-unsubscribe@seata.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@seata.apache.org
For additional commands, e-mail: notifications-help@seata.apache.org
Re: [I] 客户端配置的retry-interval 好像并不准确 [incubator-seata]
Posted by "tonglsh (via GitHub)" <gi...@apache.org>.
tonglsh commented on issue #7590:
URL: https://github.com/apache/incubator-seata/issues/7590#issuecomment-3211156531
数据库本地数据：
select * from TEST_AUTH.account_tbl;
116 U100001 10000
select * from TEST_AUTH.order_tbl;
select * from TEST_AUTH.stock_tbl;
116 C00321 100
seata-server 数据库数据:
select * from SEATA5.global_table gt where XID = '10.180.22.20:61111:9690021082154650';
10.180.22.20:61111:9690021082154650 9690021082154650 6 springboot-mybatis-seata seata-framework-group spring-seata-tx 3000000 1755787728547 NULL 2025-08-21 22:48:49 2025-08-21 23:38:49
select * from SEATA5.branch_table bt where XID = '10.180.22.20:61111:9690021082154650';
9690021082154655 10.180.22.20:61111:9690021082154650 9690021082154650 NULL jdbc:dm://10.180.22.120:5236/TEST_AUTH AT 1 springboot-mybatis-seata:10.180.10.52:34984 NULL 2025-08-21 22:48:49 2025-08-21 22:48:49
9690021082154657 10.180.22.20:61111:9690021082154650 9690021082154650 NULL jdbc:dm://10.180.22.120:5236/TEST_AUTH AT 1 springboot-mybatis-seata:10.180.10.52:34984 {"skipCheckLock":true} 2025-08-21 22:48:49 2025-08-21 22:48:49
9690021082154662 10.180.22.20:61111:9690021082154650 9690021082154650 NULL jdbc:dm://10.180.22.120:5236/TEST_AUTH AT 1 springboot-mybatis-seata:10.180.10.52:34984 NULL 2025-08-21 22:48:50 2025-08-21 22:48:50
select * from SEATA5.lock_table lt where XID = '10.180.22.20:61111:9690021082154650';
jdbc:dm://10.180.22.120:5236/TEST_AUTH^^^stock_tbl^^^116 10.180.22.20:61111:9690021082154650 9690021082154650 9690021082154655 jdbc:dm://10.180.22.120:5236/TEST_AUTH stock_tbl 116 1 2025-08-21 22:48:49 2025-08-21 22:48:49
jdbc:dm://10.180.22.120:5236/TEST_AUTH^^^order_tbl^^^40 10.180.22.20:61111:9690021082154650 9690021082154650 9690021082154657 jdbc:dm://10.180.22.120:5236/TEST_AUTH order_tbl 40 1 2025-08-21 22:48:49 2025-08-21 22:48:49
jdbc:dm://10.180.22.120:5236/TEST_AUTH^^^account_tbl^^^116 10.180.22.20:61111:9690021082154650 9690021082154650 9690021082154662 jdbc:dm://10.180.22.120:5236/TEST_AUTH account_tbl 116 1 2025-08-21 22:48:50 2025-08-21 22:48:50
--
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: notifications-unsubscribe@seata.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@seata.apache.org
For additional commands, e-mail: notifications-help@seata.apache.org
Re: [I] 客户端配置的retry-interval 好像并不准确 [incubator-seata]
Posted by "tonglsh (via GitHub)" <gi...@apache.org>.
tonglsh closed issue #7590: 客户端配置的retry-interval 好像并不准确
URL: https://github.com/apache/incubator-seata/issues/7590
--
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: notifications-unsubscribe@seata.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@seata.apache.org
For additional commands, e-mail: notifications-help@seata.apache.org
Re: [I] 客户端配置的retry-interval 好像并不准确 [incubator-seata]
Posted by "tonglsh (via GitHub)" <gi...@apache.org>.
tonglsh commented on issue #7590:
URL: https://github.com/apache/incubator-seata/issues/7590#issuecomment-3211231309
如果有人知道这个机制是什么导致的，时间开销花费在哪里，欢迎解答
--
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: notifications-unsubscribe@seata.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@seata.apache.org
For additional commands, e-mail: notifications-help@seata.apache.org
Re: [I] 客户端配置的retry-interval 好像并不准确 [incubator-seata]
Posted by "tonglsh (via GitHub)" <gi...@apache.org>.
tonglsh commented on issue #7590:
URL: https://github.com/apache/incubator-seata/issues/7590#issuecomment-3211216209
我又模拟了在重试获取全局锁时的本地锁竞争情况，发现此时seata的本地锁是循环间隔持有的，在间隙依然可以被别的事务加锁，并不会一直持有导致本地锁阻塞，我的问题解决了，所以我关闭这个issue吧
--
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: notifications-unsubscribe@seata.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@seata.apache.org
For additional commands, e-mail: notifications-help@seata.apache.org
Re: [I] 客户端配置的retry-interval 好像并不准确 [incubator-seata]
Posted by "tonglsh (via GitHub)" <gi...@apache.org>.
tonglsh commented on issue #7590:
URL: https://github.com/apache/incubator-seata/issues/7590#issuecomment-3211194515
实际上参数配置是生效了的，在配置了retry-interval: 1000 明显增大了重试间隔，但是配置的较小时，比如配置1ms最低间隔也有100ms，可能与我本机的性能有关，也就是我计算因竞争全局锁而持有的本地锁时常的算法有问题
--
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: notifications-unsubscribe@seata.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: notifications-unsubscribe@seata.apache.org
For additional commands, e-mail: notifications-help@seata.apache.org