周末值班遭遇网络故障与服务探测问题处理经验分享

”

这几天，团队一直在值班，轮流照顾我们的服务，主要做处理报警邮件、排查Bug、处理运营问题等工作。工作日没事，无论做什么，都得去上班。如果是周末，那么这一天就毁了。

不知道是因为公司网络太广，还是因为网络运维团队不称职。网络总是有问题。要么是这里的交换机掉线，要么是那里的路由器坏了，偶尔会出现各种超时的情况。然而，我们敏感的服务检测服务总能准确地捕捉到偶尔出现的小问题，为良好的工作增添一些情趣。

有几次，值班团队的朋友一起抱怨，讨论如何绕过服务保活机制，在无人察觉的情况下偷偷停止检测服务（虽然他们不敢这么做）。前几天我刚刚在周末处理了一个探测服务罐。

出现问题

晚上7点左右开始，我开始不停地收到报警邮件。电子邮件显示，检测到的多个接口已超时。

大部分执行堆栈位于：

java.io.BufferedReader.readLine(BufferedReader.java:371)
java.io.BufferedReader.readLine(BufferReader.java:389)
java_io_BufferedReader$readLine.call(Unknown Source)
com.domain.detect.http.HttpClient.getResponse(HttpClient.groovy:122)
com.domain.detect.http.HttpClient.this$2$getResponse(HttpClient.groovy)

我从这个线程堆栈中看到了很多错误。我们设置的HTTP DNS超时为1s，连接超时为2s，读取超时为3s。

出现这种错误是因为检测服务正常发送了HTTP请求，服务器收到请求并正常处理后也正常响应。但数据包在网络转发中丢失了，所以请求线程的执行栈会停留在获取接口响应上。地方。

这种情况的一个典型特征是可以在服务器上找到相应的日志记录。并且日志会显示服务器响应完全正常。

相比之下，线程堆栈停留在Socket connect处，建立连接时失败，服务器完全感知不到。

我注意到其中一个接口报告错误的频率更高。该接口需要上传一个4M的文件到服务器，然后经过一系列的业务逻辑处理，然后返回2M的文本数据。

其他接口都是简单的业务逻辑。我猜测可能是需要上传下载的数据太多，所以超时丢包的概率也比较大。

基于这个推测，该组登录服务器并使用请求的request_id搜索最近的服务日志。果然，由于网络丢包导致接口超时。

当然，领导不会就此满足，必须有人来承担这个结论的责任。于是我赶紧联系了运维和网络团队，跟他们确认了当时的网络状况。

网络组的一位同学回复说，我们检测服务所在机房的交换机比较旧，存在未知的转发瓶颈，正在优化。这让我心里踏实多了，于是在部门群里简单交代了一下，任务就完成了。

问题爆发

本以为这个轮班会有这么小的波澜，没想到晚上八点左右，各个接口的报警邮件蜂拥而至，正准备收拾东西准备单人休息的我措手不及。在星期天。

这次几乎所有接口都超时了，我们的网络I/O量大的接口每次检测到都会超时。难道是整个机房都出现故障了？

我再次通过服务器和监控看到各个接口的指标都正常。我自己测试了界面，完全没问题。由于不影响线上服务，所以我打算通过检测服务接口停止检测任务，然后慢慢排查。

结果我向暂停检测任务的接口发送了请求，但是很长时间没有响应。这时我才发现事情并没有那么简单。

解决问题

内存泄漏

于是我赶紧登录检测服务器，首先top free df三遍，发现了一些异常：

我们的检测过程的CPU使用率特别高，达到了900%。

我们的Java进程并没有做很多CPU操作。正常情况下CPU应该在100%到200%之间。如果发生这种 CPU 激增，它要么会进入无限循环，要么会进行大量 GC。

使用jstat -gc pid [interval]命令查看Java进程的GC状态。果然FULL GC达到了每秒一次：

这么多次FULL GC，应该不会出现内存泄漏的情况，所以使用jstack pid > jstack.log来保存线程栈场景。

使用jmap -dump:format=b,file=heap.log pid保存堆场景，然后重新启动检测服务，报警邮件终于停止了。

统计数据

jstat是一个非常强大的JVM监控工具。其一般用法是：

jstat [-options] pid interval

它支持的查看项目有：

使用它对于定位JVM内存问题非常有帮助。

故障排除

虽然问题已经解决了，但是为了防止再次发生，我们仍然需要找出根本原因。

分析堆栈

堆栈的分析非常简单。检查线程数是否过多以及大部分堆栈在做什么：

> grep 'java.lang.Thread.State' jstack.log  | wc -l
> 464

只有400多个线程，无一例外：

> grep -A 1 'java.lang.Thread.State' jstack.log  | grep -v 'java.lang.Thread.State' | sort | uniq -c |sort -n

     10     at java.lang.Class.forName0(Native Method)
     10     at java.lang.Object.wait(Native Method)
     16     at java.lang.ClassLoader.loadClass(ClassLoader.java:404)
     44     at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    344     at sun.misc.Unsafe.park(Native Method)

线程状态似乎没有异常。接下来，分析堆文件。

下载堆转储文件

堆文件都是二进制数据，在命令行查看非常麻烦。 Java提供的工具都是可视化的，无法在Linux服务器上查看，所以必须先将文件下载到本地。

由于我们设置的堆内存是4G，所以转储的堆文件也很大。下载起来确实很麻烦，不过我们可以先压缩一下。

gzip是一个非常强大的压缩命令，特别是我们可以设置-1~-9来指定其压缩级别。

数据越大，压缩比越大，所需时间也越长。推荐使用-6~7，-9确实太慢了，而且利润也不大。通过此压缩时间，将下载额外的文件。

使用MAT分析jvm堆

MAT 是分析 Java 堆内存的强大工具。用它打开我们的堆文件（将文件后缀更改为.hprof），它会提示我们要进行的分析类型。

对于这个分析，果断选择内存泄漏嫌疑点：

从上面的饼图可以看出，大部分堆内存都被同样的内存占用了。检查堆内存细节并回溯上层后，很快就找到了罪魁祸首。

分析代码

找到内存泄漏对象后，在项目中全局查找对象名。它是一个Bean对象，然后定位它的Map类型的属性。

这个Map使用ArrayList按照类型存储每个检测接口响应的结果。每次检测完毕后，将其填充到ArrayList中进行分析。

由于Bean对象不会被回收，也没有该属性的清除逻辑，所以当服务十多天没有上线重启时，Map就越来越大，直到内存满了。

内存满后，无法再为HTTP响应结果分配内存，所以一直卡在readLine。我们的I/O量较大的接口，报警数量特别多，这可能与响应较大，需要更多内存有关。

我向代码所有者提交了 PR，问题成功解决。

概括

其实你还是需要反省一下自己。最初的报警邮件中有一个这样的线程堆栈：

groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:166)
groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132)
groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186)
groovy.json.internal.JsonParserCharArray.decodeJsonObject(JsonParserCharArray.java:132)
groovy.json.internal.JsonParserCharArray.decodeValueInternal(JsonParserCharArray.java:186)