案发现场

昨天晚上突然短信收到 APM (即 Application Performance Management 的简称),我们内部自己搭建了这样一套系统来对应用的性能、可靠性进行线上的监控和预警的一种机制)大量告警

画外音: 监控是一种非常重要的发现问题的手段,没有的话一定要及时建立哦

紧接着运维打来电话告知线上部署的四台机器全部 OOM (out of memory, 内存不足),服务全部不可用,赶紧查看问题!

问题排查

首先运维先重启了机器,保证线上服务可用,然后再仔细地看了下线上的日志,确实是因为 OOM 导致服务不可用
惊讶!线上四台机器同一时间全部 OOM,到底发生了什么?

第一时间想到 dump 当时的内存状态,但由于为了让线上尽快恢复服务,运维重启了机器,导致无法 dump 出事发时的内存。所以我又看了下我们 APM 中对 JVM 的监控图表

画外音: 一种方式不行,尝试另外的角度切入!再次强调,监控非常重要!完善的监控能还原当时的事发现场,方便定位问题。
惊讶!线上四台机器同一时间全部 OOM,到底发生了什么?

不看不知道,一看吓一跳,从 16:00 开始应用中创建的线程居然每时每刻都在上升,一直到 3w 左右,重启后(蓝色箭头),线程也一直在不断增长),正常情况下的线程数是多少呢,600!问题找到了,应该是在下午 16:00 左右发了一段有问题的代码,导致线程一直在创建,且创建的线程一直未消亡!查看发布记录,发现发布记录只有这么一段可疑的代码 diff:在 HttpClient 初始化的时候额外加了一个 evictExpiredConnections 配置
惊讶!线上四台机器同一时间全部 OOM,到底发生了什么?

问题定位了,应该是就是这个配置导致的!(线程上升的时间点和发布时间点完全吻合!),于是先把这个新加的配置给干掉上线,上线之后线程数果然恢复正常了。那 evictExpiredConnections 做了什么导致线程数每时每刻在上升呢?这个配置又是为了解决什么问题而加上的呢?于是找到了相关同事来了解加这个配置的前因后果

还原事发经过

最近线上出现不少 NoHttpResponseException 的异常,那是什么导致了这个异常呢?

在说这个问题之前我们得先了解一下 http 的 keep-alive 机制。

先看下正常的一个 TCP 连接的生命周期
惊讶!线上四台机器同一时间全部 OOM,到底发生了什么?

可以看到每个 TCP 连接都要经过 三次握手 建立连接后才能发送数据,要经过 四次挥手 才能断开连接,如果每个 TCP 连接在 server 返回 response 后都立马断开,则发起多个 HTTP 请求就要多次创建断开 TCP, 这在 Http 请求很多 的情况下无疑是很耗性能的, 如果在 server 返回 response 不立即断开 TCP 链接,而是 复用 这条链接进行下一次的 Http 请求,则无形中省略了很多创建 / 断开 TCP 的开销,性能上无疑会有很大提升。

如下图示,左图是不复用 TCP 发起多个 HTTP 请求的情况,右图是复用 TCP 的情况,可以看到发起三次 HTTP 请求,复用 TCP 的话可以省去两次建立 / 断开 TCP 的开销,理论上发起 一个应用只要启一个 TCP 连接即可,其他 HTTP 请求都可以复用这个 TCP 连接,这样 n 次 HTTP 请求可以省去 n-1 次创建 / 断开 TCP 的开销。这对性能的提升无疑是有巨大的帮助。
惊讶!线上四台机器同一时间全部 OOM,到底发生了什么?

回过头来看 keep-alive (又称持久连接,连接复用)做的就是复用连接, 保证连接持久有效。

画中音: Http 1.1 之后 keep-alive 才默认支持并开启,不过目前大部分网站都用了 http 1.1 了,也就是说大部分都默认支持链接复用了

天下没有免费的午餐,虽然 keep-alive 省去了很多不必要的握手/挥手操作,但由于连接长期保活,如果一直没有 http 请求的话,这条连接也就长期闲着了,会占用系统资源,有时反而会比复用连接带来更大的性能消耗。 所以我们一般会为 keep-alive 设置一个 timeout, 这样如果连接在设置的 timeout 时间内一直处于空闲状态(未发生任何数据传输),经过 timeout 时间后,连接就会释放,就能节省系统开销。

看起来给 keep-alive 加 timeout 是完美了,但是又引入了新的问题(一波已平,一波又起!),考虑如下情况:

如果服务端关闭连接,发送 FIN 包(注:在设置的 timeout 时间内服务端如果一直未收到客户端的请求,服务端会主动发起带 Fin 标志的请求以断开连接释放资源),在这个 FIN 包发送但是还未到达客户端期间,客户端如果继续复用这个 TCP 连接发送 HTTP 请求报文的话,服务端会因为在四次挥手期间不接收报文而发送 RST 报文给客户端,客户端收到 RST 报文就会提示异常 (即 NoHttpResponseException )

我们再用流程图仔细梳理一下上述这种产生 NoHttpResponseException 的原因,这样能看得更明白一些
惊讶!线上四台机器同一时间全部 OOM,到底发生了什么?

费了这么大的功夫,我们终于知道了产生 NoHttpResponseException 的原因,那该怎么解决呢,有两种策略

重试,收到异常后,重试一两次,由于重试后客户端会用有效的连接去请求,所以可以避免这种情况,不过一次要注意重试次数,避免引起雪崩!
设置一个定时线程,定时清理上述的闲置连接,可以将这个定时时间设置为 keep alive timeout 时间的一半以保证超时前回收。
evictExpiredConnections就是用的上述第二种策略,来看下官方用法使用说明

Makes this instance of HttpClient proactively evict idle connections from the
connection pool using a background thread.

调用这个方法只会产生一个定时线程,那为啥应用中线程会一直增加呢,因为我们对每一个请求都创建了一个 HttpClient! 这样由于每一个 HttpClient 实例都会调用 evictExpiredConnections ,导致有多少请求都会创建多少个 定时线程!

还有一个问题,为啥线上四台机器几乎同一时间点全挂呢?

因为由于负载均衡,这四台机器的权重是一样的,硬件配置也一样,收到的请求其实也可以认为是差不多的,这样这四台机器由于创建 HttpClient 而生成的后台线程也在同一时间达到最高点,然后同时 OOM。

解决问题

所以针对以上提到的问题,我们首先把 HttpClient 改成了单例,这样保证服务启动后只会有一个定时清理线程,另外我们也让运维针对应用的线程数做了监控,如果超过某个阈值直接告警,这样能在应用 OOM 前及时发现处理。

画外音:再次强调,监控相当重要,能把问题扼杀在摇篮里!

总结

本文通过线上四台机器同时 OOM 的现象,来详细剖析产定位了产生问题的原因,可以看到我们在应用某个库时首先要对这个库要有充分的了了解(上述 HttpClient 的创建不用单例显然是个问题),其次必要的网络知识还是需要的,所以要成为一个合格的程序员,不关对语言本身有所了解,还要对网络,数据库等也要有所涉猎,这些对排查问题以及性能调优等会有非常大的帮助,再次,完善的监控非常重要,通过触发某个阈值提前告警,可以将问题扼杀在摇篮里!