Nginx" upstream prematurely closed connection while reading response header from upstream"

Posted 2020-11-14 Hello-YOYO

问题背景

　　我们这边是一个基于nginx的API网关（以下标记为A），最近两天有调用方反馈，偶尔会出现502错误，我们从Nginx的error日志里看，就会发现有" upstream prematurely closed connection while reading response header from upstream"这么一条错误日志，翻译过来其实就是上游服务过早的关闭了连接，意思很清楚，但是为什么会出现这种情况呢。而且是在业务低峰出现这种情况（也只是小概率的出现），在业务高峰的时候没有出现这种情况，而且上游服务方（以下标记为B）说出问题的请求他们那边没有收到，也就是没有任何记录，这就比较诡异了。测试环境不知道如何去复现，也就不好排查。

排查过程

　　1、在服务器上开启tcpdump抓包 tcpdump -nps0 -iany -w /tmp/20180617.pcap net [ip] and net [ip]，如果不知道tcpdump怎么使用的同学可以百度一下。

　　2、在nginx的error.log中观察到到有两条" upstream prematurely closed connection while reading response header from upstream"错误日志，分别是2018/06/07 20:41:27和2018/06/08 09:10:46两个时间点，如下图

　　3、然后查看抓包数据，找到了对应时间点的包数据，从这个可以看出，A向B发送了一个1060-2143的包，，而服务端发送了一个Fin断开连接。为什么服务端会断开连接了，我们不得而知。

　　4、上一步A发送包首字节数是1060，那必然前面肯定发送过包，那我们继续往上查，发现了如下图所示的现象。在20:40:22的时候3次握手建立连接并发送了第一个包；而且也查了在20:40:22到20:41:27中间这条长连接没有发送任何包

　　5、和B沟通，他们的Nginx中的keepalive_timeout配置为65秒，keepalive_timeout这个配置的意思是说长连接保持的时间，如果没有任何数据传输的话，超过这个时间，服务端会关闭这个连接。那这就对上了，说明在这65秒没有任何数据传输，也正好在这个点，A向B发送了数据，而B关闭了这个连接，于是就出现了上面的现象。

　　6、当然这是我根据抓包分析出来的结果，我也自己模拟了这种情况，写了一个定时任务，每隔一分钟向第一台nginx发送请求，转发到第二台nginx上。第二台nginx的keepalive_timeout配置为60，在发送第七次的时候，出现了同样的问题，nginx打印同样的错误日志，抓包的结果也和上述情况一致。验证了我上述的分析过程。

问题总结

　　1、如果系统并发量不大，没有必要开启长连接，有两种方式，一、第一台nginx可以去除proxy_http_version 1.1; proxy_set_header Connection "0";这两个配置；二、第二台nginx的keepalive_timeout可以配置为0（默认是75）。

　　2、上述问题我的解决方案是：暂时调大keepalive_timeout的值，先观察，但很有可能还是会有这个问题。

后记

　　1、网络问题的排查过程是很痛苦了，再一次验证了基础知识的重要性。

　　2、偶然报出的问题，一定不要忽视，说不定以后就是系统的瓶颈。