pc28网站开发,推荐的外贸客户搜索软件,海南响应式网页建设找哪家,网站空间多少一、起源
23年元旦期间#xff0c;大家都沉浸在一片祥和的过节气氛当中。
“滴滴滴”#xff0c;这头同事的电话响起#xff0c;具体说些什么我也没太在意#xff0c;但见同事接完电话之后展现出了一副懊恼夹杂着些许不耐烦的表情。
我不解问道#xff1a;“怎么了大家都沉浸在一片祥和的过节气氛当中。
“滴滴滴”这头同事的电话响起具体说些什么我也没太在意但见同事接完电话之后展现出了一副懊恼夹杂着些许不耐烦的表情。
我不解问道“怎么了”
同事“刚刚运营反馈系统开始刷白屏了所有的请求一直处于pending状态。”
此刻我的大脑开始飞速旋转界面白屏前端是不是有一个初始化的请求这个初始化的请求有问题导致前端没有往下运行并渲染页面
我“已经登陆进系统的用户可以正常使用吗”
同事“也不可以”。
那就不是初始化请求失败的问题了。
再往下分析应用进程应该没有宕机否则接口会快速响应404。
我“所有接口都阻塞住了还是单个接口的问题最近有没有项目发版”
同事“运营反馈是所有接口都有阻塞情况这段时间一直没有发版”。
那就怪了近期没有发版而且所有接口均有问题。
到此基本可以判定出这个问题与业务无关而是类似基础设施出现问题导致了比如网络问题、Java GC问题、线程池线程短缺出现业务饥饿问题等。
这种问题勾起了我的兴趣我决定自己上手问题开始排查…
二、表象
打开系统发现浏览器发出的接口确实都处于“pending”状态。Pspending是浏览器发出请求之后的一种状态代表该请求还未得到服务器响应如果接口RT延迟高你就有可能经常看到这种状态
接口处于pending状态我在本地使用telnet ip port命令连接应用服务器端口也是正常的到此说明网络与应用进程都是完好的。
三、排查
打开监控系统查看了Java GC耗时、次数两项指标发现和平时也没什么不一样。
查看了系统调用量发现与往常相似没有什么流量突刺。
同事查看了那段时间的系统日志也未发现明显的错误。
我手里的鼠标一直向下滑动着我和同事紧张的看着电脑紧盯着各项指标希望能看出些端倪并能以此为突破口。
果然还是看到了…
下图是近几天的TCP连接数曲线图 TCP涨势图.jpeg
发现TCP连接一直处于只涨不降的趋势除了中间几次的人为重启机器。
我进入服务器熟练的敲起Linux命令
[root] $ **netstat -na | grep 8089 | awk /^tcp/ {S[$NF]} END {for(a in S) print a, S[a]}
LISTEN 8
CLOSE_WAIT 35
ESTABLISHED 108
SYN_SENT 1
TIME_WAIT 9**[root] $ netstat -ntp | grep CLOSE_WAIT
tcp 1 0 本机ip:端口 nginx机器 CLOSE_WAIT pid/java
....观察了十分钟发现CLOSE_WAT状态的TCP连接数一直处于增长的状态。并且观察到所有的CLOSE_WAIT状态的TCP都是与Nginx建立的问了运维同学这台Nginx是这台后端应用的代理。
同事“啊原来是TCP连接数捣鬼一直上涨但不释放”。
这一点和浏览器发出的接口一直处于Pending状态刚好吻合起来了。一定是代码出现了什么问题导致接口延迟上升所有的HTTP请求映射到底层就是TCP连接应用服务器一直没有返回内容那么TCP自然也不会释放了这里我们先不考虑现代HTTP协议的KeepAlive机制。
只见同事为了止血抓紧去重启机器了好让这些TCP连接被强制关闭。
但我还有一点疑问TCP未能及时释放确实有问题不假但即便是这样区区500个TCP连接也不至于达到操作系统的阈值要知道操作系统对端口的限制理论上可以达到65535个。
那一定是有一个短板的中间件因达到了阈值而限制了整个系统很快我便想到了Tomcat因为Tomcat一定是每个业务接口都绕不过的中间件。
虽然机器已经重启了但我们有服务治理相关的平台可以调出任意一个时间点的线程状态不看不知道一看吓一跳所有以“http-nio-xxx”为前缀的线程全部阻塞在方法SocketInputStream.read0方法中。熟悉这个前缀线程的人都知道这是Tomcat线程池。
我”查一下日志看看接口AOP有没有捕捉到请求信息“
同事“捕捉到了”
我“随机抽取几个请求看看接口AOP是否捕捉到了接口响应信息”
同事抓紧去查了不一会儿惊讶的说道“老朱还真有很多请求接口响应AOP没有捕获到那就是说这些请求一直没有处理完”。
同事又说道“老朱这个项目比较特殊项目中所有的接口基本只做了透传的事情项目只是做简单的数据加工然后请求其他系统最后针对结果集再进行过滤、转换返回给前端”
我“啊原来是这样目前使用的HTTP客户端是什么”
同事“Apache HttpClient”
我“Apache HttpClient三个超时时间都设置了吧“
同事“嗯都设置了connectTimeout、socketTimeout、connectionRequestTimeout都根据项目的性质调试过了并且数据流也都妥善处理了”
我有些不解所有的超时时间都设置好了那为什么还会有大量的Tomcat线程阻塞在SocketInputstream.read0方法中呢最终导致TCP持续飙高。
我和同事都陷入了困境进入两难处境不知道如何继续排查机器重启确实可以强制释放TCP但是这方法治标不治本。
同事“啊这怎么会这样”
我“怎么了吞吞吐吐”
同事“我记得之前明明在这些应用里都加了接口AOP日志刚刚看到我们项目有日志但是其他系统中居然没有日志…
至此我有个大胆的猜测请求进入项目之后项目加工请求并转发给其他项目但转发给系统项目的这段网络出现了什么问题因为其他系统并未收到请求又因为种种原因导致超时时间并未生效慢慢的项目中所有Tomcat线程都阻塞在了SocketInputstream中的read0方法中最后Tomcat无空闲线程可去处理用户提交的新的请求。
但是什么情况下Apache HttpClient中的超时时间不生效呢
直到我看到了一篇JDK官网说明
Bug ID: JDK-8172578 SocketInputStream.socketRead0 can hang even with soTimeout set
SocketInputStream.socketRead0 can hang even with soTimeout set 在第二篇文章中有详细描述了SocketTimeOut参数失效的原因大致意思是因为OS select方法存在虚假唤醒的问题导致线程提前进行读取但又因为并没有实际数据因此造成了读取阻塞。
而我们的JDK版本是1.8.0_91也就是低于JDK修复版本当OS发出虚假唤醒之后导致Java线程进入阻塞读取状态最终导致socketTimeout失效。
事情到这就解释的通了我再来根据现象与各项指标结合起来从头到尾的阐述一波。 应用拓扑图.png
这里先祭出项目的拓扑图。
应用A是这次案发地点应用A的大多数功能只是做请求透传工作将用户请求的参数做过滤、筛选、添油加醋发送给应用B。
根据上述的拓扑性质以应用A为中心会有两段请求这里标识为A段、B段。
案发时间前几个小时起初系统稳如老狗。应用A稳定的处理着Nginx转发来的前端请求并包装发送给应用B然后将应用B返回来的数据进行筛选、处理然后返回给用户。
然而好景不长B段出现了一些网络丢包、抖动等情况变得开始不稳定了搭配上JDK8U152版本之前可能会受到操作系统的select虚假唤醒的情况慢慢的Tomcat很多线程都阻塞在了SocketInputstream的read0方法上这一点和之前看到的线程Dump信息一致。
看了眼项目对Tomcat的线程数配置server.tomcat.max-threads**400**而线程Dump出的信息中刚好有400个线程阻塞在了read0方法中。
嗯没错就是这样最后Tomcat成为了整个项目的瓶颈。
四、解决
知道了问题就非常方便解决了我主要采取了三个措施
将项目中使用的BIO HttpClient化成NIO的方式HttpAsyncClient升级JDK为JDK8u152版本添加耗时兜底方案若超过SocketTimeout时间应用A请求B应用还未结束则手动关闭TCP连接Tomcat主线程继续向下运行
其中第二点不用说我通过一段伪代码来说明一下1和3.
public static String getHttpClientResult(CloseableHttpAsyncClient asyncHttpClient, HttpRequestBase httpMethod) throws IOException {String content ; // TCP强制断开标志boolean abortFlag true;HttpResponse response null;// 执行请求FutureHttpResponse httpResponseFuture asyncHttpClient.execute(httpMethod, null);try {httpResponse httpResponseFuture.get(SOCKET_TIMEOUT, TimeUnit.MILLISECONDS);abortFlag false;// 获取返回结果if (httpResponse.getEntity() ! null) {content EntityUtils.toString(httpResponse.getEntity(), ENCODING);}} catch (InterruptedException e) {// 线程被打断重新设置标志并且向下运行Thread.currentThread().interrupt();} catch (ExecutionException e) {// http执行异常包括readTimeOut、connectTimeOutlog.error(当前线程:{},请求异常,发送TCP RST包强制断开, Thread.currentThread().getName());} catch (TimeoutException e) {/*** future get 超时 兜底方案避免主线程阻塞在read方法中* see java.net.SocketInputStream#socketRead0(java.io.FileDescriptor, byte[], int, int, int)* 若超时则发送RST包以强制连接双方断开TCP*/log.error(当前线程:{},超时:{}秒,仍未获取到数据,发送RST包, Thread.currentThread().getName(), SOCKET_TIMEOUT);} finally {if (abortFlag) {httpMethod.abort();}// 释放资源if (!Objects.isNull(httpResponse) !Objects.isNull(httpResponse.getEntity()) !Objects.isNull(httpResponse.getEntity().getContent())) {httpResponse.getEntity().getContent().close();}}return abortFlag ? null : content;}代码优化完毕赶紧发版目前我的这位同事在也没有被运维‘骚扰’过了目前TCP升降趋势稳定喜人 如下 修复后的TCP涨势图.jpeg
