关于nginx:警惕Nginx-ingress就这么挂了

当下越来越多的企业正在拥抱 k8s，如笔者公司根本所有服务都已容器化部署。

容器化场景下，ingress 是一种通过 http 协定裸露 k8s 外部服务的 api 对象，也就是说 ingress 是 k8s 集群所有服务的拜访入口。基于 ingress 的流量拜访链路如下图所示：

ingress 解决方案不少，k8s 默认举荐的是 Nginx Ingress，这也是本篇文章的配角。

7.18 号早晨 21 点左右，笔者正在小区楼下跳绳（中年码农大肚子危机），看到工作群反馈有业务早晨 19 点左右呈现大量 504。业务同学和 SRE 进行了初步排查剖析，19 点左右业务有发版，发现问题后也执行了回滚操作；排查发现 Nginx ingress 转发申请到了不存在的 pod IP。难道是 Nginx ingress 同步上游节点 IP 有异样，期间也重启了上游服务，问题未解决，19 点 30 分左右，业务复原。

查问 Nginx ingress 拜访日志，18 点 49 分业务开始呈现 504，申请响应工夫 5 秒（proxy_connect_timeout 5s），Nginx ingress 返回 504。另外，18 点 49 分之前（HTTP 200）申请的上游服务 IP，与 18 点 49 分之后（HTTP 504）申请的上游 IP 雷同。

18 点 49 分业务服务出现异常了？容器同学查问监控发现，该服务在 18 点 49 分从新调度了，也就是说，18 点 49 分上游服务的 IP 曾经变了，老的 IP 地址不可拜访了，所以服务才呈现 504。

kibana 查问 7.18 号 19 点左右拜访日志，发现不止这一个服务 504，还有一个服务也呈现大量 504，而且景象完全一致。两个服务都是 19:31 分左右复原。

pod 已从新调度，Nginx ingress 为什么没有更新上游服务 IP？

查找线上环境 nginx-ingress-controller 日志，发现日志采集（多种日志格局采集到一个 topic，解析时可能抛弃了局部日志）有些问题，kibana 查问不到无效日志。排查陷入僵局。

因为之前素来没有接触过 Nginx ingress，也不理解其配置同步逻辑，7.19 号决定简略钻研下 Nginx ingress 底层原理，以备不时之需。

github 地址为 https://github.com/kubernetes…。服务启动后，蕴含两个过程：1）nginx-ingress-controller 过程基于 Golang 实现，负责监听 k8s ingress 资源，转换生成 nginx.conf 配置文件；2）nginx 过程其实就是 openresty，另外还基于 lua 提供本地接口，用于更新上游服务 IP。

6 www-data 13h34 /nginx-ingress-controller --configmap=default/nginx-test-config --ingress-class=nginx-test
68 www-data  0:15 nginx: master process /usr/local/nginx/sbin/nginx -c /etc/nginx/nginx.conf

nginx-ingress-controller 同步的配置次要能够分为上面两类：

ingress 规定，须要转化为 server + location 配置，而且须要留神的是，所有服务的 ingress 配置最终转换合并到一个配置文件 nginx.conf，导致这个文件十分大，个别至多几十万行。另外，这类配置的变更是须要 reload nginx 过程的。
上游服务 IP，nginx-ingress-controller 监听 endpoints，并通过本地接口告诉 nginx 过程，更新上游服务 IP 地址（http://127.0.0.1:10246/config…）。

查看 nginx.conf 配置，configuration 接口拜访日志没有关上，无奈确定过后 nginx-ingress-controller 有没有通过这个接口更新上游 IP。

另外因为日志采集问题，也无奈查看 nginx-ingress-controller 日志，7.18 号问题，只能靠猜想了。。。只是心里隐隐有点好奇，为什么两个服务都是在 7.18 号晚 19:31 恢复正常？那一时刻产生什么了？难道这起 case 是容器平台造成的？

7.21 号中午 12 点左右，测试容器平台和网关平台白屏，调试发现，前端某动态资源获取异样，前端搭档排查修复。

7.21 号下午 14:10 分，反馈容器平台和网关平台前端所有接口申请全副 502。kibana 查问网关日志，发现全副是 Nginx ingress 返回 502。

502 不是网关造成的，持续帮助容器团队排查吧，毕竟网关团队在剖析 5xx 问题是比拟有教训的。登录测试环境 Nginx ingress 所在节点（还好之前排查问题申请过节点权限，而 ingress 拜访日志 kibana 貌似没有采集），grep 异样服务拜访日志。

7.21 号下午 15 点左右，初步确定起因，与 7.18 号状况相似，Nginx ingress 申请的上游服务 IP 是谬误的。

//error 日志如下
connect() failed (113: host is unreachable) while connecting to upstream, upstream: http://xxxx:80/

//access 日志记录了上游服务的 ingressName，serviceName

// 查问上游服务 endpoints
kubectl get endpoints xxxx -n xxxx

上游服务的 IP 为什么又是谬误的？nginx-ingress-controller 配置同步有异样了？那好吧，重启下上游服务试试。

重启了两次，还是没有复原，502 异样。

7.21 号下午 15:10 分左右，既然曾经确定 nginx-ingress-controller 同步配置异样，要不重启下 Nginx ingress？即便配置比拟多，实践上分钟内也能够重建配置。（预先证实，实践果然只是实践）

7.21 号下午 15:15 分重启两个 Nginx ingress 节点，重启胜利后，故障彻底扩散了，大量服务 404。（PS 这时候还被业务方调侃了，通过两小时的致力，502 变 404 了）

404 大概率是丢了配置，网关查问 404 域名，查看 Nginx ingress 配置文件 nginx.conf，发现两个配置文件都失落了局部域名配置。

这些域名的 ingress 丢了？然而查问发现 ingress 失常啊，而且查看 nginx-ingress-controller 启动日志（记录所有资源变更事件），的确获取到了该域名的 ingress，为什么会失落配置呢？是不是重启异样了？要不然再重启一次。

再看看 Nginx ingress 节点监控，发现一个节点负载十分高，难道是这个起因吗？

工夫曾经到了下午 16 点多了，重启下 Nginx ingress 节点吧，数分钟后，节点重启胜利，Nginx ingress 服务重启胜利。

7.21 号下午 16:30 分左右，业务根本恢复正常，然而还存在局部 404 申请，发现申请都是在另一个节点（未重启节点）上，网关批改 upstream，摘掉该节点，业务完全恢复。

一个下午就这么大惊失色的度过了，而事变的起因仍然未知。。。

7.21 号测试环境故障仍然是一个迷，预先想想和 7.18 线上问题十分相似。另外，为什么 Nginx ingress 重启会失落大量配置呢？下次要再产生相似的问题怎办么？仍然大刀阔斧吗？

只能再去深入研究 nginx-ingress-controller 配置同步逻辑了。

//ingress-nginx/internal/ingress/controller/controller.go

func (n *NGINXController) syncIngress(interface{}) error {
    // 获取所有 ingress 规定
    ings := n.store.ListIngresses
    
    // 配置转化，包含上游 IP 配置
    pcfg := n.getConfiguration(ings)
    
    if 非纯 upstream 节点变更 {klog.Infof("Configuration changes detected, backend reload required.")
        
        // 更新 nginx.conf
        if 更新失败 {klog.Errorf("Unexpected failure reloading the backend:\n%v", err)
            return err
        }

        klog.Infof("Backend successfully reloaded.")
    }
    
    // 更新 upstream 节点配置（接口方式）if 更新失败 {klog.Warningf("Dynamic reconfiguration failed: %v", err)
    }
}

同步配置都有记录具体的日志，7.21 号测试环境能够查问日志，那一条一条日志搜寻呗。此时也发现原来日志已采集，能够在 kibana 搜寻。

果然，搜寻到了大量的 ”Configuration changes detected, backend reload required”，而后搜寻对应的 ”Backend successfully reloaded” 却只有寥寥几条日志。那就是更新配置失败了，再搜寻 ”Unexpected failure reloading the backend”, 果然有很多。然而这条日志前面的换行符是什么鬼，err 关键词到底是什么，该怎么搜寻。

细化工夫线，放宽筛选条件，一条一条日志找找看，果然，找到了对应的错误信息：

nginx: [emerg] "underscores_in_headers" directive is not allowed here in /tmp/nginx-cfg185859647:251712

原来是 nginx.conf 语法错误，而且所有 ingress 配置会打包为一个配置文件，只有呈现语法错误，那么所有后续所有 ingress 变更，以及 upstream 变更，都无奈同步。

这是什么配置，为什么会语法错误呢？看一下这个配置的官网阐明，以及生成 nginx.conf 的模板：

Syntax:    underscores_in_headers on | off;
Default:    
underscores_in_headers off;
Context:    http, server
// 只能配置在 http 以及 server，不能配置在 location

// 模板
http {underscores_in_headers          {{ if $cfg.EnableUnderscoresInHeaders}}on{{else}}off{{end}};
    
    // 生成 server 配置
    {{range $server := $servers}}
    server { }
    {{end}}
}

出问题的配置 underscores_in_headers 只在模板里 http 配置块有啊，只能是转化 ingress 生成 server 时引入的，而且肯定是在 location 配置块引入的。

更改 nginx.conf 配置还有两种形式：1）批改 configmap，查看了下 configma 配置，没有异样，而且这个个别不会变更，临时跳过；2）ingress 变更引起，大概率就是了。

那么到底是哪一个 ingress 引入的呢？按关键字 ”underscores_in_headers” 搜寻 7.21 号下午日志，忽然发现在 14 点出问题之前，就有大量报错。扩充搜寻工夫范畴，发现语法错误在 7.21 号 11:57 就呈现了。

既然确定了 7.21 号 11:57 第一次呈现语法错误，而且这个语法错误必定是 ingress 变更引起的，那么只须要查找 ingress 变更记录就行了。找一个测试服务，关上浏览器调试模式，提交 ingress 变更，抓到接口地址，kibana 搜寻 11:57 分左右的 ingress 变更日志。

还真找到了，7.21 号 11:57 分有业务编辑 ingress，提交配置如下：

nginx.ingress.kubernetes.io/configuration-snippet":"underscores_in_headers on;"

原来是通过注解形式引入的。查看官网文档对这个注解的解释：

//using this annotation you can add additional configuration to the NGINX location. For example:

yaml
nginx.ingress.kubernetes.io/configuration-snippet: |
  more_set_headers "Request-Id: $req_id";

终于上不着天; 下不着地了，这个注解的配置会生成在 location，而恰好 underscores_in_headers 是不容许呈现在 location 的！

再扩充工夫范畴，搜寻这个 ingress 的变更记录，7.21 号下午 16:30 分变更，删掉了这个注解。原来如此，16:30 分故障复原也是一个偶合！至于 16:30 分后还呈现局部 404，是因为另一个节点没有重启，事件处理是有序串行的，之前解决异样的事件还在生产，即便不摘除过一会也会复原的。

至此，水落石出。

7.21 号问题算是搞清楚了。那么 7.18 号线上问题呢，是否也是如此？连忙查问线上日志，可怜的是日志曾经革除，kibana 也查不到了。

侥幸的是，想起来机器上个别还会压缩存储钱前几天的日志。网关也就 10 个节点左右，一个节点一个节点登录看一下呗。这里查什么呢？仍然是无奈查问 nginx-ingress-controller 的日志，然而还记得不，7.18 号晚 31 分两个服务同时复原，那么如果问题同测试环境，肯定是那一时刻 ingress 变更导致的复原。

历尽千山万水，终于找到了日志：

//2022-07-18T19:31:53+08:00，找到一条 ingress 变更记录；// 参照 ingressName，查找 7.18 号 19 点之前变更历时
//2022-07-18T18:29:51+08:00
"nginx.ingress.kubernetes.io/proxy-next-upstream":"on"

Syntax:    proxy_next_upstream error | timeout | invalid_header | http_500 | http_502 | http_503 | http_504 | http_403 | http_404 | http_429 | non_idempotent | off ...;
Default:    
proxy_next_upstream error timeout;
Context:    http, server, location

proxy_next_upstream 配置的值不是简略的 on！就是他导致的上游 IP 同步失败，而 7.18 号晚 19 点左右，恰好有两个服务从新调度了，IP 扭转了，所以才 504。

这么看来，7.21 号测试环境问题也带来了正向收益，不然难以定位到 7.18 号线上问题的根本原因。而且这个问题还是个不定时炸弹，谁晓得什么时候会再产生，下次产生又会引起多大故障！

实践果然只是实践，事实往往更残暴，实践上认为重启会从新构建配置，能够解决问题，然而重启却反而扩充了故障面；
重启不能万能的，在重启之前要认真评估剖析重启复原的可能性；
所有的开源组件，不能只是简略应用，平时应该积攒，探索其底层原理，不然真正遇到问题将大刀阔斧；特地是零碎的外围依赖组件！
外围零碎 / 组件肯定要有预案，剖析可能呈现的状况，提前制订一些止损伎俩，不然等故障产生了，干瞪眼吗？
日志采集十分重要，遇到问题没有日志，难道靠猜吗？
不要放过任何一个问题，7.18 号线上问题，7.21 号测试环境问题，如果没有排查出根因，谁晓得什么时候会再次发生？下次会不会引起更大范畴事变呢？

ingress：https://kubernetes.io/zh-cn/d…
Nginx ingress：https://github.com/kubernetes…
endpoints：https://kubernetes.io/zh-cn/d…
官网文档：https://kubernetes.github.io/…
kubectl：https://kubernetes.io/zh-cn/d…
Nginx config：http://nginx.org/en/docs/diri…

关于nginx:警惕Nginx-ingress就这么挂了

背景形容

7.18 线上服务 504

7.19 Nginx ingress 技术调研

7.21 测试环境 502

7.22 深入分析

7.18 问题回顾

反思总结

附录