search

apache / dubbo

The java implementation of Apache Dubbo. An RPC and microservice framework.
https://dubbo.apache.org/
Apache License 2.0
40.46k stars 26.42k forks source link

dubbo超时时间设置10s,而实际出现了几十秒? #40

Closed carlvine500 closed 7 years ago

carlvine500 commented 10 years ago

这是我们线上的日志，下方日志的server elapsed: 53250 ms 太吓人了，50多 s,请问这是什么原因？ 282411047 [/atg/dynamo/service/Scheduler-poller] WARN com.alibaba.dubbo.rpc.cluster.support.FailoverClusterInvoker - [DUBBO] Although retry the method hgetAll in the service com.gome.service.CacheService was successful by the provider 10.58.50.150:20990, but there have been failed providers 10.58.50.147:20990 from the registry 10.58.22.191:2181 on the consumer 10.58.50.36 using the dubbo version 2.5.3. Last error is: Invoke remote method timeout. method: hgetAll, provider: dubbo://10.58.50.147:20990/com.gome.service.CacheService?anyhost=true&application=gome-cache-redis-client-app-atg&check=false&delay=10000&dubbo=2.5.3&interface=com.gome.service.CacheService&loadbalance=random&methods=lpush,hexists,hmset,decr,set,hsetnx,lpop,type,hlen,rpush,hincrBy,hgetAll,setex,ltrim,smembers,del,substr,incrBy,decrBy,expire,append,srem,hmget,llen,hget,lindex,get,hdel,keys,ttl,expireAt,sadd,mutliExecute,hset,rpop,exists,dbSize,scard,incr,hkeys,testDubboRequest,lrange&pid=25176&revision=_Gome.EStore_slib_scacheClient&side=consumer&timeout=10000&timestamp=1395684487928, cause: Waiting server-side response timeout. start time: 2014-03-28 08:30:22.157, end time: 2014-03-28 08:31:15.407, client elapsed: 0 ms, server elapsed: 53250 ms, timeout: 10000 ms, request: Request [id=1332943, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=hgetAll, parameterTypes=[class java.lang.String, class java.lang.String], arguments=[BUDGET, 186800033_case], attachments={path=com.gome.service.CacheService, interface=com.gome.service.CacheService, timeout=10000, version=0.0.0}]], channel: /10.58.50.36:51071 -> /10.58.50.147:20990, dubbo version: 2.5.3, current host: 10.58.50.36 com.alibaba.dubbo.rpc.RpcException: Invoke remote method timeout. method: hgetAll, provider: dubbo://10.58.50.147:20990/com.gome.service.CacheService?anyhost=true&application=gome-cache-redis-client-app-atg&check=false&delay=10000&dubbo=2.5.3&interface=com.gome.service.CacheService&loadbalance=random&methods=lpush,hexists,hmset,decr,set,hsetnx,lpop,type,hlen,rpush,hincrBy,hgetAll,setex,ltrim,smembers,del,substr,incrBy,decrBy,expire,append,srem,hmget,llen,hget,lindex,get,hdel,keys,ttl,expireAt,sadd,mutliExecute,hset,rpop,exists,dbSize,scard,incr,hkeys,testDubboRequest,lrange&pid=25176&revision=_Gome.EStore_slib_scacheClient&side=consumer&timeout=10000&timestamp=1395684487928, cause: Waiting server-side response timeout. start time: 2014-03-28 08:30:22.157, end time: 2014-03-28 08:31:15.407, client elapsed: 0 ms, server elapsed: 53250 ms, timeout: 10000 ms, request: Request [id=1332943, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=hgetAll, parameterTypes=[class java.lang.String, class java.lang.String], arguments=[BUDGET, 186800033_case], attachments={path=com.gome.service.CacheService, interface=com.gome.service.CacheService, timeout=10000, version=0.0.0}]], channel: /10.58.50.36:51071 -> /10.58.50.147:20990 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.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.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.hgetAll(proxy0.java) at com.gome.cache.impl.RemoteCacheToolImpl.hgetAll(RemoteCacheToolImpl.java:105) at com.gome.cache.impl.CacheRedisToolImpl.hgetAll(CacheRedisToolImpl.java:70) at com.gome.commerce.order.submitordervalidator.basetools.BudgetManageService.allValidCases(BudgetManageService.java:383) at com.gome.commerce.order.submitordervalidator.basetools.BudgetManageService.cacheValidCase(BudgetManageService.java:370) at com.gome.commerce.promotion.LoadGomeBudgetCaseSchedule.performSchedule(LoadGomeBudgetCaseSchedule.java:19) at com.gome.commerce.estore.GomeBaseSchedule.performScheduledTask(GomeBaseSchedule.java:93) at atg.service.scheduler.Scheduler.handleNextScheduledJob(Scheduler.java:481) at atg.service.scheduler.Scheduler.handleScheduledJobs(Scheduler.java:663) at atg.service.scheduler.Scheduler$Poller.run(Scheduler.java:83) Caused by: com.alibaba.dubbo.remoting.TimeoutException: Waiting server-side response timeout. start time: 2014-03-28 08:30:22.157, end time: 2014-03-28 08:31:15.407, client elapsed: 0 ms, server elapsed: 53250 ms, timeout: 10000 ms, request: Request [id=1332943, version=2.0.0, twoway=true, event=false, broken=false, data=RpcInvocation [methodName=hgetAll, parameterTypes=[class java.lang.String, class java.lang.String], arguments=[BUDGET, 186800033_case], attachments={path=com.gome.service.CacheService, interface=com.gome.service.CacheService, timeout=10000, version=0.0.0}]], channel: /10.58.50.36:51071 -> /10.58.50.147:20990 at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:107) at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture.get(DefaultFuture.java:84) at com.alibaba.dubbo.rpc.protocol.dubbo.DubboInvoker.doInvoke(DubboInvoker.java:96) ... 23 more

xiaolongyuan commented 9 years ago

国美？

carlvine500 commented 9 years ago

嗯，之前和你们开发的同学直接沟通过了，暂时归结到网络原因了，后续有发现在请教。谢谢！

patrickchense commented 7 years ago

请问最后这个问题解决了吗？我也出现：com.alibaba.dubbo.remoting.TimeoutException: Waiting server-side response timeout. start time: 2016-10-25 15:16:42.905, end time: 2016-10-25 15:16:51.316, client elapsed: 1 ms, server elapsed: 8410 ms, timeout: 2000 ms, 而且因为没有发现不停的报10分钟，就GC over limit了，这个可以通过client 配置来解决吗？求助

counterFish commented 7 years ago

@patrickzhe server elapsed: 8410 ms, timeout: 2000 ms, 这个timeout 你是设置的哪一个啊

takeseem commented 7 years ago

实际执行时间是8.41s，因为timeout=2s，所以TimeoutException 以前也碰到过没有潜心研究，根据字面意思理解的：）

只要不频繁发生就没有问题，比如一天就10来次。

qinliujie commented 7 years ago

看起来像是 fullgc 导致的 STW

zackszhang commented 6 years ago

我这里并没有出现full gc,也有这种情况,再说full gc 50多秒?这解释有点牵强吧?想咨询是不是future这种超时机制本来就无法控制得很精确?或者说什么情况下会出现不够精确?误差有多大?微服务的rt要控制在ms级,对这种情况很敏感