目录
什么是CLOSE_WAIT状态 CLOSE_WAIT增长问题排查
问题现象
宿主机器CLOSE_WAIT状态的TCP连接数量持续增长，增长到一定数量后会断崖式减少，然后又重新增长
什么是CLOSE_WAIT状态
TCP协议
三次握手、四次挥手
建立阶段状态变化
- 客户端：CLOSED→ SYS_SENT→ ESTABLISHED
- 服务器：CLOSED→ LISTEN→ SYS_RCVD→ ESTABLISHED
结束阶段状态变化
- 主动关闭方：ESTABLISHED→ FIN_WAIT_1→ FIN_WAIT_2→ TIME_WAIT→ CLOSED
- 被动关闭方：ESTABLISHED→CLOSE_WAIT→ LAST_ACK→ CLOSED
CLOSE_WAIT状态是被动关闭方收到主动关闭方的关闭消息后产生的状态，在此状态时TCP链接状态不会自动变化，只能由应用程序主动调用关闭方法，从而进入LAST_ACK阶段
CLOSE_WAIT状态危害：此状态下占用操作系统端口资源，当端口资源耗尽时会导致TCP链接建立时绑定端口失败
问题排查
根据CLOSE_WAIT状态产生的原因可知，此状态只能由被动关闭方产生，所以会有以下两个场景：
- 客户端：主动和服务器建立连接，由服务器主动关闭连接，而客户端并未及时关闭连接
- 服务器：被动与客户端建立连接，由客户端主动关闭连接，而服务器并未及时关闭连接
CLOSE_WAIT信息查看
通过命令查看CLOSE_WAIT状态链接信息，发现是由本地发起的连接，调用外部接口，端口是80，一般情况下应该是HTTP调用
netstat -nt | grep CL |
通过Pid 26668可以确定是我们的Java应用导致了此问题
sudo ps -ef | grep 26668 |
接下来，找到IP对应的机器 xxxxx.f.cn1.qunar.com.
host 10.66.160.10 |
根据HOST无法确定是什么服务，在Portal中搜索也无法找到，初步判断为NG服务器，通过跟OPS确认，确实为NG服务器
至此确定CLOSE_WAIT状态是HTTP调用导致
使用Tcpdump命令进行数据抓包分析
sudo tcpdump -A host 10.66.160.10 and port 80 |
发现太多域名的不同接口都会通过此NG，无法确定出问题HTTP调用的具体特征
业务代码排查
业务对外的HTTP服务调用使用的是Spring的RestTemplate组件，根据经验，这块的代码应该是没有问题的，保险起见，还是排查一下
RestTemplate执行时的调用时序图如下
可知RestTemplate在处理数据结束时是调用了Response的close()方法的，但是ClientHttpRespons有很多实现，需要确定到具体的实现类去看有没有关闭
可以看出业务中使用的是ClientHttpRequestFactory实现为HttpComponentsClientHttpRequestFactory
HttpComponentsClientHttpRequestFactory→ (HttpComponentsClientHttpRequest/HttpComponentsStreamingClientHttpRequest)→ HttpComponentsClientHttpResponse
所以我们来看一下HttpComponentsClientHttpResponse的代码实现
可以看到在close()方法中已经对资源进行了回收与关闭，断定RestTemplate的使用没有问题
接下来继续在业务代码中排查到以下代码，通过代码上下文分析发现：若出现重定向的情况，原有入参Connection未被关闭
修改为以下代码，关闭连接后再创建新连接返回
发布到线上之后发现CLOSE_WAIT数量依旧持续增长，增长速度也没有减缓，说明这个地方影响量几乎可以忽略
监控趋势分析
我们再看下这个监控，前面说了CLOSE_WAIT的数量增长到某个高点之后就会断崖式回落，这种突然的变化，肯定是有某种事件触发的
在Java中，一切皆对象，可以认为每个端口资源都对应一个对象，那把这个CLOSE_WAIT数量看作某一类对象的数量的话，那这么大量的对象减少的原因是什么呢，答案就是GC
GC分两种，YongGC和FullGC，YongGC作用于新生代，GC频率较高，根据CLOSE_WAIT数量的波动曲线可以看出频率比较低，应该是FullGC
查看对应机器的FullGC的监控可以发现FullGC的时间点和CLOSE_WAIT的趋势完全吻合，说明是在FullGC过程中释放了端口资源，接下来我们在FullGC之前Dump一下Java内存来进行分析
JAVA内存DUMP分析
Dump现场内存信息进行分析
sudo -u tomcat jmap -dump:format=b,file=/tmp/heap.hprof 3033 |
下载到本地后，使用MAT打开内存文件
打开Histogram查看存活对象和不可达对象，因为之前已经确定是HTTP解耦调用的问题，所以搜索HTTP相关对象
其中发现 KeepAliveStream流对象数量比较多，尤其是在不可达对象中达到10712个
其中不可达对象无法进行分析，所以需要重存活对象入手进行分析
首先列出KeepAliveStream对象以及它引用对象
然而并未发现有价值的信息
接下来KeepAliveStream对象以及引用它对象
通过向上寻找引用对象，我们发现这样的一个引用路径
KeepAliveStream→ HttpClient→ HttpURLConnection→ URLDataSource→ DataHandler→ MimeBodyPart→ MimeMultipart→ HtmlEmail
在这里先说一下，项目里使用了Apache的Email工具包，目的是为了用来给用户通过邮件的方式来发送电子发票，电子发票是作为邮件的附件来发送的
HtmlEmail类是Apache包中的类，MimeMultipart、MimeBodyPart、DataHandler、URLDataSource是javax.mail依赖包中的类
我们发现这个MimeMultipart对象被432个MimeBodyPart对象所关联，通过字段名parent可知此MimeMultipart对象是关联其432个MimeBodyPart对象的父对象
来看一下这个MimeBodyPart对象的内部引用情况
可以看到确实引用了432个MimeBodyPart对象，打开其中一个之后可以看到一个URLDataSource对象引用了一个附件的URL对象，以及一个HttpURLConnection对象，打开其他的MimeBodyPart对象可以看到同样的情况
接下来我们搜索一下URL类在内存中有多少对象
看一下URL的对象信息
全是http://oss.qunar.corp.qunar/......
我们来看下这个域名的信息，和我们前面拿到的NG是相同的
原因验证
到这里基本可以定位到是附件发送的问题了，我们通过将定时任务调整到机器1来验证
可以看到机器1随着定时任务的执行，CLOSE_WAIT在不断增长，而其他机器基本不变
根据链接我们定位到数据库中具体业务数据，发现这次索要共有432附件，且长时间未发送出去，通过发送异常日志，确认是邮件过大，导致发送失败
Caused by: com.sun.mail.smtp.SMTPSendFailedException: 552 5.3.4 Error: message file too big at com.sun.mail.smtp.SMTPTransport.issueSendCommand(SMTPTransport.java:2114) at com.sun.mail.smtp.SMTPTransport.finishData(SMTPTransport.java:1900) at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1122) at javax.mail.Transport.send0(Transport.java:195) at javax.mail.Transport.send(Transport.java:124) at org.apache.commons.mail.Email.sendMimeMessage(Email.java:1400) ... 38 common frames omitted |
通过修复此次异常数据后，重启机器1，发现CLOSE_WAIT不再持续增长，问题临时解决
问题定位
为了彻底解决附件过多导致的CLOSE_WAIT数量持续增长，我们继续分析源码
首先，我们到代码中看一下这个URL的使用场景
package javax.activation;
import java.io.IOException;
import java.io.InputStream;
import java.io.OutputStream;
import java.net.URL;
import java.net.URLConnection;
public class URLDataSource implements DataSource {
private URL url = null;
private URLConnection url_conn = null;
public URLDataSource(URL url) {
this.url = url;
}
public String getContentType() {
String type = null;
try {
if (this.url_conn == null) {
this.url_conn = this.url.openConnection();
}
} catch (IOException var3) {
}
if (this.url_conn != null) {
type = this.url_conn.getContentType();
}
if (type == null) {
type = "application/octet-stream";
}
return type;
}
public String getName() {
return this.url.getFile();
}
public InputStream getInputStream() throws IOException {
return this.url.openStream();
}
public OutputStream getOutputStream() throws IOException {
this.url_conn = this.url.openConnection();
if (this.url_conn != null) {
this.url_conn.setDoOutput(true);
return this.url_conn.getOutputStream();
} else {
return null;
}
}
public URL getURL() {
return this.url;
}
} |
可以看到这里url_conn字段是被 getContentType() 与 getOutputStream() 两个方法做了复用
但是在 getInputStream() 中并没有复用url_conn，而是直接重新创建了个链接，拿到了一个新的流对象
翻阅ApacheEmail与JavaEmail源代码和Debug，对邮件发送流程进行分析
为方便大家理解，将整个流程简化为3个步骤
- 步骤1:
在添加附件时ApacheEmail会创建一个DataSource添加到Email对象中，如果附件是网络文件，会创建URLDataSource对象 ，此处会进行文件有效性校验，打开连接并关闭（连接1）
- 步骤2 ：
在发送邮件时首先会保存修改，然后再发送邮件
保存邮件时会通过DataHandler调用DataSource的 getContentType() 方法获取附件类型
如果是URLDataSource则会通过创建HttpURLConnection的方式获取到真实的附件类型，其中如果已经打开过连接的会直接复用，如果是新创建的连接会赋值给url_conn来进行复用（连接2）
- 步骤3:
发送邮件时，会调用DataHandler的writeTo()方法对数据进行写入，而方法内部则是调用DataSource的getInputStream()获取输入流 ，然后写入到邮件输出流中，完成之后关闭（连接3）
到这里，我们已经找到了DataSource类对象的两个方法的调用方，而 getOutputStream() 实际并没有调用方，所以可以暂时忽略
问题已经显现出来了，在getContentType()被调用时会创建一个连接同时缓存起来，但是在调用getInputStream()方法是并没有复用已有的连接，而是重新创建一个连接来获取流
这就导致了在getContentType()被调用时创建的连接没有主动关闭，由于此连接是与NG建立的，NG会在连接超过一定时长后就关闭连接（后续抓包也能反应出来），最终导致此连接停留在CLOSE_WAIT状态，同时在垃圾回收器回收之前是不会释放占用的端口。
也就是我们附件发送流程中会存在连接未关闭的情况，而我们服务也上线一段时间了，之前为什么没出现大量增长呢？
通过分析发现，如果邮件中的附件比较少，那么没有被关闭的连接会在发送完邮件之后被YongGC给回收掉
然而，这个CASE比较特殊，一个邮件中有432个附件，每个附件上传的过程是串行的，这就导致这个超大邮件对象的存活时长超过了YongGC阶段，晋升到了老年代
同时，邮件服务器不支持发送包含如此巨大数量附件的邮件，导致发送失败，而定时任务每次都回将其从数据库中取出然后尝试发送邮件
久而久之，老年代中的超大邮件对象越来越多，CLOSE_WAIT状态的TCP连接也越来越多，直到老年代空间不够时，触发FullGC，将其回收掉，同时释放端口资源，所以才会出现CLOSE_WAIT数量达到一定数量后陡然下降的现象
问题复现
接着我们再通过Debug结合抓包来看下，一个附件发送过程中的网络交互
-
连接1 → 进行附件有效性检测 （org.apache.commons.mail.MultiPartEmail#attach(java.net.URL, java.lang.String, java.lang.String, java.lang.String)）
15:37:49.495289 IP 100.85.8.35.51414 > 10.66.160.10.80: Flags [SEW], seq 49442829, win 65535, options [mss 1350,nop,wscale 6,nop,nop,TS val 146266820 ecr 0,sackOK,eol], length 0 15:37:49.501084 IP 10.66.160.10.80 > 100.85.8.35.51414: Flags [S.E], seq 2694471148, ack 49442830, win 28960, options [mss 1350,nop,nop,TS val 1447364155 ecr 146266820,nop,wscale 10], length 0 15:37:49.501160 IP 100.85.8.35.51414 > 10.66.160.10.80: Flags [.], ack 1, win 2048, options [nop,nop,TS val 146266826 ecr 1447364155], length 0 15:37:49.501576 IP 100.85.8.35.51414 > 10.66.160.10.80: Flags [P.], seq 1:212, ack 1, win 2048, options [nop,nop,TS val 146266826 ecr 1447364155], length 211: HTTP: GET /qss_qinvoice_2/XCD0207131700519456520210207131817.pdf HTTP/1.1 15:37:49.507568 IP 10.66.160.10.80 > 100.85.8.35.51414: Flags [.], ack 212, win 30, options [nop,nop,TS val 1447364160 ecr 146266826], length 0 15:37:49.522454 IP 10.66.160.10.80 > 100.85.8.35.51414: Flags [.], seq 1:1339, ack 212, win 30, options [nop,nop,TS val 1447364176 ecr 146266826], length 1338: HTTP: HTTP/1.1 200 OK --------省略一堆数据交互-------- 15:37:49.532096 IP 100.85.8.35.51414 > 10.66.160.10.80: Flags [.], ack 31313, win 2039, options [nop,nop,TS val 146266853 ecr 1447364184], length 0 15:37:55.974592 IP 100.85.8.35.51414 > 10.66.160.10.80: Flags [F.], seq 212, ack 31313, win 2048, options [nop,nop,TS val 146273257 ecr 1447364184], length 0 15:37:55.986460 IP 10.66.160.10.80 > 100.85.8.35.51414: Flags [F.], seq 31313, ack 213, win 30, options [nop,nop,TS val 1447370641 ecr 146273257], length 0 15:37:55.986501 IP 100.85.8.35.51414 > 10.66.160.10.80: Flags [.], ack 31314, win 2048, options [nop,nop,TS val 146273267 ecr 1447370641], length 0
端口 51414 双方的三次握手，四次挥手正常，主动关闭，状态到达了TIME_WAIT
-
连接2 → 获取附件类型 (javax.activation.URLDataSource#getContentType)
15:46:02.104543 IP 100.85.8.35.51529 > 10.66.160.10.80: Flags [SEW], seq 3905775205, win 65535, options [mss 1350,nop,wscale 6,nop,nop,TS val 146756153 ecr 0,sackOK,eol], length 0 15:46:02.109936 IP 10.66.160.10.80 > 100.85.8.35.51529: Flags [S.E], seq 4178754812, ack 3905775206, win 28960, options [mss 1350,nop,nop,TS val 1447856746 ecr 146756153,nop,wscale 10], length 0 15:46:02.109978 IP 100.85.8.35.51529 > 10.66.160.10.80: Flags [.], ack 1, win 2048, options [nop,nop,TS val 146756157 ecr 1447856746], length 0 15:46:02.110728 IP 100.85.8.35.51529 > 10.66.160.10.80: Flags [P.], seq 1:212, ack 1, win 2048, options [nop,nop,TS val 146756157 ecr 1447856746], length 211: HTTP: GET /qss_qinvoice_2/XCD0207131700519456520210207131817.pdf HTTP/1.1 15:46:02.114673 IP 10.66.160.10.80 > 100.85.8.35.51529: Flags [.], ack 212, win 30, options [nop,nop,TS val 1447856752 ecr 146756157], length 0 15:46:02.119958 IP 10.66.160.10.80 > 100.85.8.35.51529: Flags [.], seq 1:1339, ack 212, win 30, options [nop,nop,TS val 1447856756 ecr 146756157], length 1338: HTTP: HTTP/1.1 200 OK --------省略一堆数据交互-------- 15:46:32.118875 IP 10.66.160.10.80 > 100.85.8.35.51529: Flags [F.], seq 31313, ack 212, win 30, options [nop,nop,TS val 1447886754 ecr 146756280], length 0 15:46:32.118919 IP 100.85.8.35.51529 > 10.66.160.10.80: Flags [.], ack 31314, win 1579, options [nop,nop,TS val 146785891 ecr 1447886754], length 0
15:46:02 与 15:46:32 间隔30s， ng主动关闭，端口 51529 回复确认，两次挥手完毕后 ，就没其他报文了
-
连接3 → 文件传输 （javax.activation.URLDataSource#getInputStream）
15:46:16.775501 IP 100.85.8.35.51530 > 10.66.160.10.80: Flags [SEW], seq 702643324, win 65535, options [mss 1350,nop,wscale 6,nop,nop,TS val 146770720 ecr 0,sackOK,eol], length 15:46:16.782246 IP 10.66.160.10.80 > 100.85.8.35.51530: Flags [S.E], seq 4286571199, ack 702643325, win 28960, options [mss 1350,nop,nop,TS val 1447871417 ecr 146770720,nop,wscale 10], length 0 15:46:16.782311 IP 100.85.8.35.51530 > 10.66.160.10.80: Flags [.], ack 1, win 2048, options [nop,nop,TS val 146770727 ecr 1447871417], length 0 15:46:16.783570 IP 100.85.8.35.51530 > 10.66.160.10.80: Flags [P.], seq 1:212, ack 1, win 2048, options [nop,nop,TS val 146770728 ecr 1447871417], length 211: HTTP: GET /qss_qinvoice_2/XCD0207131700519456520210207131817.pdf HTTP/1.1 15:46:16.788445 IP 10.66.160.10.80 > 100.85.8.35.51530: Flags [.], ack 212, win 30, options [nop,nop,TS val 1447871425 ecr 146770728], length 0 15:46:16.794242 IP 10.66.160.10.80 > 100.85.8.35.51530: Flags [.], seq 1:1339, ack 212, win 30, options [nop,nop,TS val 1447871429 ecr 146770728], length 1338: HTTP: HTTP/1.1 200 OK --------省略一堆数据交互-------- 15:46:56.148226 IP 100.85.8.35.51530 > 10.66.160.10.80: Flags [F.], seq 423, ack 62625, win 2048, options [nop,nop,TS val 146809754 ecr 1447881200], length 0 15:46:56.154667 IP 10.66.160.10.80 > 100.85.8.35.51530: Flags [F.], seq 62625, ack 424, win 31, options [nop,nop,TS val 1447910789 ecr 146809754], length 0 15:46:56.154742 IP 100.85.8.35.51530 > 10.66.160.10.80: Flags [.], ack 62626, win 2048, options [nop,nop,TS val 146809760 ecr 1447910789], length 0
连接2 端口 51529 ，三次握手正常，只有两次挥手，被动关闭，状态就维持在 CLOSE_WAIT
连接3 端口 51530 ， 双方的三次握手，四次挥手正常，主动关闭，状态到达了 TIME_WAIT
解决方案
前面通过分析找到了问题根源，那我们如何解决这个问题呢
首先想到的就是升级javax.mail的版本，升级之后翻阅源代码，发现问题并没有解决，也许是这个bug之前没有被人发现
那只能自己动手丰衣足食了，首先想到的就是直接实现一个自己的就好了
@RequiredArgsConstructor
public static class FixedUrlDataSource implements DataSource {
private final URL url;
private URLConnection urlConnection = null;
@Override
public InputStream getInputStream() throws IOException {
URLConnection connection = getUrlConnection();
return connection == null ? null : connection.getInputStream();
}
@Override
public OutputStream getOutputStream() throws IOException {
URLConnection connection = getUrlConnection();
return connection == null ? null : connection.getOutputStream();
}
@Override
public String getContentType() {
URLConnection connection = null;
try {
connection = getUrlConnection();
} catch (IOException ignored) {
// ignore
}
return connection == null ? "application/octet-stream" : connection.getContentType();
}
@Override
public String getName() {
return url.getFile();
}
private URLConnection getUrlConnection() throws IOException {
if (urlConnection == null) {
urlConnection = url.openConnection();
}
return urlConnection;
}
} |
实现了DataSource之后，就需要用起来，那就需要再把HtmlEmail的attach()方法重写一下
public static class FixedHtmlEmail extends HtmlEmail {
@Override
public MultiPartEmail attach(URL url, String name, String description, String disposition)
throws EmailException {
try (InputStream ignored = url.openStream()) {
// just to validate the url
} catch (IOException e) {
throw new EmailException("Invalid URL set:" + url, e);
}
return attach(new FixedUrlDataSource(url), name, description, disposition);
}
} |
3077
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
