如何准确判断502故障与故障排查一例

我是 LEE,老李,一个在 IT 行业摸爬滚打 16 年的技术老兵。

事件背景

最近得空,重新捡起 502 的事情。跟运维小伙伴沟通后,发现很多业务系统都存在一个“随机” 502 的问题,而且都定位不到问题所在。大团队为这个事情被核心业务组挑战了很长时间,我决定拦下这个事情,看看到底是什么原因,我也非常好奇是什么原因让这么多专家困扰,实际我也想破解下迷题。

现象获取

我们拉取了一个和业务核心网关的 traefik 的转发日志,过滤了下 502 的情况,数量非常少而且只有零星的几个,出现的时间点非常没有规律。

502 状态统计

初步定位异常出现是随机行为,如此我们去检测后端业务的 Pod 状态,发现 Pod 的状态一直稳定,没有在异常时间内出现 Pod 的重启以及其他服务状态的异常的情况。随后再次检查应用 Pod 的日志内容,没有发现任何可疑的日志,甚至 502 出现的时候,应用日志都没有任何输出,证明流量没有到 Pod 内的服务上来,所以导致没有日志输出。

业务组和运维的小伙伴各持一词,都是觉得问题不会出现在自己的这边,最后大家陷入了“僵局”。我也陷入了沉思,为什么会出现这样的问题,都是觉得不是自己的问题,却都找不到强有力的证明方案,而且问题不能 100% 复现,也没有办法解决。

原理分析

在沉思片刻后,我觉得最复杂的问题导致的原因可能最简单,我决定换一个维度来思考这个问题。 既然是 502 的问题,那我们就从 http 协议上去找答案。翻找了一会,果不其然有了突破口。

状态码 IP 端口 响应 描述
502 × × × Bad Gateway - 目标 ip 不可达 (可能是缺少网络、防火墙阻挡)
503 × × Service Unavailable - 目标 ip 可达,但是 port 不可被连接 (可能是防火墙阻挡、服务监听端口没有正常启动)
499 × Client has closed connection - 目标 ip,port 可达,但是没有回应(Response) (可能是防火墙阻挡、也可能是服务端处理的时间过长,客户端“不耐烦”了,先关闭连接)

我们这次要解决的问题是 502 的问题,根据我上面总结的表格,就知道这个问题产生就需要知道几个重要的核心点:

  1. 确定 502 反馈回来的节点,一定是不是最末端的业务 Pod,一定是上层的转发层
  2. 定位断点后,要确认上下游之间的连接关系。因为 http 协议底层还是 tcp 协议,所以 tcp 那些让人烦心的事情还是要考虑起来(比如各种超时)
  3. 确定故障 Ip 为什么不可达的原因,以及触发场景,以及我们是否能够复现

然后与研发组小伙伴沟通,现在都是 HTTP 1.1 的 WebService,没有什么花头。 然后通过跟业务组和运维小伙伴反复确认架构,通过绘图,一步一步复盘可能出现异常的节点。通过结合表格,所有人发现,都是其中业务层的转发 Gateway 到其他的业务的 Pod 会存在这样问题。

既然缩小故障出现的范围,在这个小范围内,我继续归纳可能出现异常点,最后矛头全部指向了中间的 traefik,它极有可能是导致这个问题点。随后我们在对应的测试环境中部署了具备输出 502 异常原因的 traefik。 具体参看《traefik 诡异的 502 排除以及优化》这篇文章

正在大家争论的时候,我在 A4 纸上归总了下疑点:

  1. 业务 Pod 状态正常,没有出现任何异常,测试 Ip + Port 都是可达的
  2. Traefik 的日志中 "DownstreamStatus" 和 "OriginStatus" 都是 502,异常应该是后端 Pod 传入的
  3. 业务 Pod 在异常时,没有出现任何有效日志输出,流量存在可能到与没有到的可行性

其中 1 和 2 在网络层相悖,1 和 3 在业务层相悖

部署魔改的 traefik

通过更换原有业务的 Pod 的 traefik,我们开始监控出现 502 的真实报错原因。 经过一段时间的耐心等待,我们总算在日志检索的时候看到了 502 异常的原因。

502 异常报错

我们看到图片中的 "cause by: EOF", EOF 这个错误表示 Socket 已经在 io 层面到了最后,另一意思是 Socket 已经关闭了。但是 traefik 还在继续使用这个 socket 转发流量,导致出现了 502 的异常。 通过对日志记录的 upstream 的 Ip 和业务 Pod 的 Ip 的对比,确实是同一个 Ip。至此我们确认了出现 502 的原因是 Socket 提前流量在转发情况下关闭了。

502 异常总结

通过上面的图,我们总结下整个事情出现的过程。 Traefik 和 Pod 之间建立了 Tcp 连接 (Http 是基于 Tcp 协议),Traefik 和 Pod 之间使用的 HTTP 1.1 协议,自动被协商了长链接。在完成一轮数据包发送以后,Pod 因为某些原因(这些原因后面会提到)关闭了 Socket,然后在 Tcp 层面向 traefik 发送了 FIN,ACK 包,traefik 接收到了 FIN,ACK 包后, 向 Pod 发送 ACK 响应包,完成了 Socket 关闭动作。此时转发流程上层模块还没有及时更新状态,代转发的数据包继续往这个 Ip 发送。但是在发送的过程中,突然发现这个 Socket 已经关闭了,只能向客户端发送 502 的异常。

会导致 EOF 的可能原因:

  1. 后端服务器可能会突然发送 FIN,ACK 包,主动关闭了 Socket。
  2. 前、后端上配置的 http keepalive 的 idle timeout 时间不匹配,后端时间小于前端时间。

Tcpdump 抓包

为了得到最后的结论,我们在相关的环境中部署了 Tcpdump 抓包来验证整个过程是否正确。 在获得某次异常结果的时候抓包文件后,我看到了复合我判断证据。

502 异常抓包

在上面的 tcpdump 示例中,您可以看到以下内容:

  • Packet 5992, 后端 Pod 收到一个 GET 请求
  • Packet 6064, 响应是 200 OK.
  • Packet 6084, 后端 Pod 收到另一个 GET 请求
  • Packet 6154, 响应是 200 OK.
  • Packet 6228, 后端 Pod 收到第三个 GET 请求
  • 此时, 后端 Pod 返回了一个 FIN,ACK 且开始关闭连接

迷幻的转发链

假如我们在真实业务部署环境中存在这样一条类似的转发链,每一个节点往下转发都有一个 keepalive 的保持(idle timeout)时间(Tn)。

Client --T1--> L7 Proxy --T2--> L7 Proxy --T3--> .... L7 Proxy --Tn--> Pod

根据我们之前分析的内容和结论,我们可以得出这样一串时间表达式:T1 <= T2 <= T3 <= .... <= Tn

从而推到出一个治理理论:全网的转发链条在多层情况下,keepalive 的保持(idle timeout)时间需要全网规划,如果有一个环节出现异常,都会在某处触发 502 的异常出现。

有没有破局的办法呢? 有! 就是 Client 向 Pod 发送“心跳”包,刷新整个转发链中的 http keepalive 的 idle timeout 时间。

处理方法

通过一通复杂的分析与验证后,我这边对团队中小伙伴整体复盘异常,得到最后的结论:

  1. 修正链路上不合规的 http keepalive 的 idle timeout 时间,满足时间表达式
  2. 在代码中加入发送“心跳”包的功能

最终效果

最终拿出了转发中各个 L7 代理的 http keepalive 的 idle timeout 时间,然后逐一的修正,满足上面提到的“时间表达式”,业务组的 Pod 经过 48 小时的运行验证,随机 502 的情况在没有出现。当然还需要心跳”包的配合才能最终治本。

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 214,233评论 6 495
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,357评论 3 389
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 159,831评论 0 349
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,313评论 1 288
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,417评论 6 386
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,470评论 1 292
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,482评论 3 412
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,265评论 0 269
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,708评论 1 307
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,997评论 2 328
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,176评论 1 342
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,827评论 4 337
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,503评论 3 322
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,150评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,391评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,034评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,063评论 2 352