apache / apache/incubator-seata-samples

服务调用偶尔成功,经常失败

Open
#51 1 comment 0 reactions 0 assignees View on GitHub
Dominant language
Java
Stars
2.4k
Forks
2k
PR merge metrics
No merged PRs in 30d

Description

链接fescar-sever是正常的,但出现服务调用偶尔成功,经常失败,请问这是啥情况,具体日志如下
开始全局事务,XID = 10.11.0.145:8091:2005581791
2019-03-06 14:55:40.236 ERROR 28748 --- [nio-8104-exec-4] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.reflect.UndeclaredThrowableException] with root cause

com.alibaba.dubbo.remoting.TimeoutException: Waiting server-side response timeout. start time: 2019-03-06 14:55:37.230, end time: 2019-03-06 14:55:40.232, client elapsed: 0 ms, server elapsed: 3002 ms, timeout: 3000 ms, request: Request [id=25, version=2.0.2, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=decreaseStorage, parameterTypes=[class com.alibaba.fescar.samples.integration.common.dto.CommodityDTO], arguments=[CommodityDTO(id=null, commodityCode=C201901140001, name=null, count=10)], attachments={path=com.alibaba.fescar.samples.integration.common.dubbo.StorageDubboService, TX_XID=10.11.0.145:8091:2005581791, interface=com.alibaba.fescar.samples.integration.common.dubbo.StorageDubboService, version=1.0.0, timeout=3000}]], channel: /10.96.2.106:61375 -> /10.96.2.106:20882
at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:159) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:135) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.protocol.dubbo.DubboInvoker.doInvoke(DubboInvoker.java:95) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.protocol.AbstractInvoker.invoke(AbstractInvoker.java:155) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.fescar.dubbo.alibaba.TransactionPropagationFilter.invoke(TransactionPropagationFilter.java:60) ~[fescar-dubbo-alibaba-0.2.3.jar:na]
at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:72) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:72) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:54) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:72) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:49) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:72) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:77) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:56) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:78) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.cluster.support.AbstractClusterInvoker.invoke(AbstractClusterInvoker.java:244) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.cluster.support.wrapper.MockClusterInvoker.invoke(MockClusterInvoker.java:75) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:52) ~[dubbo-2.6.5.jar:2.6.5]
at com.alibaba.dubbo.common.bytecode.proxy0.decreaseStorage(proxy0.java) ~[dubbo-2.6.5.jar:2.6.5]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_161]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_161]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_161]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_161]
at com.alibaba.dubbo.config.spring.beans.factory.annotation.ReferenceAnnotationBeanPostProcessor$ReferenceBeanInvocationHandler.invoke(ReferenceAnnotationBeanPostProcessor.java:159) ~[dubbo-2.6.5.jar:2.6.5]
at com.sun.proxy.$Proxy78.decreaseStorage(Unknown Source) ~[na:na]
at com.alibaba.fescar.samples.integration.call.service.BusinessServiceImpl.handleBusiness(BusinessServiceImpl.java:46) ~[classes/:na]
at com.alibaba.fescar.samples.integration.call.service.BusinessServiceImpl$$FastClassBySpringCGLIB$$3af274ba.invoke() ~[classes/:na]
at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) ~[spring-core-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:746) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at com.alibaba.fescar.spring.annotation.GlobalTransactionalInterceptor$1.execute(GlobalTransactionalInterceptor.java:64) ~[fescar-spring-0.2.3.jar:na]
at com.alibaba.fescar.tm.api.TransactionalTemplate.execute(TransactionalTemplate.java:52) ~[fescar-tm-0.2.3.jar:na]
at com.alibaba.fescar.spring.annotation.GlobalTransactionalInterceptor.invoke(GlobalTransactionalInterceptor.java:61) ~[fescar-spring-0.2.3.jar:na]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:185) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:688) ~[spring-aop-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at com.alibaba.fescar.samples.integration.call.service.BusinessServiceImpl$$EnhancerBySpringCGLIB$$2d6ebd58.handleBusiness() ~[classes/:na]
at com.alibaba.fescar.samples.integration.call.controller.BusinessController.handleBusiness(BusinessController.java:34) ~[classes/:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_161]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_161]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_161]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_161]
at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:209) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:136) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:102) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:891) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:991) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:925) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:981) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:884) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:858) ~[spring-webmvc-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) ~[tomcat-embed-websocket-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:200) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[spring-web-5.0.12.RELEASE.jar:5.0.12.RELEASE]
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) ~[tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:806) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498) [tomcat-embed-core-8.5.37.jar:8.5.37]
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-8.5.37.jar:8.5.37]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_161]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_161]
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-8.5.37.jar:8.5.37]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_161]

2019-03-06 14:55:50.235 INFO 28748 --- [lector_TMROLE_1] c.a.fescar.core.rpc.netty.TmRpcClient : will send ping msg,channel[id: 0x1e0e3247, L:/10.96.2.106:63819 - R:/10.11.0.145:8091]

Contributor guide

Open the contributing guide

Research direction

Start at BusinessServiceImpl.java:46 and BusinessController.java:34, then inspect the Dubbo call and its 3,000 ms timeout shown in the log. Reproduce the intermittent decreaseStorage failure and trace the client/server timing; done means the cause is identified and service calls complete reliably or fail with an explained configuration or code change.

Written by the indexing model from the issue text.

Assessment

Tech stack
java, spring
Domain
backend, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.