Dubbo调用超时，服务端历史统计的处理耗时很短且找不到对应超时上下文的超时日志

A调用服务B，超时时间1秒，从某些请求来看超时了两次，重试了两次，第三次成功了，耗时仅4ms。

客户端有类似日志：

2018-05-11 00:00:14.741 [T_Common_DispatchExecutor_43] WARN com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker - [DUBBO] Although retry the method push in the service com.oppo.push.open.basic.api.service.BroadcastService was successful by the provider 10.12. 26.124:9000, but there have been failed providers [10.12.26.137:9000] (1/6) from the registry 10.12.26.154:2181 on the consumer 10.12.26.102 using the dubbo version 2.5.3. Last error is: Invoke remote method timeout. method: push, provider: dubbo://10.12.26.137:9000/com .oppo.push.open.basic.api.service.BroadcastService?accesslog=false&anyhost=true&application=push-open-platform-gateway-server&check=false&default.delay=-1&default.service.filter=-exception&default.timeout=1000&delay=-1&dubbo=2.5.3&interface=com.oppo.push.open.basic.api. service.BroadcastService&loadbalance=random&logger=slf4j&methods=revokePushMessage,revokeSmsMessage,push&pid=31597&push.retries=2&revision=3.0.2-SNAPSHOT&side=consumer&timestamp=1525937532890&transporter=netty, cause: Waiting server-side response timeout by scan timer. start time: 2018-05-11 00:00:13.710, end time: 2018-05-11 00:00:14.738, client elapsed: 0 ms, server elapsed: 1028 ms, timeout: 1000 ms, request: Request [id=2395465, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=push, parameterTy pes=[class com.oppo.push.open.basic.api.domain.PushTask], arguments=[PushTask[taskId=5af46c8da609e97b6dc17380, messageId=5af4655dad99497f2345ccda, messageCategory=3, messageType=1, taskStatus=5, target=PushTarget{id='5af46c8da609e97b6dc17381', type=REGISTRATION_ID, valu e='6187cd138ad2dbceee7f044c2409d4f1;ab5721987d21dcf5e863b58e165f144a;827f4ff3b5d31cce9e441b045eb985c9;e17854797bb4f0e7b14178cbde596c88;CN_647982d13860dde6876cdf0e37165c76;93624a57d555510bcf27cda47d5a06f9;eb3ebc3a53b12ef304de95b3e1852c60;5b752dc47cbca9721239885a062814c2; c69bd502aee453f0b78517bc9cb4548d;cc35de8b5edbff28dbaf55e4f60ad20a;CN_1239d29db4f5db54cc1bef51df3f3acc;CN_f6fd0448d1c6281da6ffa50df4d26f38;CN_2c2dc12e3c567ad81a00ca9cdca564e3;CN_d92b53c07de3e70883552295ece900f1;CN_b1cedf2537fd52e91fa29b5fb3c4eb47;525fb9de1d18e21c15479a0a 7f59b163;CN_debc0d6366f27dea1a45862020687f1a;d5bbb9bae7102ad0d69b3aeb138c4ff4;aac05d1a20d073343917c68798f9be2f;817898207275b2dbeefb6e9398f06b50;203e1b8c0de742605ecb166b6a92d9ce;8c6a4f0925ba3a1d92e3640d00507ade;fc3e47ab8ca527d964fae84ab5db00d7;d9c2ecf8051093bf7eb7818bbe5 5ec8f;c7894071806e5a6540a5380b1763e91b;b56b7a3e247258034876b9a8522b0dab;8b17b0c449bffa08407a4401f33b988f;789ca011db0844d01932fb8da2553a03;735e6aae28a3f2d5752e65f277bea9c3;e2cfca07e576a0285ab8f50dbaa3a947;8428d377795b069d9dfe033e880ed627;0939eab473c0311b5dd5567f5d191487; ec2ff892fbc28fdf0008d532a2c48560;e3df5c83de7f985e73d4e58d4d15225d;CN_c5af7007e71c23771b29eb0713cde7e2;ef91ece8b7e44a13fb31015f8f20b25b;CN_57b78f69e35ce1f8c1fcb27e36758fca;CN_d58cb83cdd32f108f84ff6eae662712f;CN_5564f22ea67f3391fc0f37b23d68ade0;e2b842e3aea81c7e7784fae318e bfb8a;2315554dca29eac7100d823f262c2b6f;18c0676bc2300630bad171d72353de0b;116c0728d4d8bed6aa80ba78a77620c1;11c37c408a7c88cf80e7bca695228c05;643413c1adad5e72df94594017797078;CN_c8dedeeeacdc24e9194386929e5367a7;CN_77a3fc33b094c592bad79d1aa95761af;4b9ceaaac2fbca88c01c3976c4a c7849;0a1c506ef41acca7bf4c01a758ece6cb;66c0c30821c399e06bb63cfd630b2016;2a5efb3ee633035f5d3700dc744b97d2;07348c108d514773761a828499877ce4;4532d9d99307e6b3634fdfc06aecbb09;6aae440b59761d2ed4e425206f276dc7', effectiveValue='null', unsubscribeValue='null', deviceId='null'} , appId=nJNKY574F2C4TWrAqYobsa3X, creator=null, messageTitle=null, createTime=Fri May 11 00:00:13 CST 2018, updateTime=Fri May 11 00:00:13 CST 2018], finishTime=null], extFields={}]], attachments={path=com.oppo.push.open.basic.api.service.BroadcastService, interface=com .oppo.push.open.basic.api.service.BroadcastService, timeout=1000, version=0.0.0}]], channel: /10.12.26.102:49081 -> /10.12.26.137:9000, dubbo version: 2.5.3, current host: 10.12.26.102 com.alibaba.dubbo.rpc.RpcException: Invoke remote method timeout. method: push, provider: dubbo://10.12.26.137:9000/com.oppo.push.open.basic.api.service.BroadcastService?accesslog=false&anyhost=true&application=push-open-platform-gateway-server&check=false&default.delay =-1&default.service.filter=-exception&default.timeout=1000&delay=-1&dubbo=2.5.3&interface=com.oppo.push.open.basic.api.service.BroadcastService&loadbalance=random&logger=slf4j&methods=revokePushMessage,revokeSmsMessage,push&pid=31597&push.retries=2&revision=3.0.2-SNAPSH OT&side=consumer&timestamp=1525937532890&transporter=netty, cause: Waiting server-side response timeout by scan timer. start time: 2018-05-11 00:00:13.710, end time: 2018-05-11 00:00:14.738, client elapsed: 0 ms, server elapsed: 1028 ms, timeout: 1000 ms, request: Reque st [id=2395465, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=push, parameterTypes=[class com.oppo.push.open.basic.api.domain.PushTask], arguments=[PushTask[taskId=5af46c8da609e97b6dc17380, messageId=5af4655dad99497f2345ccda, mess ageCategory=3, messageType=1, taskStatus=5, target=PushTarget{id='5af46c8da609e97b6dc17381', type=REGISTRATION_ID, value='6187cd138ad2dbceee7f044c2409d4f1;ab5721987d21dcf5e863b58e165f144a;827f4ff3b5d31cce9e441b045eb985c9;e17854797bb4f0e7b14178cbde596c88;CN_647982d13860d de6876cdf0e37165c76;93624a57d555510bcf27cda47d5a06f9;eb3ebc3a53b12ef304de95b3e1852c60;5b752dc47cbca9721239885a062814c2;c69bd502aee453f0b78517bc9cb4548d;cc35de8b5edbff28dbaf55e4f60ad20a;CN_1239d29db4f5db54cc1bef51df3f3acc;CN_f6fd0448d1c6281da6ffa50df4d26f38;CN_2c2dc12e3c 567ad81a00ca9cdca564e3;CN_d92b53c07de3e70883552295ece900f1;CN_b1cedf2537fd52e91fa29b5fb3c4eb47;525fb9de1d18e21c15479a0a7f59b163;CN_debc0d6366f27dea1a45862020687f1a;d5bbb9bae7102ad0d69b3aeb138c4ff4;aac05d1a20d073343917c68798f9be2f;817898207275b2dbeefb6e9398f06b50;203e1b8 c0de742605ecb166b6a92d9ce;8c6a4f0925ba3a1d92e3640d00507ade;fc3e47ab8ca527d964fae84ab5db00d7;d9c2ecf8051093bf7eb7818bbe55ec8f;c7894071806e5a6540a5380b1763e91b;b56b7a3e247258034876b9a8522b0dab;8b17b0c449bffa08407a4401f33b988f;789ca011db0844d01932fb8da2553a03;735e6aae28a3f 2d5752e65f277bea9c3;e2cfca07e576a0285ab8f50dbaa3a947;8428d377795b069d9dfe033e880ed627;0939eab473c0311b5dd5567f5d191487;ec2ff892fbc28fdf0008d532a2c48560;e3df5c83de7f985e73d4e58d4d15225d;CN_c5af7007e71c23771b29eb0713cde7e2;ef91ece8b7e44a13fb31015f8f20b25b;CN_57b78f69e35ce 1f8c1fcb27e36758fca;CN_d58cb83cdd32f108f84ff6eae662712f;CN_5564f22ea67f3391fc0f37b23d68ade0;e2b842e3aea81c7e7784fae318ebfb8a;2315554dca29eac7100d823f262c2b6f;18c0676bc2300630bad171d72353de0b;116c0728d4d8bed6aa80ba78a77620c1;11c37c408a7c88cf80e7bca695228c05;643413c1adad5 e72df94594017797078;CN_c8dedeeeacdc24e9194386929e5367a7;CN_77a3fc33b094c592bad79d1aa95761af;4b9ceaaac2fbca88c01c3976c4ac7849;0a1c506ef41acca7bf4c01a758ece6cb;66c0c30821c399e06bb63cfd630b2016;2a5efb3ee633035f5d3700dc744b97d2;07348c108d514773761a828499877ce4;4532d9d99307e 6b3634fdfc06aecbb09;6aae440b59761d2ed4e425206f276dc7', effectiveValue='null', unsubscribeValue='null', deviceId='null'}, appId=nJNKY574F2C4TWrAqYobsa3X, creator=null, messageTitle=null, createTime=Fri May 11 00:00:13 CST 2018, updateTime=Fri May 11 00:00:13 CST 2018], f inishTime=null], extFields={}]], attachments={path=com.oppo.push.open.basic.api.service.BroadcastService, interface=com.oppo.push.open.basic.api.service.BroadcastService, timeout=1000, version=0.0.0}]], channel: /10.12.26.102:49081 -> /10.12.26.137:9000 at com.alibaba.dubbo.rpc.protocol.dubbo.DubboInvoker.doInvoke(DubboInvoker.java:99) at com.alibaba.dubbo.rpc.protocol.AbstractInvoker.invoke(AbstractInvoker.java:144) at com.alibaba.dubbo.rpc.listener.ListenerInvokerWrapper.invoke(ListenerInvokerWrapper.java:74) 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.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.oppo.trace.dubbo.DubboConsumerTraceFilter.invoke(DubboConsumerTraceFilter.java:37) 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.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53) at com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker.doInvoke(FailoverClusterInvoker.java:77) 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.proxy0.push(proxy0.java) at com.oppo.push.open.platform.gateway.action.notification.NotificationBroadcastAction.doExecute(NotificationBroadcastAction.java:105) at com.oppo.push.open.platform.gateway.action.AbstractAction.execute(AbstractAction.java:51) at com.oppo.push.httpframework.Action.ActionCallable$1.exec(ActionCallable.java:39) at com.oppo.push.httpframework.Action.ActionCallable$1.exec(ActionCallable.java:36) at com.oppo.push.httpframework.common.TraceTemplate.rootExec(TraceTemplate.java:24) at com.oppo.push.httpframework.Action.ActionCallable.run(ActionCallable.java:36) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask.run(FutureTask.java:262) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) Caused by: com.alibaba.dubbo.remoting.TimeoutException: Waiting server-side response timeout by scan timer. start time: 2018-05-11 00:00:13.710, end time: 2018-05-11 00:00:14.738, client elapsed: 0 ms, server elapsed: 1028 ms, timeout: 1000 ms, request: Request [id=2395 465, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=push, parameterTypes=[class com.oppo.push.open.basic.api.domain.PushTask], arguments=[PushTask[taskId=5af46c8da609e97b6dc17380, messageId=5af4655dad99497f2345ccda, messageCategory =3, messageType=1, taskStatus=5, target=PushTarget{id='5af46c8da609e97b6dc17381', type=REGISTRATION_ID, value='6187cd138ad2dbceee7f044c2409d4f1;ab5721987d21dcf5e863b58e165f144a;827f4ff3b5d31cce9e441b045eb985c9;e17854797bb4f0e7b14178cbde596c88;CN_647982d13860dde6876cdf0e 37165c76;93624a57d555510bcf27cda47d5a06f9;eb3ebc3a53b12ef304de95b3e1852c60;5b752dc47cbca9721239885a062814c2;c69bd502aee453f0b78517bc9cb4548d;cc35de8b5edbff28dbaf55e4f60ad20a;CN_1239d29db4f5db54cc1bef51df3f3acc;CN_f6fd0448d1c6281da6ffa50df4d26f38;CN_2c2dc12e3c567ad81a00c a9cdca564e3;CN_d92b53c07de3e70883552295ece900f1;CN_b1cedf2537fd52e91fa29b5fb3c4eb47;525fb9de1d18e21c15479a0a7f59b163;CN_debc0d6366f27dea1a45862020687f1a;d5bbb9bae7102ad0d69b3aeb138c4ff4;aac05d1a20d073343917c68798f9be2f;817898207275b2dbeefb6e9398f06b50;203e1b8c0de742605e cb166b6a92d9ce;8c6a4f0925ba3a1d92e3640d00507ade;fc3e47ab8ca527d964fae84ab5db00d7;d9c2ecf8051093bf7eb7818bbe55ec8f;c7894071806e5a6540a5380b1763e91b;b56b7a3e247258034876b9a8522b0dab;8b17b0c449bffa08407a4401f33b988f;789ca011db0844d01932fb8da2553a03;735e6aae28a3f2d5752e65f2 77bea9c3;e2cfca07e576a0285ab8f50dbaa3a947;8428d377795b069d9dfe033e880ed627;0939eab473c0311b5dd5567f5d191487;ec2ff892fbc28fdf0008d532a2c48560;e3df5c83de7f985e73d4e58d4d15225d;CN_c5af7007e71c23771b29eb0713cde7e2;ef91ece8b7e44a13fb31015f8f20b25b;CN_57b78f69e35ce1f8c1fcb27e 36758fca;CN_d58cb83cdd32f108f84ff6eae662712f;CN_5564f22ea67f3391fc0f37b23d68ade0;e2b842e3aea81c7e7784fae318ebfb8a;2315554dca29eac7100d823f262c2b6f;18c0676bc2300630bad171d72353de0b;116c0728d4d8bed6aa80ba78a77620c1;11c37c408a7c88cf80e7bca695228c05;643413c1adad5e72df945940 17797078;CN_c8dedeeeacdc24e9194386929e5367a7;CN_77a3fc33b094c592bad79d1aa95761af;4b9ceaaac2fbca88c01c3976c4ac7849;0a1c506ef41acca7bf4c01a758ece6cb;66c0c30821c399e06bb63cfd630b2016;2a5efb3ee633035f5d3700dc744b97d2;07348c108d514773761a828499877ce4;4532d9d99307e6b3634fdfc0 6aecbb09;6aae440b59761d2ed4e425206f276dc7', effectiveValue='null', unsubscribeValue='null', deviceId='null'}, appId=nJNKY574F2C4TWrAqYobsa3X, creator=null, messageTitle=null, createTime=Fri May 11 00:00:13 CST 2018, updateTime=Fri May 11 00:00:13 CST 2018], finishTime=n ull], extFields={}]], attachments={path=com.oppo.push.open.basic.api.service.BroadcastService, interface=com.oppo.push.open.basic.api.service.BroadcastService, timeout=1000, version=0.0.0}]], channel: /10.12.26.102:49081 -> /10.12.26.137:9000 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) ... 27 common frames omitted

有以下两个奇怪的地方：

1、从报超时的服务端上看，找不到对应的超时的warn日志

2、从我们内部服务端统计的耗时来看，此接口从来没有大于100ms的。

以下是我的分析：

猜测和dubbo 服务端进入业务线程前的排队有关，但是我们没有设置queue的长度，所以默认应该是不排队的，线程池耗尽应该抛出的异常不是timeout。

即使排队了，但是服务端没有找到此上下文的超时日志，感觉像完全没有收到此请求？

会不会是直接网络上丢了包？如果网络上传输就失败了，异常会是超时么？此请求是一个对象，转换为JSON后有几K。

求解答

原提问者GitHub用户Jaskey