dubbo 调用方法超时

Question

我ctrl调用一个方法再生产上一直超时，测试环境又是好的。我把生产的代码拉到本地也是好的。就奇怪了。下面是日志：
`[labrador-rest] 2020-09-04 11:43:07.478 [http-bio-8998-exec-1] ERROR com.cargopm.util.login.JWTFilter - login filter error! requestUrl:http://faq.mayibida.com/labra...
org.springframework.web.util.NestedServletException: Request processing failed; nested exception is com.alibaba.dubbo.rpc.RpcException: Failed to invoke the method selectKnowLedgeById in the service com.cargopm.basicdata.remote.KnowledgeRemote. Tried 1 times of the providers [172.19.37.122:30013] (1/1) from the registry 172.19.37.123:2181 on the consumer 172.19.37.123 using the dubbo version 2.8.4. Last error is: Invoke remote method timeout. method: selectKnowLedgeById, provider: dubbo://172.19.37.122:30013/com.cargopm.basicdata.remote.KnowledgeRemote?anyhost=true&application=labrador-rest&check=false&default.accesslog=true&default.check=false&default.retries=0&default.timeout=20000&default.token=true&dubbo=2.8.4&generic=false&interface=com.cargopm.basicdata.remote.KnowledgeRemote&methods=selectKnowLedgeById,selectSourceList,selectEmpList,selectKnowLedgePage,selectHotState,deleteKnowLedge,sortHotState,selectAllCount,selectKnowLedgeByCode,updateKnowledgePublishState,addKnowLedges,batchRelease,addOrUpdateKnowledge,selectLastDate&pid=8133&reggroup=dubbo&revision=1.4.9-20200724.101402-3&side=consumer&timestamp=1598435867349, cause: Waiting server-side response timeout by scan timer. start time: 2020-09-04 11:42:47.451, end time: 2020-09-04 11:43:07.477, client elapsed: 0 ms, server elapsed: 20025 ms, timeout: 20000 ms, request: Request [id=22164, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=selectKnowLedgeById, parameterTypes=[class java.lang.Long],arguments=[3152], attachments={path=com.cargopm.basicdata.remote.KnowledgeRemote, X-B3-SpanId=e2c6b049fec72b1c, X-B3-ParentSpanId=170fa9d9a0035de2, X-B3-Sampled=1, X-B3-TraceId=170fa9d9a0035de2, interface=com.cargopm.basicdata.remote.KnowledgeRemote, version=0.0.0, timeout=20000, token=true}]], channel: /172.19.37.123:52974 -> /172.19.37.122:30013

    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:965)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:844)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:624)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:829)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at com.cargopm.util.zipkin.filter.HttpServletRequestReplacedFilter.doFilter(HttpServletRequestReplacedFilter.java:34)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at brave.servlet.TracingFilter.doFilter(TracingFilter.java:86)
    at brave.spring.webmvc.DelegatingTracingFilter.doFilter(DelegatingTracingFilter.java:34)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at com.cargopm.util.login.JWTFilter.doFilter(JWTFilter.java:34)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:343)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:260)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1137)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)

Caused by: com.alibaba.dubbo.rpc.RpcException: Failed to invoke the method selectKnowLedgeById in the service com.cargopm.basicdata.remote.KnowledgeRemote. Tried 1 times of the providers [172.19.37.122:30013] (1/1) from the registry 172.19.37.123:2181 on the consumer 172.19.37.123 using the dubbo version 2.8.4. Last error is: Invoke remote method timeout. method: selectKnowLedgeById, provider: dubbo://172.19.37.122:30013/com.cargopm.basicdata.remote.KnowledgeRemote?anyhost=true&application=labrador-rest&check=false&default.accesslog=true&default.check=false&default.retries=0&default.timeout=20000&default.token=true&dubbo=2.8.4&generic=false&interface=com.cargopm.basicdata.remote.KnowledgeRemote&methods=selectKnowLedgeById,selectSourceList,selectEmpList,selectKnowLedgePage,selectHotState,deleteKnowLedge,sortHotState,selectAllCount,selectKnowLedgeByCode,updateKnowledgePublishState,addKnowLedges,batchRelease,addOrUpdateKnowledge,selectLastDate&pid=8133&reggroup=dubbo&revision=1.4.9-20200724.101402-3&side=consumer&timestamp=1598435867349, cause: Waiting server-side response timeout by scan timer. start time: 2020-09-04 11:42:47.451, end time: 2020-09-04 11:43:07.477, client elapsed: 0 ms, server elapsed: 20025 ms, timeout: 20000 ms, request: Request [id=22164, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=selectKnowLedgeById, parameterTypes=[class java.lang.Long], arguments=[3152], attachments={path=com.cargopm.basicdata.remote.KnowledgeRemote, X-B3-SpanId=e2c6b049fec72b1c, X-B3-ParentSpanId=170fa9d9a0035de2, X-B3-Sampled=1, X-B3-TraceId=170fa9d9a0035de2, interface=com.cargopm.basicdata.remote.KnowledgeRemote, version=0.0.0, timeout=20000, token=true}]], channel:/172.19.37.123:52974 -> /172.19.37.122:30013

    at com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:101)
    at com.alibaba.dubbo.rpc.cluster.support.AbstractClusterInvoker.invoke(AbstractClusterInvoker.java:227)
    at com.alibaba.dubbo.rpc.cluster.support.wrapper.MockClusterInvoker.invoke(MockClusterInvoker.java:72)
    at com.alibaba.dubbo.rpc.proxy.InvokerInvocationHandler.invoke(InvokerInvocationHandler.java:52)
    at com.alibaba.dubbo.common.bytecode.proxy37.selectKnowLedgeById(proxy37.java)
    at com.cargopm.labrador.basicdata.ctrl.KnowLedgePublicCtrl.selectKnowLedgeById(KnowLedgePublicCtrl.java:60)
    at sun.reflect.GeneratedMethodAccessor356.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:483)
    at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:215)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:132)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:104)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:745)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:686)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:953)
    ... 40 common frames omitted

Caused by: com.alibaba.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2020-09-04 11:42:47.451, end time: 2020-09-04 11:43:07.477, client elapsed: 0 ms, server elapsed: 20025 ms, timeout: 20000 ms, request: Request [id=22164, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=selectKnowLedgeById, parameterTypes=[class java.lang.Long], arguments=[3152], attachments={path=com.cargopm.basicdata.remote.KnowledgeRemote, X-B3-SpanId=e2c6b049fec72b1c, X-B3-ParentSpanId=170fa9d9a0035de2, X-B3-Sampled=1, X-B3-TraceId=170fa9d9a0035de2, interface=com.cargopm.basicdata.remote.KnowledgeRemote, version=0.0.0, timeout=20000, token=true}]], channel: /172.19.37.123:52974 -> /172.19.37.122:30013

    at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.returnFromResponse(DefaultFuture.java:188)
    at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:110)
    at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:84)
    at com.alibaba.dubbo.rpc.protocol.dubbo.DubboInvoker.doInvoke(DubboInvoker.java:96)
    at com.alibaba.dubbo.rpc.protocol.AbstractInvoker.invoke(AbstractInvoker.java:144)
    at brave.dubbo.rpc.TracingFilter.invoke(TracingFilter.java:123)
    at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)
    at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75)
    at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)
    at com.alibaba.dubbo.rpc.protocol.dubbo.filter.FutureFilter.invoke(FutureFilter.java:53)
    at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)
    at com.alibaba.dubbo.rpc.filter.ConsumerContextFilter.invoke(ConsumerContextFilter.java:48)
    at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91)
    at com.alibaba.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:74)
    at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53)
    at com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:77)
    ... 57 common frames omitted`

Answer 1

如果有链路监控的，检查具体耗时是网络导致的，还是服务端处理导致。如果是服务端，检查是否数据库等业务处理导致的，缩小范围。

如果怀疑是dubbo处理的，可以检查服务参数，比如是否设置等待队列，导致请求被延迟超时处理了，没有机会及时尝试别的服务节点。