问题
HttpClient偶尔报NoHttpResponseException: xxx failed to respond
feign.RetryableException: xxx:80 failed to respond executing POST http://xx
复现方法
google得知,这个只会在服务器端keep-alive刚好过期的时间我们进行访问才能大概率复现,方法如下:
wireshark进行抓包得出底层服务器的keep-alive时间
写一段程序,用于探测底层服务器的keep-alive:
开启wireshark进行抓包,执行程序直到下图出现即可停止
重点看左下角的红色框,时间相差65秒左右,没错从而可以得知底层服务器的keep-alive 是 65秒,也就是当一个连接socket 65秒内没有数据交互,底层服务器就会认为这个连接可以关闭了,因此才会在3分36秒进行挥手操作发送一个FIN包,这时我们稍微改造一下这个程序,如下:
相比第一个,有两个改动
加了一个循环
每次调用的间隔改成和底层服务器相同的65秒
我们清空wireshark,运行该程序抓包,结果如下:
问题分析
红色框1:前3个请求是建立连接的过程,三次握手,接着4个请求就是client和server的数据交互,着重看最后四个请求
9012 -> 59233 [FIN, ACK]:服务器主动进行关闭,给client发送了FIN包
59233 -> 9012 [ACK]:client进行回应ACK包
69233 -> 9012 [FIN, ACK]:按照四次挥手原则,client发现目前数据已经发送完毕了,因此也发出FIN包
9012 -> 59233 [RST]:服务器直接返回一个RST
红色框2:同2
红色框3:前面的7个步骤都是相同的,建立连接,数据交互,区别唯独在于绿色框
9012 -> 59233 POST /hy/json: client认为服务器端可用,因此给服务器发送数据
9012 -> 59233 [FIN, ACK]:服务器认为此连接已经失效,因为超过了65的keep-alive时间,主动进行关闭,给client发送了FIN包
59233 -> 9012 [ACK]:client进行回应ACK包
69233 -> 9012 [FIN, ACK]:按照四次挥手原则,client发现目前数据已经发送完毕了,因此也发出FIN包
9012 -> 59233 [RST]:服务器直接返回一个RST 通过Seq=188,可判断这条是给【9012 -> 59233 POST /hy/json】这个请求回的
9012 -> 59233 [RST]:服务器直接返回一个RST 通过Seq=189,可判断这条是给【69233 -> 9012 [FIN, ACK]】回的
9012 -> 59233 [RST]:服务器直接返回一个RST 通过Seq=189,同6
通过分析抓包数据,得出结果是,当client客户端认为这条Socket连接有用,这时服务器端却认为该Socket连接无用,并主动关闭,就会报错,属于临界值没有处理好的
这时有人就说了,为什么前两次就没有问题呢,原因是HttpClient会进行连接过期是否可用的检查,那么也就能理解这是httpclient的一个bug,即使httpclient有做这么一件事情,但是由于网络I/O原因,导致httpclient认为一个关闭了的连接是有效的,才报了这个错误。
HttpClient为什么会复用一个已经被关闭的连接
开启debug日志
通过仔细分析HttpClient打印的debug日志,可发现左边正常交互日志 打印了一串 "end of stream" 后进行了连接的重新建立, connection established ,而右边错误日志打印了一串 "[read] I/O error: Read timed out" 后没有进行连接的重新建立,因此就报错了
那么可以通过打印 "[read] I/O error: Read timed out"日志的上下文日志缩小 排查代码的范围,上文日志 Connection request,下文日志 Connection leased,进行代码定位
基本上定位到了PooingHttpClientConnectionManager.java这个类,那么进行代码跟踪吧
追踪到了 AbstractConnPool.java类,那么这段代码什么意思呢,这个就是进行连接是否能够复用的检查代码
对validateAfterInactivity进行判断,这个是服务器keep-alive的值
leasedEntry.getUpdated() + validateAfterInactivity <= System.currentTimeMillis():如果连接的最后一次使用时间 + 服务器keep-alive的时间 小于等于当前时间,那么就认为该连接可能已经失效了
!validate(leasedEntry): 因此会进行连接是否失效的检查
跟进去看看
最终找到"end of stream" and "[read] I/O error: Read timed out" 打印的地方
然后回到如下图代码:
可以看到
当bytesRead 值为 -1 时,返回true,那么HttpClient就会认为该连接失效了,不能够复用,并进行清理操作,
当抛出异常是ShockTimeoutException时会返回false, 那么HttpClient就会认为该连接可复用
解决方案
禁用HttpClient的连接复用(有点扯淡)
重试方案:http请求使用重发机制,捕获NohttpResponseException的异常,重新发送请求,重发3次后还是失败才停止
根据keep Alive时间,调整validateAfterInactivity小于keepAlive Time,但这种方法依旧不能避免同时关闭
系统主动检查每个连接的空闲时间,并提前自动关闭连接,避免服务端主动断开
推荐使用重试方案