incubator-seata icon indicating copy to clipboard operation
incubator-seata copied to clipboard

Published 20 hours ago • verified publisher icon apache

Saga模式下 V1.5.X版本全局事务超时回滚问题

Open JPPeng opened this issue 2 years ago • 3 comments

所有分支事务结束后【不论是否正常提交。正常提交所有相应的分支事务成功记录；有异常时，有相应的异常记录及补偿记录】，但全局事务最后有进入一个空的Begin分支： report status: Begin route instruction is null, process end 在半小时【1800000ms】后，会对所有正常执行的分析进行补偿操作，结束全局事务，并清除全局表中相关记录。： report status: TimeoutRollbacking route instruction is null, process end Branch Rollbacked result: PhaseTwo_Rollbacked

JPPeng avatar Aug 11 '22 07:08 JPPeng

但是同样问题在V1.4.2版本中不存在

JPPeng avatar Aug 11 '22 07:08 JPPeng

与问题：https://github.com/seata/seata/issues/4852 类似表现。所有正常提交或补偿的分支事务都会回滚。

JPPeng avatar Aug 11 '22 07:08 JPPeng

昨天刚新建了类似的issue，不过我只有在seata多节点的时候会遇到这个这个问题，nacos做注册中心

Shi-Le-Zhi avatar Aug 11 '22 07:08 Shi-Le-Zhi

为方便专家分析，提供一个所有分支事务正常提交后，半小时后回滚的客户端与服务端事务日志文件。 E:\jdk-11.0.9\bin\java.exe -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:2149,suspend=y,server=n -XX:TieredStopAtLevel=1 -noverify -Dspring.output.ansi.enabled=always -javaagent:C:\Users\dell\AppData\Local\JetBrains\IntelliJIdea2021.2\captureAgent\debugger-agent.jar -Dcom.sun.management.jmxremote -Dspring.jmx.enabled=true -Dspring.liveBeansView.mbeanDomain -Dspring.application.admin.enabled=true -Dfile.encoding=UTF-8 -classpath "E:\newonline\springcloud-eureka-seata-saga-master\order-server\target\classes;D:\maven\repository\com\alibaba\cloud\spring-cloud-starter-alibaba-nacos-discovery\2.2.5.RELEASE\spring-cloud-starter-alibaba-nacos-discovery-2.2.5.RELEASE.jar;D:\maven\repository\com\alibaba\cloud\spring-cloud-alibaba-commons\2.2.5.RELEASE\spring-cloud-alibaba-commons-2.2.5.RELEASE.jar;D:\maven\repository\com\alibaba\nacos\nacos-client\1.4.1\nacos-client-1.4.1.jar;D:\maven\repository\com\alibaba\nacos\nacos-common\1.4.1\nacos-common-1.4.1.jar;D:\maven\repository\commons-io\commons-io\2.2\commons-io-2.2.jar;D:\maven\repository\org\apache\httpcomponents\httpasyncclient\4.1.4\httpasyncclient-4.1.4.jar;D:\maven\repository\org\apache\httpcomponents\httpcore\4.4.14\httpcore-4.4.14.jar;D:\maven\repository\org\apache\httpcomponents\httpcore-nio\4.4.14\httpcore-nio-4.4.14.jar;D:\maven\repository\com\alibaba\nacos\nacos-api\1.4.1\nacos-api-1.4.1.jar;D:\maven\repository\com\google\guava\guava\29.0-jre\guava-29.0-jre.jar;D:\maven\repository\com\google\guava\failureaccess\1.0.1\failureaccess-1.0.1.jar;D:\maven\repository\com\google\guava\listenablefuture\9999.0-empty-to-avoid-conflict-with-guava\listenablefuture-9999.0-empty-to-avoid-conflict-with-guava.jar;D:\maven\repository\com\google\code\findbugs\jsr305\3.0.2\jsr305-3.0.2.jar;D:\maven\repository\org\checkerframework\checker-qual\2.11.1\checker-qual-2.11.1.jar;D:\maven\repository\com\google\errorprone\error_prone_annotations\2.3.4\error_prone_annotations-2.3.4.jar;D:\maven\repository\com\google\j2objc\j2objc-annotations\1.3\j2objc-annotations-1.3.jar;D:\maven\repository\commons-codec\commons-codec\1.14\commons-codec-1.14.jar;D:\maven\repository\com\fasterxml\jackson\core\jackson-core\2.11.4\jackson-core-2.11.4.jar;D:\maven\repository\com\fasterxml\jackson\core\jackson-databind\2.11.4\jackson-databind-2.11.4.jar;D:\maven\repository\com\fasterxml\jackson\core\jackson-annotations\2.11.4\jackson-annotations-2.11.4.jar;D:\maven\repository\io\prometheus\simpleclient\0.5.0\simpleclient-0.5.0.jar;D:\maven\repository\org\yaml\snakeyaml\1.26\snakeyaml-1.26.jar;D:\maven\repository\com\alibaba\spring\spring-context-support\1.0.10\spring-context-support-1.0.10.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-commons\2.2.5.RELEASE\spring-cloud-commons-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\security\spring-security-crypto\5.3.8.RELEASE\spring-security-crypto-5.3.8.RELEASE.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-context\2.2.5.RELEASE\spring-cloud-context-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-starter-netflix-ribbon\2.2.5.RELEASE\spring-cloud-starter-netflix-ribbon-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-netflix-ribbon\2.2.5.RELEASE\spring-cloud-netflix-ribbon-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-netflix-archaius\2.2.5.RELEASE\spring-cloud-netflix-archaius-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-starter-netflix-archaius\2.2.5.RELEASE\spring-cloud-starter-netflix-archaius-2.2.5.RELEASE.jar;D:\maven\repository\commons-configuration\commons-configuration\1.8\commons-configuration-1.8.jar;D:\maven\repository\com\netflix\ribbon\ribbon\2.3.0\ribbon-2.3.0.jar;D:\maven\repository\com\netflix\ribbon\ribbon-transport\2.3.0\ribbon-transport-2.3.0.jar;D:\maven\repository\io\reactivex\rxnetty-contexts\0.4.9\rxnetty-contexts-0.4.9.jar;D:\maven\repository\io\reactivex\rxnetty-servo\0.4.9\rxnetty-servo-0.4.9.jar;D:\maven\repository\javax\inject\javax.inject\1\javax.inject-1.jar;D:\maven\repository\io\reactivex\rxnetty\0.4.9\rxnetty-0.4.9.jar;D:\maven\repository\com\netflix\ribbon\ribbon-core\2.3.0\ribbon-core-2.3.0.jar;D:\maven\repository\com\netflix\ribbon\ribbon-httpclient\2.3.0\ribbon-httpclient-2.3.0.jar;D:\maven\repository\commons-collections\commons-collections\3.2.2\commons-collections-3.2.2.jar;D:\maven\repository\org\apache\httpcomponents\httpclient\4.5.13\httpclient-4.5.13.jar;D:\maven\repository\com\sun\jersey\jersey-client\1.19.1\jersey-client-1.19.1.jar;D:\maven\repository\com\sun\jersey\jersey-core\1.19.1\jersey-core-1.19.1.jar;D:\maven\repository\javax\ws\rs\jsr311-api\1.1.1\jsr311-api-1.1.1.jar;D:\maven\repository\com\sun\jersey\contribs\jersey-apache-client4\1.19.1\jersey-apache-client4-1.19.1.jar;D:\maven\repository\com\netflix\servo\servo-core\0.12.21\servo-core-0.12.21.jar;D:\maven\repository\com\netflix\netflix-commons\netflix-commons-util\0.3.0\netflix-commons-util-0.3.0.jar;D:\maven\repository\com\netflix\ribbon\ribbon-loadbalancer\2.3.0\ribbon-loadbalancer-2.3.0.jar;D:\maven\repository\com\netflix\netflix-commons\netflix-statistics\0.1.1\netflix-statistics-0.1.1.jar;D:\maven\repository\io\reactivex\rxjava\1.3.8\rxjava-1.3.8.jar;D:\maven\repository\org\springframework\boot\spring-boot-starter-web\2.3.9.RELEASE\spring-boot-starter-web-2.3.9.RELEASE.jar;D:\maven\repository\org\springframework\boot\spring-boot-starter\2.3.9.RELEASE\spring-boot-starter-2.3.9.RELEASE.jar;D:\maven\repository\org\springframework\boot\spring-boot\2.3.9.RELEASE\spring-boot-2.3.9.RELEASE.jar;D:\maven\repository\org\springframework\boot\spring-boot-starter-logging\2.3.9.RELEASE\spring-boot-starter-logging-2.3.9.RELEASE.jar;D:\maven\repository\ch\qos\logback\logback-classic\1.2.3\logback-classic-1.2.3.jar;D:\maven\repository\ch\qos\logback\logback-core\1.2.3\logback-core-1.2.3.jar;D:\maven\repository\org\apache\logging\log4j\log4j-to-slf4j\2.13.3\log4j-to-slf4j-2.13.3.jar;D:\maven\repository\org\apache\logging\log4j\log4j-api\2.13.3\log4j-api-2.13.3.jar;D:\maven\repository\org\slf4j\jul-to-slf4j\1.7.30\jul-to-slf4j-1.7.30.jar;D:\maven\repository\jakarta\annotation\jakarta.annotation-api\1.3.5\jakarta.annotation-api-1.3.5.jar;D:\maven\repository\org\springframework\boot\spring-boot-starter-json\2.3.9.RELEASE\spring-boot-starter-json-2.3.9.RELEASE.jar;D:\maven\repository\com\fasterxml\jackson\datatype\jackson-datatype-jdk8\2.11.4\jackson-datatype-jdk8-2.11.4.jar;D:\maven\repository\com\fasterxml\jackson\datatype\jackson-datatype-jsr310\2.11.4\jackson-datatype-jsr310-2.11.4.jar;D:\maven\repository\com\fasterxml\jackson\module\jackson-module-parameter-names\2.11.4\jackson-module-parameter-names-2.11.4.jar;D:\maven\repository\org\springframework\boot\spring-boot-starter-tomcat\2.3.9.RELEASE\spring-boot-starter-tomcat-2.3.9.RELEASE.jar;D:\maven\repository\org\apache\tomcat\embed\tomcat-embed-core\9.0.43\tomcat-embed-core-9.0.43.jar;D:\maven\repository\org\glassfish\jakarta.el\3.0.3\jakarta.el-3.0.3.jar;D:\maven\repository\org\apache\tomcat\embed\tomcat-embed-websocket\9.0.43\tomcat-embed-websocket-9.0.43.jar;D:\maven\repository\org\springframework\spring-web\5.2.13.RELEASE\spring-web-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\spring-beans\5.2.13.RELEASE\spring-beans-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\spring-webmvc\5.2.13.RELEASE\spring-webmvc-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\spring-aop\5.2.13.RELEASE\spring-aop-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\spring-context\5.2.13.RELEASE\spring-context-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\spring-expression\5.2.13.RELEASE\spring-expression-5.2.13.RELEASE.jar;D:\maven\repository\mysql\mysql-connector-java\5.1.47\mysql-connector-java-5.1.47.jar;D:\maven\repository\com\baomidou\mybatis-plus-boot-starter\3.3.0\mybatis-plus-boot-starter-3.3.0.jar;D:\maven\repository\com\baomidou\mybatis-plus\3.3.0\mybatis-plus-3.3.0.jar;D:\maven\repository\com\baomidou\mybatis-plus-extension\3.3.0\mybatis-plus-extension-3.3.0.jar;D:\maven\repository\com\baomidou\mybatis-plus-core\3.3.0\mybatis-plus-core-3.3.0.jar;D:\maven\repository\com\baomidou\mybatis-plus-annotation\3.3.0\mybatis-plus-annotation-3.3.0.jar;D:\maven\repository\com\github\jsqlparser\jsqlparser\3.1\jsqlparser-3.1.jar;D:\maven\repository\org\mybatis\mybatis\3.5.3\mybatis-3.5.3.jar;D:\maven\repository\org\mybatis\mybatis-spring\2.0.3\mybatis-spring-2.0.3.jar;D:\maven\repository\org\springframework\boot\spring-boot-autoconfigure\2.3.9.RELEASE\spring-boot-autoconfigure-2.3.9.RELEASE.jar;D:\maven\repository\org\springframework\boot\spring-boot-starter-jdbc\2.3.9.RELEASE\spring-boot-starter-jdbc-2.3.9.RELEASE.jar;D:\maven\repository\com\zaxxer\HikariCP\3.4.5\HikariCP-3.4.5.jar;D:\maven\repository\org\springframework\spring-jdbc\5.2.13.RELEASE\spring-jdbc-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\spring-tx\5.2.13.RELEASE\spring-tx-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-starter-openfeign\2.2.5.RELEASE\spring-cloud-starter-openfeign-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-starter\2.2.5.RELEASE\spring-cloud-starter-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\security\spring-security-rsa\1.0.9.RELEASE\spring-security-rsa-1.0.9.RELEASE.jar;D:\maven\repository\org\bouncycastle\bcpkix-jdk15on\1.64\bcpkix-jdk15on-1.64.jar;D:\maven\repository\org\bouncycastle\bcprov-jdk15on\1.64\bcprov-jdk15on-1.64.jar;D:\maven\repository\org\springframework\cloud\spring-cloud-openfeign-core\2.2.5.RELEASE\spring-cloud-openfeign-core-2.2.5.RELEASE.jar;D:\maven\repository\io\github\openfeign\form\feign-form-spring\3.8.0\feign-form-spring-3.8.0.jar;D:\maven\repository\io\github\openfeign\form\feign-form\3.8.0\feign-form-3.8.0.jar;D:\maven\repository\commons-fileupload\commons-fileupload\1.4\commons-fileupload-1.4.jar;D:\maven\repository\io\github\openfeign\feign-core\10.10.1\feign-core-10.10.1.jar;D:\maven\repository\io\github\openfeign\feign-slf4j\10.10.1\feign-slf4j-10.10.1.jar;D:\maven\repository\org\slf4j\slf4j-api\1.7.30\slf4j-api-1.7.30.jar;D:\maven\repository\io\github\openfeign\feign-hystrix\10.10.1\feign-hystrix-10.10.1.jar;D:\maven\repository\com\netflix\archaius\archaius-core\0.7.6\archaius-core-0.7.6.jar;D:\maven\repository\com\netflix\hystrix\hystrix-core\1.5.18\hystrix-core-1.5.18.jar;D:\maven\repository\org\hdrhistogram\HdrHistogram\2.1.9\HdrHistogram-2.1.9.jar;D:\maven\repository\com\alibaba\cloud\spring-cloud-starter-alibaba-seata\2.2.5.RELEASE\spring-cloud-starter-alibaba-seata-2.2.5.RELEASE.jar;D:\maven\repository\org\springframework\boot\spring-boot-starter-aop\2.3.9.RELEASE\spring-boot-starter-aop-2.3.9.RELEASE.jar;D:\maven\repository\org\aspectj\aspectjweaver\1.9.6\aspectjweaver-1.9.6.jar;D:\maven\repository\io\seata\seata-spring-boot-starter\1.5.2\seata-spring-boot-starter-1.5.2.jar;D:\maven\repository\io\seata\seata-spring-autoconfigure-client\1.5.2\seata-spring-autoconfigure-client-1.5.2.jar;D:\maven\repository\io\seata\seata-spring-autoconfigure-core\1.5.2\seata-spring-autoconfigure-core-1.5.2.jar;D:\maven\repository\io\seata\seata-all\1.5.2\seata-all-1.5.2.jar;D:\maven\repository\io\netty\netty-all\4.1.59.Final\netty-all-4.1.59.Final.jar;D:\maven\repository\org\antlr\antlr4\4.8\antlr4-4.8.jar;D:\maven\repository\org\antlr\antlr4-runtime\4.8\antlr4-runtime-4.8.jar;D:\maven\repository\org\antlr\antlr-runtime\3.5.2\antlr-runtime-3.5.2.jar;D:\maven\repository\org\antlr\ST4\4.3\ST4-4.3.jar;D:\maven\repository\org\abego\treelayout\org.abego.treelayout.core\1.0.3\org.abego.treelayout.core-1.0.3.jar;D:\maven\repository\org\glassfish\javax.json\1.0.4\javax.json-1.0.4.jar;D:\maven\repository\com\ibm\icu\icu4j\61.1\icu4j-61.1.jar;D:\maven\repository\com\alibaba\fastjson\1.2.83\fastjson-1.2.83.jar;D:\maven\repository\com\alibaba\druid\1.2.6\druid-1.2.6.jar;D:\maven\repository\com\typesafe\config\1.2.1\config-1.2.1.jar;D:\maven\repository\commons-lang\commons-lang\2.6\commons-lang-2.6.jar;D:\maven\repository\org\apache\commons\commons-pool2\2.8.1\commons-pool2-2.8.1.jar;D:\maven\repository\commons-pool\commons-pool\1.6\commons-pool-1.6.jar;D:\maven\repository\cglib\cglib\3.1\cglib-3.1.jar;D:\maven\repository\org\ow2\asm\asm\4.2\asm-4.2.jar;D:\maven\repository\aopalliance\aopalliance\1.0\aopalliance-1.0.jar;D:\maven\repository\com\github\ben-manes\caffeine\caffeine\2.8.8\caffeine-2.8.8.jar;D:\maven\repository\org\apache\commons\commons-lang3\3.4\commons-lang3-3.4.jar;D:\maven\repository\org\projectlombok\lombok\1.18.18\lombok-1.18.18.jar;D:\maven\repository\org\springframework\spring-core\5.2.13.RELEASE\spring-core-5.2.13.RELEASE.jar;D:\maven\repository\org\springframework\spring-jcl\5.2.13.RELEASE\spring-jcl-5.2.13.RELEASE.jar;C:\Program Files\JetBrains\IntelliJ IDEA 2021.2\lib\idea_rt.jar" io.seata.sample.OrderServerApplication Connected to the target VM, address: '127.0.0.1:2149', transport: 'socket'

. ____ _ __ _ _ /\ / ' __ _ () __ __ _ \ \ \
( ( )__ | '_ | '| | ' / ` | \ \ \
\/ )| |)| | | | | || (| | ) ) ) ) ' || .__|| ||| |_, | / / / / =========||==============|/=//// :: Spring Boot :: (v2.3.9.RELEASE)

2022-08-11 23:07:54.247 INFO 1368 --- [ main] io.seata.sample.OrderServerApplication : No active profile set, falling back to default profiles: default 2022-08-11 23:07:55.352 INFO 1368 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=753931ab-e8a8-3908-9ab2-050c3c0f1f82 2022-08-11 23:07:55.358 INFO 1368 --- [ main] trationDelegate$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) 2022-08-11 23:07:55.359 INFO 1368 --- [ main] trationDelegate$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) 2022-08-11 23:07:55.360 INFO 1368 --- [ main] trationDelegate$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) 2022-08-11 23:07:55.394 INFO 1368 --- [ main] trationDelegate$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) 2022-08-11 23:07:55.413 INFO 1368 --- [ main] trationDelegate$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) 2022-08-11 23:07:55.418 INFO 1368 --- [ main] trationDelegate$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) 2022-08-11 23:07:55.421 INFO 1368 --- [ main] i.s.s.b.a.SeataAutoConfiguration : Automatically configure Seata 2022-08-11 23:07:55.492 INFO 1368 --- [ main] io.seata.config.ConfigurationFactory : load Configuration from :Spring Configuration 2022-08-11 23:07:55.501 INFO 1368 --- [ main] i.seata.config.nacos.NacosConfiguration : Nacos check auth with userName/password. WARNING: An illegal reflective access operation has occurred WARNING: Illegal reflective access by net.sf.cglib.core.ReflectUtils$2 (file:/D:/maven/repository/cglib/cglib/3.1/cglib-3.1.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain) WARNING: Please consider reporting this to the maintainers of net.sf.cglib.core.ReflectUtils$2 WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations WARNING: All illegal access operations will be denied in a future release 2022-08-11 23:07:55.984 INFO 1368 --- [ main] i.s.s.a.GlobalTransactionScanner : Initializing Global Transaction Clients ... 2022-08-11 23:07:56.083 INFO 1368 --- [ main] i.s.core.rpc.netty.NettyClientBootstrap : NettyClientBootstrap has started 2022-08-11 23:07:56.292 INFO 1368 --- [ main] i.s.c.r.netty.NettyClientChannelManager : will connect to 192.168.99.1:8091 2022-08-11 23:08:01.661 INFO 1368 --- [ main] i.s.core.rpc.netty.NettyPoolableFactory : NettyPool create channel to transactionRole:TMROLE,address:192.168.99.1:8091,msg:< RegisterTMRequest{applicationId='order-server', transactionServiceGroup='default_tx_group'} > 2022-08-11 23:08:15.581 INFO 1368 --- [ main] i.s.c.rpc.netty.TmNettyRemotingClient : register TM success. client version:1.5.2, server version:1.5.2,channel:[id: 0x114bdae0, L:/192.168.99.1:2248 - R:/192.168.99.1:8091] 2022-08-11 23:08:15.592 INFO 1368 --- [ main] i.s.core.rpc.netty.NettyPoolableFactory : register success, cost 92 ms, version:1.5.2,role:TMROLE,channel:[id: 0x114bdae0, L:/192.168.99.1:2248 - R:/192.168.99.1:8091] 2022-08-11 23:08:15.594 INFO 1368 --- [ main] i.s.s.a.GlobalTransactionScanner : Transaction Manager Client is initialized. applicationId[order-server] txServiceGroup[default_tx_group] 2022-08-11 23:08:15.624 INFO 1368 --- [ main] io.seata.rm.datasource.AsyncWorker : Async Commit Buffer Limit: 10000 2022-08-11 23:08:15.625 INFO 1368 --- [ main] i.s.rm.datasource.xa.ResourceManagerXA : ResourceManagerXA init ... 2022-08-11 23:08:15.636 INFO 1368 --- [ main] i.s.core.rpc.netty.NettyClientBootstrap : NettyClientBootstrap has started 2022-08-11 23:08:15.636 INFO 1368 --- [ main] i.s.s.a.GlobalTransactionScanner : Resource Manager is initialized. applicationId[order-server] txServiceGroup[default_tx_group] 2022-08-11 23:08:15.636 INFO 1368 --- [ main] i.s.s.a.GlobalTransactionScanner : Global Transaction Clients are initialized. 2022-08-11 23:08:15.761 INFO 1368 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'com.alibaba.cloud.seata.feign.SeataFeignClientAutoConfiguration$FeignBeanPostProcessorConfiguration' of type [com.alibaba.cloud.seata.feign.SeataFeignClientAutoConfiguration$FeignBeanPostProcessorConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-08-11 23:08:15.766 INFO 1368 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'seataFeignObjectWrapper' of type [com.alibaba.cloud.seata.feign.SeataFeignObjectWrapper] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying) 2022-08-11 23:08:16.173 INFO 1368 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8180 (http) 2022-08-11 23:08:16.187 INFO 1368 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2022-08-11 23:08:16.187 INFO 1368 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.43] 2022-08-11 23:08:16.532 INFO 1368 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext 2022-08-11 23:08:16.532 INFO 1368 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 22253 ms 2022-08-11 23:08:17.460 INFO 1368 --- [ main] o.s.s.c.ThreadPoolExecutorFactoryBean : Initializing ExecutorService 'threadExecutor' 2022-08-11 23:08:17.499 INFO 1368 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Starting... 2022-08-11 23:08:17.821 INFO 1368 --- [ main] com.zaxxer.hikari.HikariDataSource : HikariPool-1 - Start completed. 2022-08-11 23:08:17.843 INFO 1368 --- [ main] i.s.s.t.DefaultSagaTransactionalTemplate : Initializing Global Transaction Clients ... 2022-08-11 23:08:17.844 INFO 1368 --- [ main] i.s.s.t.DefaultSagaTransactionalTemplate : Transaction Manager Client is initialized. applicationId[order-server] txServiceGroup[default_tx_group] 2022-08-11 23:08:17.844 INFO 1368 --- [ main] i.s.s.t.DefaultSagaTransactionalTemplate : Resource Manager is initialized. applicationId[order-server] txServiceGroup[default_tx_group] 2022-08-11 23:08:17.845 INFO 1368 --- [ main] i.s.c.r.netty.NettyClientChannelManager : will connect to 192.168.99.1:8091 2022-08-11 23:08:17.845 INFO 1368 --- [ main] i.s.c.rpc.netty.RmNettyRemotingClient : RM will register :order-server#default_tx_group 2022-08-11 23:08:17.846 INFO 1368 --- [ main] i.s.core.rpc.netty.NettyPoolableFactory : NettyPool create channel to transactionRole:RMROLE,address:192.168.99.1:8091,msg:< RegisterRMRequest{resourceIds='order-server#default_tx_group', applicationId='order-server', transactionServiceGroup='default_tx_group'} > 2022-08-11 23:08:17.867 INFO 1368 --- [ main] i.s.c.rpc.netty.RmNettyRemotingClient : register RM success. client version:1.5.2, server version:1.5.2,channel:[id: 0x16359ce9, L:/192.168.99.1:2254 - R:/192.168.99.1:8091] 2022-08-11 23:08:17.867 INFO 1368 --- [ main] i.s.core.rpc.netty.NettyPoolableFactory : register success, cost 18 ms, version:1.5.2,role:RMROLE,channel:[id: 0x16359ce9, L:/192.168.99.1:2254 - R:/192.168.99.1:8091] 2022-08-11 23:08:17.868 INFO 1368 --- [ main] i.s.s.t.DefaultSagaTransactionalTemplate : Global Transaction Clients are initialized. 2022-08-11 23:08:18.074 WARN 1368 --- [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources. 2022-08-11 23:08:18.074 INFO 1368 --- [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath. 2022-08-11 23:08:18.078 WARN 1368 --- [ main] c.n.c.sources.URLConfigurationSource : No URLs will be polled as dynamic configuration sources. 2022-08-11 23:08:18.078 INFO 1368 --- [ main] c.n.c.sources.URLConfigurationSource : To enable URLs as dynamic configuration sources, define System property archaius.configurationSource.additionalUrls or make config.properties available on classpath. 2022-08-11 23:08:27.639 INFO 1368 --- [ main] o.s.s.c.ThreadPoolTaskScheduler : Initializing ExecutorService 'Nacos-Watch-Task-Scheduler' 2022-08-11 23:08:36.114 INFO 1368 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8180 (http) with context path '' 2022-08-11 23:08:36.121 INFO 1368 --- [ main] c.a.c.n.registry.NacosServiceRegistry : nacos registry, SEATA_GROUP order-server 192.168.99.1:8180 register finished 2022-08-11 23:08:42.592 INFO 1368 --- [ main] io.seata.sample.OrderServerApplication : Started OrderServerApplication in 64.952 seconds (JVM running for 134.65) 2022-08-11 23:16:12.769 INFO 1368 --- [nio-8180-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet' 2022-08-11 23:16:12.769 INFO 1368 --- [nio-8180-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet' 2022-08-11 23:16:12.778 INFO 1368 --- [nio-8180-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 9 ms 2022-08-11 23:16:12.882 INFO 1368 --- [nio-8180-exec-1] i.seata.sample.service.OrderServiceImpl : ------->交易开始 2022-08-11 23:16:12.892 INFO 1368 --- [nio-8180-exec-1] io.seata.tm.TransactionManagerHolder : TransactionManager Singleton io.seata.tm.DefaultTransactionManager@61281a0e 2022-08-11 23:16:12.907 INFO 1368 --- [nio-8180-exec-1] i.seata.tm.api.DefaultGlobalTransaction : Begin new global transaction [192.168.99.1:8091:4711059268309713064] 2022-08-11 23:16:12.962 INFO 1368 --- [nio-8180-exec-1] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Begin process the state instance in the saga branch. 2022-08-11 23:16:18.271 INFO 1368 --- [nio-8180-exec-1] io.seata.sample.service.OrderSaveImpl : 保存订单, businessKey：1660230972884, order: Order(id=null, userId=1, productId=1, count=1, payAmount=1, status=0) 2022-08-11 23:16:18.358 INFO 1368 --- [nio-8180-exec-1] .s.s.e.p.i.ServiceTaskHandlerInterceptor : State[SaveOrder] finish with status[SU] 2022-08-11 23:16:18.360 INFO 1368 --- [nio-8180-exec-1] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Finish process the state instance in the saga branch. 2022-08-11 23:16:18.360 INFO 1368 --- [nio-8180-exec-1] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Begin process the state instance in the saga branch. 2022-08-11 23:16:25.588 INFO 1368 --- [nio-8180-exec-1] c.netflix.config.ChainedDynamicProperty : Flipping property: account-server.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647 2022-08-11 23:16:25.605 INFO 1368 --- [nio-8180-exec-1] c.netflix.loadbalancer.BaseLoadBalancer : Client: account-server instantiated a LoadBalancer: DynamicServerListLoadBalancer:{NFLoadBalancer:name=account-server,current list of Servers=[],Load balancer stats=Zone stats: {},Server stats: []}ServerList:null 2022-08-11 23:16:25.614 INFO 1368 --- [nio-8180-exec-1] c.n.l.DynamicServerListLoadBalancer : Using serverListUpdater PollingServerListUpdater 2022-08-11 23:16:25.659 INFO 1368 --- [nio-8180-exec-1] c.netflix.config.ChainedDynamicProperty : Flipping property: account-server.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647 2022-08-11 23:16:25.661 INFO 1368 --- [nio-8180-exec-1] c.n.l.DynamicServerListLoadBalancer : DynamicServerListLoadBalancer for client account-server initialized: DynamicServerListLoadBalancer:{NFLoadBalancer:name=account-server,current list of Servers=[192.168.99.1:8181],Load balancer stats=Zone stats: {unknown=[Zone:unknown; Instance count:1; Active connections count: 0; Circuit breaker tripped count: 0; Active connections per server: 0.0;] },Server stats: [[Server:192.168.99.1:8181; Zone:UNKNOWN; Total Requests:0; Successive connection failure:0; Total blackout seconds:0; Last connection made:Thu Jan 01 08:00:00 CST 1970; First connection made: Thu Jan 01 08:00:00 CST 1970; Active Connections:0; total failure count in last (1000) msecs:0; average resp time:0.0; 90 percentile resp time:0.0; 95 percentile resp time:0.0; min resp time:0.0; max resp time:0.0; stddev resp time:0.0] ]}ServerList:com.alibaba.cloud.nacos.ribbon.NacosServerList@4040adb8 2022-08-11 23:16:26.601 INFO 1368 --- [nio-8180-exec-1] .s.s.e.p.i.ServiceTaskHandlerInterceptor : State[ReduceAccount] finish with status[SU] 2022-08-11 23:16:26.603 INFO 1368 --- [nio-8180-exec-1] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Finish process the state instance in the saga branch. 2022-08-11 23:16:26.603 INFO 1368 --- [nio-8180-exec-1] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Begin process the state instance in the saga branch. 2022-08-11 23:16:26.632 INFO 1368 --- [nio-8180-exec-1] c.netflix.config.ChainedDynamicProperty : Flipping property: storage-server.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647 2022-08-11 23:16:26.634 INFO 1368 --- [nio-8180-exec-1] c.netflix.loadbalancer.BaseLoadBalancer : Client: storage-server instantiated a LoadBalancer: DynamicServerListLoadBalancer:{NFLoadBalancer:name=storage-server,current list of Servers=[],Load balancer stats=Zone stats: {},Server stats: []}ServerList:null 2022-08-11 23:16:26.635 INFO 1368 --- [nio-8180-exec-1] c.n.l.DynamicServerListLoadBalancer : Using serverListUpdater PollingServerListUpdater 2022-08-11 23:16:26.636 INFO 1368 --- [erListUpdater-1] c.netflix.config.ChainedDynamicProperty : Flipping property: account-server.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647 2022-08-11 23:16:26.642 INFO 1368 --- [nio-8180-exec-1] c.netflix.config.ChainedDynamicProperty : Flipping property: storage-server.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647 2022-08-11 23:16:26.643 INFO 1368 --- [nio-8180-exec-1] c.n.l.DynamicServerListLoadBalancer : DynamicServerListLoadBalancer for client storage-server initialized: DynamicServerListLoadBalancer:{NFLoadBalancer:name=storage-server,current list of Servers=[192.168.99.1:8182],Load balancer stats=Zone stats: {unknown=[Zone:unknown; Instance count:1; Active connections count: 0; Circuit breaker tripped count: 0; Active connections per server: 0.0;] },Server stats: [[Server:192.168.99.1:8182; Zone:UNKNOWN; Total Requests:0; Successive connection failure:0; Total blackout seconds:0; Last connection made:Thu Jan 01 08:00:00 CST 1970; First connection made: Thu Jan 01 08:00:00 CST 1970; Active Connections:0; total failure count in last (1000) msecs:0; average resp time:0.0; 90 percentile resp time:0.0; 95 percentile resp time:0.0; min resp time:0.0; max resp time:0.0; stddev resp time:0.0] ]}ServerList:com.alibaba.cloud.nacos.ribbon.NacosServerList@16fd5ab0 2022-08-11 23:16:27.648 INFO 1368 --- [erListUpdater-0] c.netflix.config.ChainedDynamicProperty : Flipping property: storage-server.ribbon.ActiveConnectionsLimit to use NEXT property: niws.loadbalancer.availabilityFilteringRule.activeConnectionsLimit = 2147483647 2022-08-11 23:16:31.283 INFO 1368 --- [nio-8180-exec-1] .s.s.e.p.i.ServiceTaskHandlerInterceptor : State[ReduceStorage] finish with status[SU] 2022-08-11 23:16:31.285 INFO 1368 --- [nio-8180-exec-1] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Finish process the state instance in the saga branch. 2022-08-11 23:16:31.299 INFO 1368 --- [nio-8180-exec-1] i.seata.tm.api.DefaultGlobalTransaction : [192.168.99.1:8091:4711059268309713064] report status: Begin 2022-08-11 23:16:31.299 INFO 1368 --- [nio-8180-exec-1] i.s.s.p.handler.DefaultRouterHandler : route instruction is null, process end saga transaction commit succeed. XID: 192.168.99.1:8091:4711059268309713064

半小时后********************* 2022-08-11 23:46:14.430 INFO 1368 --- [h_RMROLE_1_1_16] i.s.c.r.p.c.RmBranchRollbackProcessor : rm handle branch rollback process:xid=192.168.99.1:8091:4711059268309713064,branchId=-1,branchType=SAGA,resourceId=order-server#default_tx_group,applicationData=TimeoutRollbacking 2022-08-11 23:46:14.432 INFO 1368 --- [h_RMROLE_1_1_16] io.seata.rm.AbstractRMHandler : Branch Rollbacking: 192.168.99.1:8091:4711059268309713064 -1 order-server#default_tx_group 2022-08-11 23:46:14.439 INFO 1368 --- [h_RMROLE_1_1_16] i.s.s.e.i.ProcessCtrlStateMachineEngine : Operation [compensate] start. stateMachineInstance[id:192.168.99.1:8091:4711059268309713064] 2022-08-11 23:46:14.441 INFO 1368 --- [h_RMROLE_1_1_16] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Begin process the state instance in the saga branch. 2022-08-11 23:46:24.602 INFO 1368 --- [h_RMROLE_1_1_16] .s.s.e.p.i.ServiceTaskHandlerInterceptor : State[CompensateReduceStorage] finish with status[SU] 2022-08-11 23:46:24.607 INFO 1368 --- [h_RMROLE_1_1_16] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Finish process the state instance in the saga branch. 2022-08-11 23:46:24.608 INFO 1368 --- [h_RMROLE_1_1_16] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Begin process the state instance in the saga branch. 2022-08-11 23:46:26.528 INFO 1368 --- [h_RMROLE_1_1_16] .s.s.e.p.i.ServiceTaskHandlerInterceptor : State[CompensateReduceAccount] finish with status[SU] 2022-08-11 23:46:26.529 INFO 1368 --- [h_RMROLE_1_1_16] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Finish process the state instance in the saga branch. 2022-08-11 23:46:26.529 INFO 1368 --- [h_RMROLE_1_1_16] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Begin process the state instance in the saga branch. 2022-08-11 23:46:26.531 INFO 1368 --- [h_RMROLE_1_1_16] io.seata.sample.service.OrderSaveImpl : 删除订单, businessKey：1660230972884, order: Order(id=17, userId=1, productId=1, count=1, payAmount=1, status=0) 2022-08-11 23:46:32.028 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : channel [id: 0x114bdae0, L:/192.168.99.1:2248 - R:/192.168.99.1:8091] read idle. 2022-08-11 23:46:32.030 INFO 1368 --- [ctor_TMROLE_1_1] i.s.core.rpc.netty.NettyPoolableFactory : will destroy channel:[id: 0x114bdae0, L:/192.168.99.1:2248 - R:/192.168.99.1:8091] 2022-08-11 23:46:32.031 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 - R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.034 INFO 1368 --- [h_RMROLE_1_1_16] .s.s.e.p.i.ServiceTaskHandlerInterceptor : State[DeleteOrder] finish with status[SU] 2022-08-11 23:46:32.036 INFO 1368 --- [h_RMROLE_1_1_16] s.s.e.p.i.InSagaBranchHandlerInterceptor : [192.168.99.1:8091:4711059268309713064] Finish process the state instance in the saga branch. 2022-08-11 23:46:32.087 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.088 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.netty.NettyClientChannelManager : return to pool, rm channel:[id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.088 INFO 1368 --- [ctor_TMROLE_1_1] i.s.core.rpc.netty.NettyPoolableFactory : channel valid false,channel:[id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.088 INFO 1368 --- [ctor_TMROLE_1_1] i.s.core.rpc.netty.NettyPoolableFactory : will destroy channel:[id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.088 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.088 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.core.rpc.netty.NettyPoolableFactory : channel valid false,channel:[id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.core.rpc.netty.NettyPoolableFactory : will destroy channel:[id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.089 ERROR 1368 --- [h_RMROLE_1_1_16] i.s.c.rpc.netty.AbstractNettyRemoting : wait response error:io.netty.channel.StacklessClosedChannelException,ip:/192.168.99.1:8091,request:xid=192.168.99.1:8091:4711059268309713064,extraData=null 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : channel inactive: [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.core.rpc.netty.NettyPoolableFactory : channel valid false,channel:[id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.core.rpc.netty.NettyPoolableFactory : will destroy channel:[id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091] 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.089 INFO 1368 --- [ctor_TMROLE_1_1] i.s.c.r.n.AbstractNettyRemotingClient : ChannelHandlerContext(AbstractNettyRemotingClient$ClientHandler#0, [id: 0x114bdae0, L:/192.168.99.1:2248 ! R:/192.168.99.1:8091]) will closed 2022-08-11 23:46:32.109 ERROR 1368 --- [h_RMROLE_1_1_16] io.seata.saga.rm.SagaResourceManager : StateMachine compensate failed, xid: 192.168.99.1:8091:4711059268309713064

io.seata.common.exception.FrameworkException: java.lang.RuntimeException: io.netty.channel.StacklessClosedChannelException at io.seata.saga.proctrl.handler.DefaultRouterHandler.route(DefaultRouterHandler.java:80) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.process.impl.CustomizeBusinessProcessor.route(CustomizeBusinessProcessor.java:89) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.impl.ProcessControllerImpl.process(ProcessControllerImpl.java:45) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.eventing.impl.ProcessCtrlEventConsumer.process(ProcessCtrlEventConsumer.java:35) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.eventing.impl.ProcessCtrlEventConsumer.process(ProcessCtrlEventConsumer.java:28) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.eventing.impl.DirectEventBus.offer(DirectEventBus.java:69) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.eventing.impl.DirectEventBus.offer(DirectEventBus.java:33) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.eventing.impl.ProcessCtrlEventPublisher.publish(ProcessCtrlEventPublisher.java:34) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.impl.ProcessCtrlStateMachineEngine.compensateInternal(ProcessCtrlStateMachineEngine.java:539) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.impl.ProcessCtrlStateMachineEngine.compensate(ProcessCtrlStateMachineEngine.java:460) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.rm.SagaResourceManager.branchRollback(SagaResourceManager.java:142) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.rm.AbstractRMHandler.doBranchRollback(AbstractRMHandler.java:125) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.rm.AbstractRMHandler$2.execute(AbstractRMHandler.java:67) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.rm.AbstractRMHandler$2.execute(AbstractRMHandler.java:63) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.core.exception.AbstractExceptionHandler.exceptionHandleTemplate(AbstractExceptionHandler.java:131) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.rm.AbstractRMHandler.handle(AbstractRMHandler.java:63) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.rm.DefaultRMHandler.handle(DefaultRMHandler.java:68) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.core.protocol.transaction.BranchRollbackRequest.handle(BranchRollbackRequest.java:35) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.rm.AbstractRMHandler.onRequest(AbstractRMHandler.java:150) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.core.rpc.processor.client.RmBranchRollbackProcessor.handleBranchRollback(RmBranchRollbackProcessor.java:63) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.core.rpc.processor.client.RmBranchRollbackProcessor.process(RmBranchRollbackProcessor.java:58) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.core.rpc.netty.AbstractNettyRemoting.lambda$processMessage$2(AbstractNettyRemoting.java:281) ~[seata-all-1.5.2.jar:1.5.2] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na] at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-all-4.1.59.Final.jar:4.1.59.Final] at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na] Caused by: java.lang.RuntimeException: java.lang.RuntimeException: io.netty.channel.StacklessClosedChannelException at io.seata.core.rpc.netty.AbstractNettyRemoting.sendSync(AbstractNettyRemoting.java:208) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.core.rpc.netty.AbstractNettyRemotingClient.sendSyncRequest(AbstractNettyRemotingClient.java:187) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.tm.DefaultTransactionManager.syncCall(DefaultTransactionManager.java:95) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.tm.DefaultTransactionManager.globalReport(DefaultTransactionManager.java:89) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.tm.api.DefaultGlobalTransaction.globalReport(DefaultGlobalTransaction.java:233) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.tm.DefaultSagaTransactionalTemplate.reportTransaction(DefaultSagaTransactionalTemplate.java:105) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.store.db.DbAndReportTcStateLogStore.reportTransactionFinished(DbAndReportTcStateLogStore.java:226) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.store.db.DbAndReportTcStateLogStore.recordStateMachineFinished(DbAndReportTcStateLogStore.java:188) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.pcext.utils.EngineUtils.endStateMachine(EngineUtils.java:119) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.pcext.routers.TaskStateRouter.compensateRoute(TaskStateRouter.java:186) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.pcext.routers.TaskStateRouter.route(TaskStateRouter.java:75) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.engine.pcext.StateMachineProcessRouter.route(StateMachineProcessRouter.java:85) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.saga.proctrl.handler.DefaultRouterHandler.route(DefaultRouterHandler.java:69) ~[seata-all-1.5.2.jar:1.5.2] ... 25 common frames omitted Caused by: java.lang.RuntimeException: io.netty.channel.StacklessClosedChannelException at io.seata.core.protocol.MessageFuture.get(MessageFuture.java:71) ~[seata-all-1.5.2.jar:1.5.2] at io.seata.core.rpc.netty.AbstractNettyRemoting.sendSync(AbstractNettyRemoting.java:199) ~[seata-all-1.5.2.jar:1.5.2] ... 37 common frames omitted Caused by: io.netty.channel.StacklessClosedChannelException: null at io.netty.channel.AbstractChannel$AbstractUnsafe.write(Object, ChannelPromise)(Unknown Source) ~[netty-all-4.1.59.Final.jar:4.1.59.Final]

2022-08-11 23:46:32.125 INFO 1368 --- [h_RMROLE_1_1_16] io.seata.rm.AbstractRMHandler : Branch Rollbacked result: PhaseTwo_RollbackFailed_Retryable 2022-08-11 23:46:32.144 INFO 1368 --- [h_RMROLE_1_2_16] i.s.c.r.p.c.RmBranchRollbackProcessor : rm handle branch rollback process:xid=192.168.99.1:8091:4711059268309713064,branchId=-1,branchType=SAGA,resourceId=order-server#default_tx_group,applicationData=TimeoutRollbacking 2022-08-11 23:46:32.144 INFO 1368 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch Rollbacking: 192.168.99.1:8091:4711059268309713064 -1 order-server#default_tx_group 2022-08-11 23:46:32.149 INFO 1368 --- [h_RMROLE_1_2_16] io.seata.rm.AbstractRMHandler : Branch Rollbacked result: PhaseTwo_Rollbacked 2022-08-11 23:46:36.080 INFO 1368 --- [eoutChecker_1_1] i.s.c.r.netty.NettyClientChannelManager : will connect to 192.168.99.1:8091 2022-08-11 23:46:36.081 INFO 1368 --- [eoutChecker_1_1] i.s.core.rpc.netty.NettyPoolableFactory : NettyPool create channel to transactionRole:TMROLE,address:192.168.99.1:8091,msg:< RegisterTMRequest{applicationId='order-server', transactionServiceGroup='default_tx_group'} > 2022-08-11 23:46:36.086 INFO 1368 --- [eoutChecker_1_1] i.s.c.rpc.netty.TmNettyRemotingClient : register TM success. client version:1.5.2, server version:1.5.2,channel:[id: 0xca925a76, L:/192.168.99.1:3833 - R:/192.168.99.1:8091] 2022-08-11 23:46:36.087 INFO 1368 --- [eoutChecker_1_1] i.s.core.rpc.netty.NettyPoolableFactory : register success, cost 3 ms, version:1.5.2,role:TMROLE,channel:[id: 0xca925a76, L:/192.168.99.1:3833 - R:/192.168.99.1:8091]

JPPeng avatar Aug 16 '22 09:08 JPPeng