排查一次线上connect reset by peer的异常

发表于 | 分类于 阅读次数:

公司业务系统中有一个功能是某个系统客户端要定时加载目标jar包到系统中实现功能的热扩展，线上出了一个很奇怪的异常，是jar包提供端出现了connect reset by peer，隔一段时间就会报异常
并且业务功能并没有受到影响，但是毕竟是生产环境，一点错误都有可能造成损失，问题还是要看的啊

首先定位问题，该异常由jar包提供端抛出，jar删除后便不再抛出，由此基本可以缩小范围至客户端加载jar包代码，但是光看代码似乎并没有什么大的问题
所以我需要看看服务端抛异常的时候究竟在干什么，这里就用到了tcpdump，用这个工具将服务端的tcp日志打印出来

服务端部署在docker容器中，首先使用nsenter将命名空间锁定到容器的pid

1
2
3
4
5
6
//获取容器id/name
docker ps | grep xxx
//获取PID
docker inspect --format "{{.State.Pid}}" container_id/name
使用nsenter切换网络命名空间
nsenter -n -t pid

之后查找客户端所在的ip地址，也就是tcpdump中要用到的host信息，我们要锁定查找范围为服务端到客户端之间的所有连接

使用命令
tcpdump host 你的host -w tcphistory.pcap

如果没问题的话，那么这个进程将持续把tcp的日志写入到tcphistory.pcap文件中

现在开始等待服务端日志抛出connect reset by peer异常，抛出后使用ctrl+c结束tcpdump命令

之后我们打开tcp日志分析的一个软件，叫做wireshark，我们惊奇的发现，抛出异常的时候有很多tcp连接在关闭了

客户端的tcp连接集中的发送reset包到服务端，于是我去了解了下在tcp什么情况下会发送reset包

1
2
3
4
5
1.客户端尝试与服务器未对外提供服务的端口建立TCP连接，服务器将会直接向客户端发送reset报文。
2.客户端和服务器的某一方在交互的过程中发生异常（如程序崩溃等），该方系统将向对端发送TCP reset报文，告之对方释放相关的TCP连接
3.接收端收到TCP报文，但是发现该TCP的报文，并不在其已建立的TCP连接列表内，则其直接向对端发送reset报文
4.在交互的双方中的某一方长期未收到来自对方的确认报文，则其在超出一定的重传次数或时间后，会主动向对端发送reset报文释放该TCP连接
5.有些应用开发者在设计应用系统时，会利用reset报文快速释放已经完成数据交互的TCP连接，以提高业务交互的效率

用排除法，显然在我们的情境中是第二种情况

于是我去查找客户端的日志，似乎没有发现什么异常
难道就这样结束了吗，不不不
进入客户端容器
利用名令netstat查看当前的的tcp连接，发现有一大票CLOSE_WAIT的TCP连接，说明服务端已经将数据写入完毕了，发送了FIN报文，但是好嘛，客户端不知道是什么在持有连接不放，让连接一直在等待
结合tcpdump下来的日志，看起来是在客户端在集中释放资源，是跟什么有关系呢，我想到了GC
于是我调出了客户端的gc日志，发现果然时间跟释放连接的时间有关系
所以仔细搜寻了代码，发现在一个工具类中有使用HttpClient，每次发送请求都会创建一次Client的对象，使用完没有主动调用close()方法，似乎症结找到了
做了一下优化，查阅资料发现4.x的HttpClient是线程安全的，可以作为静态的成员变量来复用，于是改造完成后测试

嗯，connect rest by peer依旧出现，但是好消息是CLOSE_WAIT消失了，连接数量似乎稳定了下来，解决了一个隐藏的问题，继续查

查到了下面一串代码

1
2
HttpURLConnection urlConnection = (HttpURLConnection) url.openConnection();
long astModified = urlConnection.getLastModified();

于是在本地尝试复现该问题

1
2
3
4
HttpURLConnection urlConnection = (HttpURLConnection) url.openConnection();
long astModified = urlConnection.getLastModified();
//强制关闭该连接
urlConnection.disconnect();

复现成功，经查阅资料，由于文件相对较大，方法getLastModified()方法中是去拿http请求头中的参数，所以，在tcp的第一个window中传输数据的数据就已经满足了程序，就没有继续读下面的流，于是在GC的时候urlConnection被关闭了，而服务器正在写入这个流，所以就出现了connect reset by peer，尝试如果是小文件，则第一个window就已经把所有数据都传输回来了，则不会出现connect reset by peer，tcp的window相当于一个缓冲区，缓冲区满了回去刷新，然后再次写入

所以将流消费完毕，即可解决问题

1
2
3
4
InputStream inputStream = urlConnection.getInputStream();
InputStreamReader inputStreamReader = new InputStreamReader(inputStream);
BufferedReader bufferedReader = new BufferedReader(inputStreamReader);
bufferedReader.lines().forEach(l -> {});

虽然不是很优雅，但是也是解决了问题

总结一下，这次排错发现了两个问题

  1. 4.x的HttpClient是线程安全的，并且是可复用的，如果没有复用，在调用完HttpClient时记得close掉这个对象，不然会出现连接占用的问题
  2. HttpURLConnection如果不想让服务端出现异常，需要将流消费完毕，也就是让服务端把数据写完，才可以关闭这个连接