中国建设银行个人卡信息网站,免费建站网站seo,推广网站哪里好,做网站要掌握几种语言问题描述线上突然出现Dubbo超时调用#xff0c;时间刚好为Consumer端设置的超时时间。有好几个不同的接口都报超时了第1次调用超时#xff0c;第2次#xff08;或第3次#xff09;重试调用非常快#xff08;正常水平#xff09;Dubbo调用超时的情况集中出现了3次#xf…问题描述线上突然出现Dubbo超时调用时间刚好为Consumer端设置的超时时间。有好几个不同的接口都报超时了第1次调用超时第2次或第3次重试调用非常快正常水平Dubbo调用超时的情况集中出现了3次每次都是过一会自动恢复排查排查日志看到调用超时首先就拿着traceId去服务提供方查日志。 奇怪的是在服务提供方的业务日志里面只有正常的调用日志耗时正常没有超时调用的日志。 从正常的调用日志里面看一切都是正常的看不出所以然。 给人的感觉就是超时那次请求的调用没有达到服务提供方。此时系统活动情况通过系统历史监控我们发现除了gc比平时稍微高一点外也在正常水位没有其他的异常CPU、内存、网络等指标都在正常范围。查看Dubbo线程活动情况第2次系统集中超时报警的做的第一件事就是登录到那台服务器查看dubbo线程活动情况看下能不能找到阻塞在哪一行代码。很遗憾所有的dubbo线程都没有阻塞都是正常的WAITING状态。并没有明显表明阻塞在某段代码这可难倒我们了如果没有阻塞的话为什么dubbo调用方会报超时继续看代码该接口是否存在阻塞的代码硬着头皮重新看代码每一个分支突然发现底层的一个方法中有http调用会不会是这个http调用导致的超时如果是的话那么不同的接口调用超时的情况就说的通了因为上层大部分接口都会调用这个底层方法。怀揣着激动的心仔细看了http调用的逻辑用的是JDK提供的HttpURLConnection其中只用了HttpURLConnection#getContentLength方法并且也在finally代码块中将这个连接关闭了。好像也不是这个引起的起初还以为getContentLength会把文件给下载下来但是看了接口文档以后发现只会去读头信息中的ContentLength。/*** Returns the value of the {code content-length} header field.* p* bNote/b: {link #getContentLengthLong() getContentLengthLong()}* should be preferred over this method, since it returns a {code long}* instead and is therefore more portable./p** return the content length of the resource that this connections URL* references, {code -1} if the content length is not known,* or if the content length is greater than Integer.MAX_VALUE.*/public int getContentLength() {long l getContentLengthLong();if (l gt; Integer.MAX_VALUE)return -1;return (int) l;}代码阻塞的情况可能性也不大因为重试请求不会超时如果代码阻塞那么重试请求大概率也会超时。数据访问层是否有异常情况既然代码没有阻塞那么有没有可能是数据访问层的异常造成的呢毕竟不止一个接口存在超时的问题如果是底层数据访问层的异常导致那么也说得通。重点排查了mysql但结果是令人失望的并没有慢SQL并且dubbo超时期间mysql实例的CPU和内存水位都是正常的。除了mysql、redis实例本身指标正常外基于上面同样的理由如果数据访问层有问题那么重试基本上也会超时。所以数据访问层导致超时的线索也被排除。有没有可能是Dubbo层面的问题排查再次陷入僵局逼迫着我们重新梳理排查思路除了代码阻塞除了数据访问层异常除了超时请求其他请求的日志都是正常的那么还有可能会导致超时呢会不会是Dubbo本身异常导致的此时有一个关键的线索进入我们的视野超时的那次请求去哪儿了在服务提供方的日志里面没有超时请求的的日志只有重试请求成功的业务日志。太奇怪了就算超时总的留下日志的吧日志都不留欺负我胖虎吗到这里想到超时的请求可能是一个突破口于是开始看Dubbo的相关的源码和文档。从官方文档中的服务端调用链一层层往下查在AllChannelHandler源码中看到了令人兴奋的注释兴奋之余为了避免理解偏差还特地用百度翻译了一下满了那么服务端不会返回直到客户端超时这不是正式我们碰到的问题吗 并且此时还没有进入业务代码所以没有打印业务日志这样就可以解释为什么没有服务提供方没有超时请求的日志了。别激动这里明明有返回threadpool is exhausted异常信息怎么能说没有返回呢 别急这是另外一个项目引用的dubbo版本是2.6.2。 回到出问题的那个项目查看dubbo版本2.8.6查看AllChannelHandler源码是的在2.8.6版本中并没有这个返回错误题好像找到了OK剩下的就是验证了。验证准备将DubboServerHandler线程池的最大线程数调到5使用Apache Bench进行压测200请求、并发10个线程case1复现问题Dubbo使用2.8.6版本预期部分请求超时报错重试耗时正常压测结果符合预期部分接口报错超时并且重试请求耗时正常case2验证猜想Dubbo使用2.6.2版本预期部分请求报错线程池耗尽threadpool is exhausted并且重试大概率也会报该错误压测结果符合预期至此基本判定线上Dubbo调用超时的问题就是因为线程池耗尽引起的。这个超时问题前前后后查了一周左右排查过程中试了很多排查方向为了叙述方便就没有展开。避坑指南合理设置Dubbo线程池大小。默认是200合理设置超时时间。如果真出现了Dubbo调用超时的情况合理的超时时间能够避免服务调用方被打爆Dubbo接口必须有返回值。从AllChannelHandler#received的源码和注释中可以看到只有有返回值的接口才会返回线程池耗尽的错误信息其它的情况则不会将错误信息返回给调用方直到调用方超时。
