本文为Kubernetes监控系列的第三篇文章,系列目录如下:
-
Kubernetes中的服务发现与故障排除(本篇)
-
Docker与Kubernetes在WayBlazer的使用案例(敬请期待)
-
它们是孤立的,你和你要监视的进程之间存在一定的障碍,在主机上运行的传统故障排除工具不了解容器、命名空间和编排平台。
-
它们带来最小的运行时间,只需要服务及其依赖项,而不需要所有的故障排除工具,想象下只用busybox来进行故障排除!
-
它们调度在你集群、进行容器移动,扩容或者缩容。随着流程的结束,它们变得非常不稳定,出现并消失。
-
并通过新的虚拟网络层互相通信。
-
第一部分:Kubernetes故障排除之服务发现
-
第二部分:Kubernetes故障排除之DNS解析
-
第三部分:Kubernetes故障排除之使用Docker运行容器
$ kubectl create namespace critical-appnamespace "critical-app" created$ kubectl create -f backend.yamlservice "backend" createddeployment "backend" created
然后创建一个客户端来加载我们的后端服务:
$ kubectl run -it --image=tutum/curl client --namespace critical-app --restart=Never
Kubernetes故障排除之服务发现 在我们的client容器中可以运行一个简单测试 root@client:/# curl backend 来查看我们的Kubernetes service是如何工作的。但我们不想遗漏下什么,我们认为可以使用FQDN进行服务发现测试,在Kubernetes文档[3]中会发现,每个service都会获得一个默认的DNS:my-svc.my-namespace.svc.cluster.local。因此,我们用它作为FQDN进行测试。 在client容器的shell端运行:root@client:/# curl backend.critical-app.svc.cluster.local,不过这次curl命令卡住了10秒,然后返回了预期网址!作为一个分布式系统工程师,这是最糟糕的事情之一:你希望直接失败或者成功,而不是等待10秒。 为了定位出问题,我们使用了Sysdig。Sysdig是一个开源Linux可视化工具,提供对容器的本地可见性,包括Docker、Kubernetes、DC / OS和Mesos等等。将htop,tcpdump,strace,lsof,netstat等的功能组合在一起,Sysdig提供了Kubernetes基础架构环境中的所有系统调用和应用程序数据。Monitoring Kubernetes with Sysdig[4]中很好地介绍了如何在Kubernetes中使用这个工具。 为了分析上述问题原因,我们将请求sysdig来dump所有信息到捕获文件中:
$ sudo sysdig -k http://127.0.0.1:8080 -s8192 -zw capture.scap
快速解释下每个参数:
-
-k http://localhost:8080 连接Kubernetes API
-
-s8192 扩大IO缓冲区,因为我们需要显示全部内容,否则默认情况下会被切断,
-
-zw capture.scap 将系统调用与元数据信息压缩并dump到文件中
$ sysdig -r capture.scap -pk -NA "fd.type in (ipv4, ipv6) and (k8s.ns.name=critical-app or proc.name=skydns)" | less
快速解释下每个参数:
-
-r capture.scap 读取捕获文件
-
-pk 打印Kubernetes部分到stdout中
-
-NA 显示ASCII输出
[...]10030 16:41:39.536689965 0 client (b3a718d8b339) curl (22370:13) < socket fd=3(<4>)10031 16:41:39.536694724 0 client (b3a718d8b339) curl (22370:13) > connect fd=3(<4>)10032 16:41:39.536703160 0 client (b3a718d8b339) curl (22370:13) < connect res=0 tuple=172.17.0.7:46162->10.0.2.15:5310048 16:41:39.536831645 1 (36ae6d09d26e) skydns (17280:11) > recvmsg fd=6(<3t>:::53)10049 16:41:39.536834352 1 (36ae6d09d26e) skydns (17280:11) < recvmsg res=87 size=87 data=backendcritical-appsvcclusterlocalcritical-appsvcclusterlocal tuple=::ffff:172.17.0.7:46162->:::5310050 16:41:39.536837173 1 (36ae6d09d26e) skydns (17280:11) > recvmsg fd=6(<3t>:::53)[...]
SkyDNS发送请求(10097)到etcd的API(/local/cluster/svc/critical-app/local/cluster/svc/critical-app/backend),显然etcd不能识别这个service,然后返回(10167)“Key not found”。这通过DNS查询响应传回给curl。
[...]10096 16:41:39.538247116 1 (36ae6d09d26e) skydns (4639:8) > write fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=22110097 16:41:39.538275108 1 (36ae6d09d26e) skydns (4639:8) < write res=221 data=GET /v2/keys/skydns/local/cluster/svc/critical-app/local/cluster/svc/critical-app/backend?quorum=false&recursive=true&sorted=false HTTP/1.1Host: 10.0.2.15:4001User-Agent: Go 1.1 package httpAccept-Encoding: gzip10166 16:41:39.538636659 1 (36ae6d09d26e) skydns (4617:1) > read fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=409610167 16:41:39.538638040 1 (36ae6d09d26e) skydns (4617:1) < read res=285 data=HTTP/1.1 404 Not FoundContent-Type: application/jsonX-Etcd-Cluster-Id: 7e27652122e8b2aeX-Etcd-Index: 1259Date: Thu, 08 Dec 2016 15:41:39 GMTContent-Length: 112{"errorCode":100,"message":"Key not found","cause":"/skydns/local/cluster/svc/critical-app/local","index":1259}[...]
curl没有放弃并再次尝试(10242),不过这次用的是backend.critical-app.svc.cluster.local.svc.cluster.local。看起来这次curl尝试将critical-app这个追加搜索域去除,使用一个不同的搜索域。显然,当请求到达etcd(10247)时,再次失败(10345)。
[...]10218 16:41:39.538914765 0 client (b3a718d8b339) curl (22370:13) < connect res=0 tuple=172.17.0.7:35547->10.0.2.15:5310242 16:41:39.539005618 1 (36ae6d09d26e) skydns (17280:11) < recvmsg res=74 size=74 data=backendcritical-appsvcclusterlocalsvcclusterlocal tuple=::ffff:172.17.0.7:35547->:::5310247 16:41:39.539018226 1 (36ae6d09d26e) skydns (17280:11) > recvmsg fd=6(<3t>:::53)10248 16:41:39.539019925 1 (36ae6d09d26e) skydns (17280:11) < recvmsg res=74 size=74 data=0]backendcritical-appsvcclusterlocalsvcclusterlocal tuple=::ffff:172.17.0.7:35547->:::5310249 16:41:39.539022522 1 (36ae6d09d26e) skydns (17280:11) > recvmsg fd=6(<3t>:::53)10273 16:41:39.539210393 1 (36ae6d09d26e) skydns (4639:8) > write fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=20810274 16:41:39.539239613 1 (36ae6d09d26e) skydns (4639:8) < write res=208 data=GET /v2/keys/skydns/local/cluster/svc/local/cluster/svc/critical-app/backend?quorum=false&recursive=true&sorted=false HTTP/1.1Host: 10.0.2.15:4001User-Agent: Go 1.1 package httpAccept-Encoding: gzip10343 16:41:39.539465153 1 (36ae6d09d26e) skydns (4617:1) > read fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=409610345 16:41:39.539467440 1 (36ae6d09d26e) skydns (4617:1) < read res=271 data=HTTP/1.1 404 Not Found[...]
curl会再次尝试,我们可以看这次的DNS查询请求(10418),加上了cluster.local变成backend.critical-app.svc.cluster.local.cluster.local。这次etcd请求(10479)同样失败(10524)。
[...]10396 16:41:39.539686075 0 client (b3a718d8b339) curl (22370:13) < connect res=0 tuple=172.17.0.7:40788->10.0.2.15:5310418 16:41:39.539755453 0 (36ae6d09d26e) skydns (17280:11) < recvmsg res=70 size=70 data=backendcritical-appsvcclusterlocalclusterlocal tuple=::ffff:172.17.0.7:40788->:::5310433 16:41:39.539800679 0 (36ae6d09d26e) skydns (17280:11) > recvmsg fd=6(<3t>:::53)10434 16:41:39.539802549 0 (36ae6d09d26e) skydns (17280:11) < recvmsg res=70 size=70 data=backendcritical-appsvcclusterlocalclusterlocal tuple=::ffff:172.17.0.7:40788->:::5310437 16:41:39.539805177 0 (36ae6d09d26e) skydns (17280:11) > recvmsg fd=6(<3t>:::53)10478 16:41:39.540166087 1 (36ae6d09d26e) skydns (4639:8) > write fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=20410479 16:41:39.540183401 1 (36ae6d09d26e) skydns (4639:8) < write res=204 data=GET /v2/keys/skydns/local/cluster/local/cluster/svc/critical-app/backend?quorum=false&recursive=true&sorted=false HTTP/1.1Host: 10.0.2.15:4001User-Agent: Go 1.1 package httpAccept-Encoding: gzip10523 16:41:39.540421040 1 (36ae6d09d26e) skydns (4617:1) > read fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=409610524 16:41:39.540422241 1 (36ae6d09d26e) skydns (4617:1) < read res=267 data=HTTP/1.1 404 Not Found[...]
对于未经训练的人来说,可能看起来我们发现了这个问题:一堆无效的请求。但实际上这不是事实,如果我们查看时间戳,第一个etcd请求(10097)和最后一个(10479)之间的差异,第二列中的时间戳相距小于10ms。而我们正在寻找一个秒数问题,而不是毫秒——那么等待的时间在哪里?
当我们继续浏览捕获文件时,我们可以看到curl不停止尝试使用DNS查询到SkyDNS,现在使用backend.critical-app.svc.cluster.local.localdomain(10703)。这个.localdomain不被SkyDNS识别为Kubernetes的内部域,因此它决定将这个查询转发给它的上游DNS解析器(10691),而不是去etcd进行服务发现。
[...]10690 16:41:39.541376928 1 (36ae6d09d26e) skydns (4639:8) > connect fd=8(<4>)10691 16:41:39.541381577 1 (36ae6d09d26e) skydns (4639:8) < connect res=0 tuple=10.0.2.15:44249->8.8.8.8:5310702 16:41:39.541415384 1 (36ae6d09d26e) skydns (4639:8) > write fd=8(<4u>10.0.2.15:44249->8.8.8.8:53) size=6810703 16:41:39.541531434 1 (36ae6d09d26e) skydns (4639:8) < write res=68 data=Nbackendcritical-appsvcclusterlocallocaldomain10717 16:41:39.541629507 1 (36ae6d09d26e) skydns (4639:8) > read fd=8(<4u>10.0.2.15:44249->8.8.8.8:53) size=51210718 16:41:39.541632726 1 (36ae6d09d26e) skydns (4639:8) < read res=-11(EAGAIN) data=58215 16:41:43.541261462 1 (36ae6d09d26e) skydns (4640:9) > close fd=7(<4u>10.0.2.15:54272->8.8.8.8:53)58216 16:41:43.541263355 1 (36ae6d09d26e) skydns (4640:9) < close res=0[...]
扫描时间戳列时,我们发现SkyDNS发出请求后第一个较大的间隙,然后等待大约4秒(10718-58215)。鉴于.localdomain不是有效的TLD(顶级域名),上游服务器将只是忽略此请求。超时后,SkyDNS再次尝试使用相同的查询(75923),再等待几秒钟(75927-104208)。总的来说,我们一直在等待大约8秒钟,以查找不存在并且被忽略的DNS条目。
[...]58292 16:41:43.542822050 1 (36ae6d09d26e) skydns (4640:9) < write res=68 data=Nbackendcritical-appsvcclusterlocallocaldomain58293 16:41:43.542829001 1 (36ae6d09d26e) skydns (4640:9) > read fd=8(<4u>10.0.2.15:56371->8.8.8.8:53) size=51258294 16:41:43.542831896 1 (36ae6d09d26e) skydns (4640:9) < read res=-11(EAGAIN) data=75904 16:41:44.543459524 0 (36ae6d09d26e) skydns (17280:11) < recvmsg res=68 size=68 data=[...]75923 16:41:44.543560717 0 (36ae6d09d26e) skydns (17280:11) < recvmsg res=68 size=68 data=Nbackendcritical-appsvcclusterlocallocaldomain tuple=::ffff:172.17.0.7:47441->:::5375927 16:41:44.543569823 0 (36ae6d09d26e) skydns (17280:11) > recvmsg fd=6(<3t>:::53)104208 16:41:47.551459027 1 (36ae6d09d26e) skydns (4640:9) > close fd=7(<4u>10.0.2.15:42126->8.8.8.8:53)104209 16:41:47.551460674 1 (36ae6d09d26e) skydns (4640:9) < close res=0[...]
但最后,它一切正常!为什么?curl停止尝试修补事物并应用搜索域。当我们在命令行中输入时,它会逐字尝试域名。SkyDNS通过etcd服务发现API请求解析DNS请求(104406)。打开一个与服务IP地址(107992)的连接,然后使用iptables将其转发给Pod,并且HTTP响应返回到curl容器(108024)。
[...]104406 16:41:47.552626262 0 (36ae6d09d26e) skydns (4639:8) < write res=190 data=GET /v2/keys/skydns/local/cluster/svc/critical-app/backend?quorum=false&recursive=true&sorted=false HTTP/1.1[...]104457 16:41:47.552919333 1 (36ae6d09d26e) skydns (4617:1) < read res=543 data=HTTP/1.1 200 OK[...]{"action":"get","node":{"key":"/skydns/local/cluster/svc/critical-app/backend","dir":true,"nodes":[{"key":"/skydns/local/cluster/svc/critical-app/backend/6ead029a","value":"{\"host\":\"10.3.0.214\",\"priority\":10,\"weight\":10,\"ttl\":30,\"targetstrip\":0}","modifiedIndex":270,"createdIndex":270}],"modifiedIndex":270,"createdIndex":270}}[...]107992 16:41:48.087346702 1 client (b3a718d8b339) curl (22369:12) < connect res=-115(EINPROGRESS) tuple=172.17.0.7:36404->10.3.0.214:80108002 16:41:48.087377769 1 client (b3a718d8b339) curl (22369:12) > sendto fd=3(<4t>172.17.0.7:36404->10.3.0.214:80) size=102 tuple=NULL108005 16:41:48.087401339 0 backend-1440326531-csj02 (730a6f492270) nginx (7203:6) < accept fd=3(<4t>172.17.0.7:36404->172.17.0.5:80) tuple=172.17.0.7:36404->172.17.0.5:80 queuepct=0 queuelen=0 queuemax=128108006 16:41:48.087406626 1 client (b3a718d8b339) curl (22369:12) < sendto res=102 data=GET / HTTP/1.1[...]108024 16:41:48.087541774 0 backend-1440326531-csj02 (730a6f492270) nginx (7203:6) < writev res=238 data=HTTP/1.1 200 OKServer: nginx/1.10.2[...]
通过系统层面的情况,我们可以得出结论:造成这个问题的根本原因有两个方面。首先,当我给curl一个FQDN时,它不相信我并试图应用搜索域算法。其次,.localdomain不应该存在,因为它在我们的Kubernetes集群中是不可路由的。
如果你认为这是通过使用tcpdump也能完成,只是你还没尝试。我能100%肯定它不会被安装在你的容器内,你可以在主机外部运行它,但祝你找到与对应Kubernetes调度容器的网络命名空间匹配的网络接口。请继续阅读:我们还没有完成故障排除。
Kubernetes故障排除之DNS解析 让我们看看resolv.conf文件中的内容。容器可能已经不存在了,或者curl调用后文件可能已经改变。但是我们有一个包含发生了所有事情的捕获文件。 通常情况下,容器的运行时间与进程内运行的时间一样长,当进程结束时容器就消失了。这是对容器进行故障排除最具挑战性的部分之一。我们如何探索已经消失的东西?我们如何重现发生的事情?在这些情况下,Sysdig捕获文件非常有用。 我们来分析捕获文件,但不是过滤网络流量,我们将在这次对resolv文件进行过滤。我们希望看到resolv.conf与curl读取的完全一样,以确认我们的想法,它包含localdomain。
$ sysdig -pk -NA -r capture.scap -c echo_fds "fd.type=file and fd.name=/etc/resolv.conf"------ Read 119B from [k8s_client.eee910bc_client_critical-app_da587b4d-bd5a-11e6-8bdb-028ce2cfb533_bacd01b6] [b3a718d8b339] /etc/resolv.conf (curl)search critical-app.svc.cluster.local svc.cluster.local cluster.local localdomainnameserver 10.0.2.15options ndots:5[...]
这是使用sysdig的一种新的方式:
-c echo_fds 使用Sysdig chisel——附加脚本——用以聚合信息并格式化输出。此外,过滤器仅包含文件描述符上的IO活动,该文件描述符是一个文件,名称为/etc/resolv.conf,正是我们所要寻找的。
通过系统调用,我们看到有一个选项叫做ndots。 此选项是curl不信任我们的FQDN并试图首先追加所有搜索域的原因。如果你阅读了manpage[6],就会知道ndots会强制libc,任何小于5个点的域名解析都不会被视为fqdn,但会尝试首先追加所有搜索域。ndots有一个很好的理由,所以我们可以执行 curl backend。但是谁在那里添加了localdomain?
Kubernetes故障排除之使用Docker运行容器 我们不想在没有找到这个本地域的罪魁祸首的情况下完成我们的故障排除。 这样,我们可以责怪软件而不是人,是Docker加了搜索域?或者Kubernetes在创建容器时指导Docker这么做? 既然我们知道Kubernetes和Docker之间的所有控制通信都是通过Unix套接字完成的,我们可以使用它来过滤掉所有的东西:
$ sudo sysdig -pk -s8192 -c echo_fds -NA "fd.type in (unix) and evt.buffer contains localdomain"
这一次,我们将使用一个非常棒的过滤器的来捕捉现场 evt.buffer containers。 这个过滤器需要所有的事件缓冲区,如果它包含我们正在寻找的字符串,将被我们的chisel捕获并格式化输出。
现在我需要创建一个新的客户端来窥探容器编排时发生的情况:
$ kubectl run -it --image=tutum/curl client-foobar --namespace critical-app --restart=Never
可以看到,Kubernetes中的hyperkube使用Docker API在/var/run/docker.sock上写了一个HTTP POST请求到/containers/create。如果我们通读它,我们会发现这个请求包含一个选项“DnsSearch”:[“critical-app.svc.cluster.local”,“svc.cluster.local”,“cluster.local”,“localdomain”]。Kubernetes,我们抓到你了!很可能它出于某种原因,就像我的本地开发机器设置了该搜索域一样。无论如何,这是一个不同的故事。
[...]------ Write 2.61KB to [k8s-kubelet] [de7157ba23c4] (hyperkube)POST /containers/create?name=k8s_POD.d8dbe16c_client-foobar_critical-app_085ac98f-bd64-11e6-8bdb-028ce2cfb533_9430448e HTTP/1.1Host: docker[...] "DnsSearch":["critical-app.svc.cluster.local","svc.cluster.local","cluster.local","localdomain"],[...]
总结 准确地再现容器内发生的事情可能会非常具有挑战性,因为它们在进程死亡或刚刚结束时终止。Sysdig捕获通过系统调用包含所有信息,包括网络流量、文件系统I/O和进程行为,提供故障排除所需的所有数据。 在容器环境中进行故障排除时,能够过滤和添加容器上下文信息(如Docker容器名称或Kubernetes元数据)使我们的排查过程更加轻松。 Sysdis在所有主流Linux发行版、OSX以及Windows上都能使用,下载[7]它获得最新版本。Sysdig是一个开源工具,但该项目背后的公司也提供了一个商业产品[8]来监视和排除多个主机上的容器和微服务。 相关链接:
-
https://github.com/gianlucaborello/healthchecker-kubernetes/blob/master/manifests/backend.yaml
-
https://sysdig.com/blog/understanding-how-kubernetes-services-dns-work/
-
http://kubernetes.io/docs/user-guide/services/#dns
-
http://blog.kubernetes.io/2015/11/monitoring-Kubernetes-with-Sysdig.html
-
https://github.com/bencer/troubleshooting-docker-kubernetes-sysdig/raw/master/capture.scap
-
http://man7.org/linux/man-pages/man5/resolv.conf.5.html
-
http://www.sysdig.org/install/
-
https://www.sysdig.com/