问题log
com.alibaba.dubbo.rpc.RpcException: Failed to invoke the method getExpressGoldOrderCount in the service com.xxx.xxx.IExpressGoldOrderService.
Tried 3 times of the providers [*.*.*.*:20880] \u00281/1\u0029 from the registry *.*.*.*:2181 on the consumer 172.16.134.115 using the
dubbo version 2.6.2. Last error is: Invoke remote method timeout. method: getExpressGoldOrderCount, provider: dubbo:
//*.*.*.*:20880/com.xxx.xxx.IExpressGoldOrderService?anyhost=true&application=zt-express&check=false&dubbo=2.6.2
&generic=false&interface=com.xxx.xxx.IExpressGoldOrderService&methods=sumCancelAmount,getExpressGoldOrderList,
updateExpressGoldOrder,insertExpressGoldOrder,getExpressGoldOrderCount&pid=8745®ister.ip=172.16.134.115&remote.timestamp=
1572435096569&revision=master&side=consumer&timeout=8000×tamp=1572438031171&version=master, cause: Waiting server-side
response timeout by scan timer. start time: 2019-10-30 20:20:58.558, end time: 2019-10-30 20:21:06.560, client elapsed: 1 ms,
server elapsed: 8001 ms, timeout: 8000 ms, request: Request [id=2, version=2.0.0, twoway=true, event=false, broken=false, data
=RpcInvocation [methodName=getExpressGoldOrderCount, parameterTypes=[interface java.util.Map], arguments=[{offset=0, pageNo=1,
couponType=2, couponStatus=1, limit=20, pageSize=20, sort=desc, order=cancel_time}], attachments={path=com.xxx.xxx.IExpressGoldOrderService,
interface=com.xxx.xxx.IExpressGoldOrderService, version=master, timeout=8000}]], channel: /172.16.134.115:51186 -\u003E /*.*.*.*:20880
错误分析
调用服务超时
排查
首先看dubbo连接是否正常,是否能ping通providers其次看服务者providers是否正常;有没有报错打印出providers调用的方法日志,看看是否连接成功
less 查日志的教训
菜鸟连接 less 菜鸟讲解 查日志 习惯性的使用less control+g 命令查看行尾,行尾并没有打印错误信息,错误的认为服务是正常的。然后去找其他连接超时问题。 迷途:延长超时时间timeout改为8000 因为 client elapsed: 1 ms, server elapsed: 8001 ms 服务花了8001,那应该是服务超时了,延长一点就行。(超时时间设置为8000ms,8000ms过了服务没有响应,服务端8001) 后来详细看providers日志 tail -fn -300 然后调用观察,发现有错误日志,数据库连接问题。 真相大白了,由于数据库连接问题,导致服务调用失败,不断尝试连接数据库,不断失败,对于消费者来说,是不知道的。
总结
日志分析时注意细节,经验还不够,需要更多的场景,更多的bug来丰富自己,加油!没有bug的程序猿不是好程序猿!