Nginx upstream长连接报错问题排查过程

Unifix
Jun 25, 2021

--

前情提要

我们的海外的跨数据中心使用nginx来充当中间proxy,转发来自终端的请求,proxy到后端使用aws的peering通信,由于是跨了洲际的,所以ping延迟比较高,在160ms+。原来的转发使用的是http短连接,众所周知,短连接需要在每次请求的时候都进行tcp握手,tcp握手需要至少耗掉一次RTT(客户端发syn包,到服务端返回syn+ack,耗时一个RTT,接下来客户端再返回一个ack包,接下来马上客户端会发实际http报文,所以这个ack的耗时应当忽略不计),接下来http报文至少都需要一个发包及一个回包即一个RTT,所以一次请求最少需要两个RTT即320ms+,大量的时间消耗在这个网络链路中,所以我们打算把短连接改成长连接,理论上能把耗时减少到160ms+。

按照方案实施,请求延迟确实得到了提升,但是随之而来的是每天都有少数一些请求报502(bad gateway)错误,接下来本文所记录的就是nginx upstream开启keepalive之后偶现502的排查过程及优化方案

基于nginx 1.11.2源码进行分析

1.表现

通过监测发现,每天的nginx access.log都会报一些502的请求错误,同时error.log也会打一些错误出来,如下

2021/06/24 19:56:41 [error] 3225#3225: *362914597 upstream prematurely closed connection while reading response header from upstream, client: 1.1.1.1, server: app.com, request: "GET /api HTTP/1.1", upstream: "http://10.1.1.1:80/api", host: "xxx.com"2021/06/24 19:56:41 [error] 3225#3225: *362914597 no live upstreams while connecting to upstream, client: 1.1.1.1, server: app.com, request: "GET /api HTTP/1.1", upstream: "http://app/api", host: "xxx.com"

第一条log的意思大概是nginx在等待上游的响应数据时被上游提前关闭了连接;而第二条log的意思是nginx准备向上游发起请求的时候发现没有存活的后端,注意那个带*号的数字`*362914597`,这是一个请求的会话id,这表示这两个log来自于同一个客户端请求的上下文,从目前的信息看报502是由于上游主动关闭连接,同时找不到存活的后端

首先说明一下,在没有开启keepalive之前是没有这种类型的报错的,所以这里的问题基本上大概率跟keepalive有关联,但目前为止还没有什么头绪

2. 遇事不决,tcpdump上路

对于这种网络问题,我习惯从底层开始追溯,在有问题的机器上面跑一个tcpdump任务,然后等待问题的出现,以下是抓到的一些包:

看红框的那条记录,在这个时刻,nginx向上游发了一个包,但就在差不多同个瞬间,只差了几毫秒,上游却返回了FIN包,由于nginx跟上游的延迟在100多ms,所以此时上游应该还没有收到nginx发的包,却主动进行断连

继续看红框这个包的上一条记录,是在差不多65秒之前发送的,也就是说这条连接空闲了65秒左右,看到65这个数字,我基本上知道怎么回事了:默认的nginx.conf里面会配置一个参数,keepalive_timeout,这个参数的值正是65,而我们这个nginx的上游正好也是一台nginx服务,也是说这个上游的服务对http长连接的空闲保持时间默认是65秒,时间一到就主动断开

而如果断开的这一瞬间,如果下游也同时发包,就会造成以上截图的情况,两端同时向对端发包,此进请求发起者会在同一瞬间收到一个FIN包,而以此认为服务端发起关闭,所以nginx在这种情况下会打印出:upstream prematurely closed connection while reading response header

正常情况下,如果nginx与后端的upstream处于同一内网,延迟非常低的情况下,发生这种情况的概率是非常低的,但是我们的情况恰好不同,我们的上下游延迟100多ms,会导致发生这种碰撞的概率大很多

3. no live upstreams的问题

第一条error的原因找到了,接下来还需要看看为什么还会在同一条请求里面打出no live upstreams这种日志

直接撸源码,全局搜一下这句话,只在一个地方出现

ngx_http_upstream.c里面的ngx_http_upstream_connect这个函数

nginx会先调用ngx_event_connect_peer取一个后端地址(注意,此时取的不是可用的socket连接,而是用于连接的地址信息,就是你在upsream里面配的那行server信息),如果返回NGX_BUSY,则打出这个error

接下来重点看为什么rc会返回NGX_BUSY,nginx的upstream机制相当灵活,如果要展开讲就太繁琐了,简要总结一下,当一个客户端请求过来的时候,nginx的upstream模块会为这个请求寻找一个合适的后端地址,然后建立连接,把请求转发过去,然后接收后端响应后再转发给客户端,完成一个请求的闭环,而上面提到的ngx_event_connect_peer的作用正是寻找合适的后端,不过我们知道,如果配置了多个后端,nginx是会执行一定的负载均衡模式的,nginx提供了round robin轮询、least conn最少连接数等好几种模式,如果不在配置文件中指定的话,nginx默认使用round robin,以下简称rr,我们的服务没有特别指定负载均衡模式,所以使用的是rr,接下来看rr是如何寻找合适的后端地址的,rr模块位于:src/http/ngx_http_upstream_round_robin.c,不过看rr之前我们得先看看keepalive模块

是的,因为我们开启了keepalive特性,所以keepalive模块会被加载,keepalive模块会把寻找后端的这个回调设置为自己,优先级高于rr,同时把rr的回调地址保存下来,可以认为keepalive把ngx_event_connect_peer给patch下来,替换成自己,搞了一层warpper,然后里面再调用rr,所以我们先来看keepalive是如何执行的,简单过一下,本文讨论的重点不在keepalive模块

看红框这一行,当nginx向keepalive模块取一个地址的时候,keepalive模块会向调用origin_get_peer,而这个正是rr的回调地址

keepalive先向rr取一个后端地址,取完之后keepalive模块会有一个缓存链表,他把打开过的socket全部保存下来,以此实现对upstream的长连接,向rr取完地址之后会在这个链表里面查找,如果找到某条连接正是这个后端地址的话就从cache链表里面取出来,再把这个连接赋给connection对象,完成连接的分配过程

跟踪代码可以看出,我们遇到的返回NGX_BUSY这个错误码正是keepalive在调用rr的时候返回的,跟keepalive模块本身没什么关系,所以这里先略过keepalive模块,继续看rr,rr模块比较重要,我不截图了,直接用gist贴上源码奉上,首先是ngx_http_upstream_get_peer这个函数,nginx在选取后端的阶段最终调用的就是这段代码,如下:

19行-53行就是rr选取后端的核心过程,for循环rrp的peers列表,这个列表其实就是我们在nginx.conf中配置的upstream后端列表,循环里面会遍历每一个后端,执行一系列判断条件如下:

  • 判断tried字段是否被置位,是的话就略过,而这个tried字段被置位的时机是在第64行,也就是说当rr在同一条请求中如果选中一个后端,就把置位这个字段,作用是避免在同一条请求中如果后端连接错误需要重复多次选取后端的时候不要重复选到同一个后端
  • 接下来判断down字段,我们可以在upstream中给一个server设置down,这时候他就是下线状态,nginx不会调度到他
  • 接下来判断最大重试次数fails字段,这个跟我们在upstream中配置的max_fails字段有关,这个字段在本文场景中很重要,同时这个字段是在一个worker进程中全局共享的,也就是说所有请求都会读写这个fails字段,比如说有一个请求失败了,就把fails加一。在这里会判断fails的次数在一个判断周期内(可由fail_timeout参数配置,默认是10秒)是否已经达到max_fails设置的阈值了,是的话则暂时把这个后端凉到一边,等周期过了再说吧
  • 接下来是给这个后端更新权重
  • 往下,会选择当前权重最高的那个后端

分析到这里,我们主要聚集于tried和fails这两个条件,因为导致NGX_BUSY错误是找不到后端,而遍历结束之后没有发现可用后端是tried或fails这两个条件没满足导致的,进一步缩小排查范围

我们先来说一下fails,fails不满足条件是因为fails大于max_fails,所以必然在代码的某些地方会给filas做加一的操作,这个地方就是:ngx_http_upstream_free_round_robin_peer,当一条请求结束之后,nginx会用这个函数,通知rr要释放这条后端连接了,看如下代码:

看第31行的这个判断条件里面,如果传进来state是失败的话,那么rr就会给这个后端的fails加一,再看第41行,如果fails已经达到max_fails设置的阈值,那nginx会打开一个warn级别的日志:upstream server temporarily disabled,这个日志非常重要,正是这个日志让我确认是fails达到阈值了才报错,不过这个日志是warn级别,默认情况下error.log是没有这行日志的,需要在nginx.conf里面给log选项加上warn设置一下日志级别,再reload一下服务

果然,当出现no live upstreams错误的时候,nginx同时也打出了upstream server temporarily disabled!!

等待,那tried字段呢?容我解释

正常来说,nginx的upsream自动会有一个重试机制,也就是说在一条请求上下文里面,如果当前后端请求出错了,并不会导致这个当前请求出错,而是nginx会尝试向其他后端去重试,重试过程中判断的就是tried这个字段,这个字段是请求上下文里面的局部变量,只对当前请求有效,比如我后端有三个地址,请求一个地址的时候就会把该地址的tried置位,这样当请求失败之后第二次重试的时候就会把重复选到这个后端,可以说是tried+fails共同完成了导致502报错的元凶

4. 复盘502报错过程

  1. 当前请求在向upstream后端等待响应数据的过程中被主动断开
  2. 当前请求上下文把这个后端的tried置位,然后判断错误原因,非404之类的错误就统一认为是NGX_PEER_FAILED,这种情况下这个后端的fails会被加一,然后打印一下错误原因,比如上文提到的upstream prematurely closed connection
  3. 接下来,nginx会再次尝试找到可用后端,就重新进入到ngx_http_upstream_get_peer,查找tried还没被置位,同时fails还没达到阈值,就用这个后端继续发起连接
  4. 如果所有后端都已尝试过且fails都达到阈值了,则直接抛出NGX_BUSY,日志报no live upstream,无可用后端,直接向客户端抛出502错误
  5. 我们在使用长连接过程中报502主要是上游在特定时间点会主动关闭连接(超过空闲时间,或者更新应用的时候会释放所有长连接),这种情况下会导致nginx进入重试阶段,这个阶段其实还不至于抛出502
  6. 当上游同时主动关闭多个连接的时候,有可能导致这个里的nginx的多个请求都被主动关闭,而导致多个后端地址的fail被加一,默认情况下,我们没有配置max_fails,所以默认是1,即只要有一个后端主动关闭连接并且nginx刚好在向对端发送数据导致错误,那个这个后端地址就会达到fails阈值,上文说过,这个fails是进程内共享的,所以另的请求的报错有可能影响到我当前请求的判断,认为这个后端不可用
  7. 当所有后端都发生了fails达到阈值的情况,那nginx就认为后端挂了,直接抛出502

5. 解决方案

知道原因之后,现在来想解决方案了,由于上游的集体主动断连是不可避免的,所以能做的就是改变当前nginx的行为

  1. 设置一下max_fails参数,把这个值设得略高一点,这个需要结合服务日常qps,如果设得太高反而会把真正有问题的后端错误给忽略掉,所以我们把这个值设置到合理大小
  2. 如果设置了max_fails,而上游的断连势汹汹,那还需要一个兜底方案,尽量让nginx多尝试几次,不要直接抛出502,这种情况下我想到的方案是增加back后端组,同时把这组参数设成跟主力的后端组一致,nginx在判断到所有后端都挂掉之前其实他会判断我们有没有配置back备份的server,如果有的话还会继续尝试连接back servers,我把back server设置到同一组后端,等于说多了一个重试步骤
  3. keepalive空闲连接数参数也要设置到合理范围,如果设得太小,则空闲连接会被很快地释放掉,主动释放会导致端口进入time_wait,qps高到一定程度的时候time_wait端口数量爆满会带来更严重的问题;也不能设得太高,设得太高一定被上游集体断连的话,会更快地让fails达到max_fails的阈值,所以这个值也是需要根据实际运营场景去调整的
  4. 调完这些参数之后重新观察服务,发现502的问题得到解决,error.log依然会打印upstream prematurely closed,但不影响服务

6. 经验总结

其实一开始发现这种错误的时候首先尝试去google搜索别人遇到的类似问题,但是通常这并不会马上就找到想要的答案,每个人遇到的场景不同,即使问题表现是一样的,但是内因可能大相径庭,找不到想要的答案是很正常的。而解决问题的思路就显得很重要了,比如从抓包观察入手,再从源码寻找复现条件,都是极其重要的手段

--

--

Responses (1)