本文整理自灵雀云的专家工程师刘梦馨,在《蓝鲸 X DeepFlow 可观测性 Meetup》 中的分享实录,从一个毫无头绪的 K8s DNS 故障出发,分享问题的排查思路,详解排查过程中遇到的 DNS 服务、Alpine 镜像、业务代码逻辑、CNI 插件等各个层面的异常现象。整个排查过程基于 DeepFlow 的持续观测能力,实现了对故障现场的高清还原。刘老师同时也从资深用户的角度,对 DeepFlow Dashboard 提出了宝贵的易用性改善建议。
我主要是负责我们这边(灵雀云)容器网络的事情,我们有一个开源项目叫 Kube-OVN,可能有的人知道,但我今天不讲那块儿,做容器网络的话,会知道名义上我们是开发,但是可能一多半的时间都在排查问题。今天的话我就给大家介绍一下,我们利用 DeepFlow 来帮助我们排查了一个比较困难、困扰我们比较长时间问题的一个案例,希望对大家有一些启发。
故障场景
这是在我们环境里第一次部署 DeepFlow,然后看 DNS 的一个面板,其实看 DNS (的 dashboard ) 我是蒙的,因为第一眼他告诉我这个 Client Error 是有 58%,我这个环境里其实没有什么问题的,是我一个测试的环境,刚把它部署上去,我想看一下这个面板怎么用,它就告诉我这个环境里超过一半的 DNS 请求都是错误的,当时直接就把我给打蒙了。
我给大家简单说一下,这是 K8s 里面一个机制导致的问题,这个问题导致了接下来我们很多的问题,导致我们的排查都变得很困难。比如说我们这个从客户端它是一个简单的 git clone 一个域名,在 K8s 里面它其实是要做很多的事情的,因为 K8s 自己有自己的服务发现的一些机制,它有一个自己的 CoreDNS,它会先尝试在集群内解析的时候,每个 Pod 在 K8s 中启动的时候,K8s 会把 Pod 的 /etc/resolve.conf 给改掉,会给它拼很多的后缀。可以看到下面这个图,kube-system.svc.cluster.local 这个是最完整的,然后可能有 .svc 的,把前面的 namespace 去掉,然后再把 svc 的去掉,然后再把集群的 cluster domain 给你拼下来。导致的结果就是容器里面去做一个 DNS 请求,而且如果你很不幸请求的是一个外网的,因为我们访问是个外网的仓库,是需要把后面的 5 个域名全都匹配一遍,它会把这个拼成完整的域名,然后去请求,请求如果失败的话他会走下一个,失败的话再走下一个,直到最后一次失败他才会真正的去访问你的真实想访问的域名。
而且还有一个问题是他不是发一次(请求),它是每一个请求 IPV4 和 IPV6 同时发,所以它一次的话是发两个请求,把这个请求发给 CoreDNS, CoreDNS 收到这个请求之后,它会根据你的这个后缀来判断是不是做集群内解析。如果集群内解析的话,它会尝试,如果没有的话,它其实还是会往上游发。所以理论上来说,你这个前面发了 10 多次请求,CoreDNS 因为本地不匹配,所以还会再去往上游再去发 10 多次的请求。
看一下这个(Dashboard 的结果),我们这个集群里面其实不全是访问外网了,大部分还是内网的,但是总体相当于有将近 60% 的这个 DNS 请求都是无效的,这是 K8s 本身的机制,会带来这样的一个问题。
DNS 上游网络排查
我们就在这个过程中进一步的去看(Request Log)日志,发现有一些很奇怪的一个现象,理论上来说,我们大部分的域名解析都是失败,因为他又补全了一个那个奇怪的域名是解析不到的。但是我们在有一次的失败过程中,我们把这个就 DNS 解析的日志拉出来的时候,发现那个很奇怪的现象,请求 alauda.cn 时,补全了一个错误的域名,但是不知道出现了一些什么样的情况,上游返回了一个 Success,但是返回 Success 的时候它有没有返回域名,Response 里面是空的,当天的上游返回有一个异常的现象,从 DNS 的角度,它应该返回一个 NX DOMAIN,说这个域名不存在,但他不知道那天是抽了什么风,他返回了一个就是成功,但是里面是没有任何数据记录的,我们认为你这个解析是没有这个类型的一个记录,相当于解析列表是空的,它返回了这样的一种情况。
Musl Libc 库错误处理排查
低内核版本 Bug 导致 conntrack 创建冲突
回来之后,我们发现当时的判断稍微有一些问题,其实并不是说它最终成功了,而是 DeepFlow 的 DNS 面板稍微有点小问题,它展示的是 Client Error 的一些情况。但是对于这种超时的情况,它其实是没有显示出来的,可能跟这个机制有关,因为 Client Error 是很明确你上游返回的一个错误。但是超时的话,尤其是 UDP 这种情况,可能就是你发这个包出去没有人回来,所以他那个面板里面我们其实一开始是没有找到那个中间的一些过程的,后来我们还是到了那个 Request Log 里面,把所有的 DNS 记录,所有的 UDP 记录都拉出来,我们会发现这边有很规律的这个 5 秒一次。比如说这 25-30、30-35、35-40 这样的一些情况,可以很明显地看到中间会有隔 5 秒的这个情况。
ARP 缓存未更新导致 Mac 地址错误
比如说这种的话,其实我现在说下来,大家可能感觉这个好像排查的还比较顺利,但其实挺困难的啊,就是我怎么就突然看到这差 5 秒了?是不是这个事情就很困难?还有就是这个我怎么就正好发现了那边是一个成功的,但是返回 0 这个其实都很困难的,就是你的信息这些东西都有了,但是真的就有时候靠经验或者是靠运气,我才正好的发现了这条数据是异常的,所以我还挺希望就是 DeepFlow 如果我就告诉他一个时间段,那就告诉我: “诶这条数据好像挺异常的”,那我其实就就会好受很多,就不会天天挨骂,对不对?