捉虫笔记 3 则(2016.05)
更新日期:
最近的工作中,突然出现很多奇怪的bug,本文记录其中的3则。本文以真实的问题为蓝本,但并非百分百原样描述。
问题1:Tomcat 的 CLOSE_WAIT 状态的连接过多
问题现象
项目中的一个系统,即将第一版上线,时间压的比较紧,半个月前刚刚发布到 UAT 环境。除去一些业务上的 bug 不提,发现一个很诡异的现象:系统的一个模块在工作2天之后连不上了。
经过检查,发现是服务器后台 TCP 连接有很多处于 CLOSE_WAIT 状态。问题短时间内无法查明,于是决定重启应用,不耽误测试进度。第二天,问题重现,无解,重启,第三天,仍然重现,周而复始。
完全不知问题所在,一筹莫展。
问题原因
开始怀疑是 Tomcat 的keepAliveTimeout
或connectionLinger
相关参数设置有问题,导致 HTTP 连接长时间没有释放,但实际上并不是这个原因。
系统的大致架构是这样,共有2个应用,A 应用对外提供 REST 访问;B 应用对内提供 REST 访问,同时,B 应用上连接了很多 ActiveMQ,用于请求其他系统的数据。A、B 应用和 MQ 均部署在同一服务器上。
真正的原因是,实际上的多个 CLOSE_WAIT 状态是因为连了很多 tcp://xxxxxxx
的MQ造成的。细节是这样,A 应用的一个访问请求,通过 REST 访问 B 应用,再通过 B 上的 MQ 去获取外部的数据,B 在请求外部数据的时候,使用了 responseQueue.poll()
这样的写法来异步等待 MQ 的返回(别问我为什么不用同步的请求,外部的接口就只能提供这些)。因此,在外部系统处理发生异常的时候,该消息就永远不会返回,而可怜的 B 应用只能傻傻在那里等,并耗费一条 Tomcat 的线程,A 应用则因为 REST 请求超时,早早收回了资源,进入了 TCP 所谓的半关闭状态。
如果仅仅如此的话,请求不会返回,我们应该也能很快发现这个问题。实际上,奇葩的是,来自 A 应用的这个请求是一个定时请求,每隔一段时间请求一次,如果取不到数据,就用前一次的数据返回。更奇葩的是,MQ 另一端的数据提供方并不是每次都会产生错误,前几次数据请求是返回正常的,后几次会发生问题。更更奇葩的是,数据提供方的这个数据并没有经常变,在生产环境中该数据变动频率会比较高,但是在测试环境,可能没去造数据,每天的数据都一样。种种特例情况导致了我们开始查问题的时候根本没去往这个方向想。
问题解法
改为使用 responseQueue.poll(timeout, timeUnit)
这样的写法来异步等待 MQ 的返回,最多等待 30 秒,如无返回直接超时。修改代码总量仅3行。
问题2:HTTPClient 遇到 Connection Reset
问题
问题现象
还是这个项目,在上一个新版之后,发现原先能用的 HTTPClient 请求,无法请求到了,客户端提示的异常中有 Connection Reset
。
问题原因
有了之前那个 CLOSE_WAIT 问题的经验,在查这个问题的时候,对 TCP、HTTP 什么的已经有一些经验了。造成这个问题的原因基本上是,TCP 的一端(通常是服务器端)在向另一端写数据的时候,在数据尚未写完的时候,就强行关闭了连接,导致发的数据不全。类似的原因还可能提示 BROKEN PIPE
这样的错误。
多数情况下,该连接的服务器端应该在打开 socket 连接的时候启用了 SO_LINGER
这样的参数,并设置 linger=0
,对 Tomcat 来说,就是设置了 connectionLinger=0
。但是仅仅这样,仍然不足以产生这样的问题,问题是在 HTTPClient 连接的时候,设置了 HTTP Header 参数 Connection: close
,默认情况下,该参数是 Connection: keep-alive
,表示请求完之后,不立即关闭 TCP 连接,如果马上还有 HTTP 连接的话,可以继续使用这条连接,如果该参数值是 close,那就表示立刻关闭。正因为有 Connection: close
和 connectionLinger=0
的配合,才导致了一请求完成,立刻关闭连接,并且不等待数据发送完毕,因此造成 TCP 数据包不完整。
问题解法
删掉使用 HTTPClient 的时候设置的 HTTP Header Connection: close
,即这一行 webClient.replaceHeader("Connection", "close");
。修改代码总量仅1行。
问题3:Chrome 在 POST 或 PUT 比较大的数据包时,提示 net::ERR_SSL_PROTOCOL_ERROR
问题现象
还是这个项目,使用 Chrome 浏览器测试,在 POST、PUT 少量数据的时候,系统正常;当 HTTP 数据包大于 8k(近似值)的时候,提示 net::ERR_SSL_PROTOCOL_ERROR
。系统采用 HTTPS 协议。
这是一个很诡异的问题,在开发测试环境没有发生,在 UAT 环境发生了。首先怀疑是操作系统和依赖库的原因,查了一遍,无果。使用旧版的浏览器没这个问题,但是新版的有;使用其他浏览器提示的信息不一致,FireFox 没有提示,仅仅是空返回,某国产浏览器提示 Connection Reset
。总之,找不到该问题必然发生的条件。
问题原因
其实,HTTPS 背后的 SSL/TLS 协议是有分版本的,做 Java 的可以参考这个。对 Tomcat 来说,有以下一些版本可以设置(sslEnabledProtocols
参数),SSLv2、SSLv3、TLSv1、TLSv1.1、TLSv1.2、SSLv2Hello。我们设置的是 sslEnabledProtocols="TLSv1,TLSv1.1,TLSv1.2,SSLv2Hello"
在服务器端启用了这么多 SSL/TLS 协议版本的时候,浏览器在访问的时候会先握手,以确定要用哪个版本的协议(我猜这部分应该是明文),最后会选择一个服务器和浏览器都支持的协议版本,如果符合要求的协议版本有多个,应该会选择版本最高的那个(不确定是不是最高版本)。
我们的问题发生在库文件上,服务器和浏览器在握手阶段,判定使用 TLSv1.2 协议是没问题的,于是接下来使用该协议。但是,实际上该协议在服务器端的实现有 Bug,不能处理超过 8k 的包,因此就会报错 net::ERR_SSL_PROTOCOL_ERROR
,Chrome 的报错还是比较准确的。为什么不怀疑是浏览器的问题,因为 Chrome、FireFox、IE 都有问题,所以应该是服务器的问题。但是,具体这个问题是发生在 OpenSSL、JDK、还是 Tomcat,就不得而知了,OpenSSL 1.0.1p、JDK 1.8.0_66、Tomcat 8.0.32。
该问题在以下一些场景必然不会发生,
- OpenSSL 0.9.8 版本,只要是 0.9.8 这个大版本就不会有这个问题,因为 OpenSSL 的这个版本不支持 TLSv1.2(参考这里),所以握手的时候不会选到这个协议;
- 老的浏览器,比如 Chrome 27,这么老的浏览器还不支持 TLSv1.2,因此也选不到 TLSv1.2;
问题的发现是采用 FireFox 中的隐藏参数 security.tls.version.max
,限制浏览器可选的 TLS 协议版本,可以参考这里。
问题解法
将 Tomcat 中的参数改为 sslEnabledProtocols="TLSv1,TLSv1.1,SSLv2Hello"
。修改代码总量仅8个字符。
问题遗留
虽然找到的解决方法和可能的原因,但是仍然没有最终解决这个问题。因为同样的操作系统、库、JDK、Tomcat,在开发测试环境就没有碰到这样的问题,这个还没有找到解释。
总结
问题的修改可能很简单,但是问题本身可能很复杂(当然,对大牛来说,这都是简单问题),需要坚实的基本功才能找到问题,对症下药。