美文网首页
NoHttpResponseException: xxx fai

NoHttpResponseException: xxx fai

作者: coderljx | 来源:发表于2022-11-01 17:58 被阅读0次

    问题

    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:


    image.png

    开启wireshark进行抓包,执行程序直到下图出现即可停止

    image.png

    重点看左下角的红色框,时间相差65秒左右,没错从而可以得知底层服务器的keep-alive 是 65秒,也就是当一个连接socket 65秒内没有数据交互,底层服务器就会认为这个连接可以关闭了,因此才会在3分36秒进行挥手操作发送一个FIN包,这时我们稍微改造一下这个程序,如下:


    image.png

    相比第一个,有两个改动

    加了一个循环
    每次调用的间隔改成和底层服务器相同的65秒
    我们清空wireshark,运行该程序抓包,结果如下:


    image.png

    问题分析

    image.png

    红色框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日志


    image.png

    通过仔细分析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,进行代码定位

    image.png image.png

    基本上定位到了PooingHttpClientConnectionManager.java这个类,那么进行代码跟踪吧

    image.png

    追踪到了 AbstractConnPool.java类,那么这段代码什么意思呢,这个就是进行连接是否能够复用的检查代码

    对validateAfterInactivity进行判断,这个是服务器keep-alive的值

    leasedEntry.getUpdated() + validateAfterInactivity <= System.currentTimeMillis():如果连接的最后一次使用时间 + 服务器keep-alive的时间 小于等于当前时间,那么就认为该连接可能已经失效了
    !validate(leasedEntry): 因此会进行连接是否失效的检查
    跟进去看看

    image.png

    最终找到"end of stream" and "[read] I/O error: Read timed out" 打印的地方
    然后回到如下图代码:

    image.png

    可以看到

    当bytesRead 值为 -1 时,返回true,那么HttpClient就会认为该连接失效了,不能够复用,并进行清理操作,
    当抛出异常是ShockTimeoutException时会返回false, 那么HttpClient就会认为该连接可复用

    解决方案

    禁用HttpClient的连接复用(有点扯淡)
    重试方案:http请求使用重发机制,捕获NohttpResponseException的异常,重新发送请求,重发3次后还是失败才停止
    根据keep Alive时间,调整validateAfterInactivity小于keepAlive Time,但这种方法依旧不能避免同时关闭
    系统主动检查每个连接的空闲时间,并提前自动关闭连接,避免服务端主动断开
    推荐使用重试方案

    相关文章

      网友评论

          本文标题:NoHttpResponseException: xxx fai

          本文链接:https://www.haomeiwen.com/subject/tcwjtdtx.html