Kubernetes监控系列(三):Kubernetes服务发现与故障排除


【编者的话】本文是Kubernetes监控系列的第三篇,主要讲述了Kubernetes的故障排除以及服务发现。

本文是关于在生产中使用Kubernetes系列的一部分。第一部分介绍了Kubernetes和监控工具的基础知识第二部分涵盖了Kubernetes报警的最佳实践。这部分将介绍对Kubernetes故障排除,特别是服务发现,最后一部分是监控Kubernetes的实际使用案例。像Kubernetes,DC / OS Mesos或Docker Swarm这样的容器编排平台可以帮助你方便地管理容器,但对解决容器问题并没有什么帮助:
  • 它们是孤立的,你和你要监视的进程之间存在一定的障碍,在主机上运行的传统故障排除工具不了解容器、命名空间和编排平台。
  • 它们带来最小的运行时间,只需要服务及其依赖项,而不需要所有的故障排除工具,想象下只用busybox来进行故障排除!
  • 它们调度在你集群、进行容器移动,扩容或者缩容。随着流程的结束,它们变得非常不稳定,出现并消失。
  • 并通过新的虚拟网络层互相通信。


本文将通过一个真实用例讲诉如何在Kubernetes中进行故障排除。我们将涵盖Kubernetes内部3个不同层的故障排除:
  • 第一部分:Kubernetes故障排除之服务发现
  • 第二部分:Kubernetes故障排除之DNS解析
  • 第三部分:Kubernetes故障排除之使用Docker运行容器


本文场景将使用一个简单的Kubernetes服务,包括3个Nginx pod和一个带有curl命令的客户端。在链接中可以看到场景需要使用的yaml文件 backend.yaml。如果你刚刚接触Kubernetes,可以看下“Understanding how Kubernetes DNS services work”这篇文章来学习如何部署上述服务。实际操作如下:
$ kubectl create namespace critical-app
namespace "critical-app" created
$ kubectl create -f backend.yaml
service "backend" created
deployment "backend" created

然后创建一个客户端来加载我们的后端服务:
$ kubectl run -it --image=tutum/curl client --namespace critical-app --restart=Never

第一部分:Kubernetes故障排除之服务发现

在我们的client容器中可以运行一个简单测试 root@client:/# curl backend 来查看我们的Kubernetes service是如何工作的。但我们不想遗漏下什么,我们认为可以使用FQDN进行服务发现测试,在Kubernetes文档中会发现,每个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中很好地介绍了如何在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到文件中


同时,我们将再次运行curl命令来复现这个问题:# curl backend.critical-app.svc.cluster.local。这确保了我们在上面捕获的文件中拥有所有数据,以重现场景并解决问题。

一旦curl返回,我们可以执行Ctrl+C来终止数据捕获,并且我们将拥有一个10s的捕获文件,包括我们的Kubernetes主机中发生的所有事情以及服务发现过程。现在我们可以开始在集群内或集群外解决问题,只要在安装了sysdig的环境中复制文件:
$ 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输出


以及双引号中是过滤内容。Sysdig能够理解Kubernetes语义,因此我们可以过滤来自名称空间critical-app中的任何容器或任何名为skydns的进程的套接字IPv4或IPv6上的流量。加入proc.name = skydns因为这是内部Kubernetes DNS解析器,并且作为Kubernetes基础结构的一部分运行在我们的命名空间之外。
troubleshooting_docker_with_sysdig.png

Sysdig也有一个交互式的ncurses接口。

为了跟随此服务发现故障排除示例,你可以下载捕获文件capture.scap并使用sysdig自行查看它。

我们立即看到curl如何尝试解析域名,但在DNS查询有效载荷上我们有些奇怪(10049):backend.critical-app.svc.cluster.local.critical-app.svc.cluster.local。看上去由于某些原因,curl不识别已经给定的FQDN,并且决定追加一个搜索域。
[...]
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:53
10048 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->:::53
10050 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=221
10097 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.1
Host: 10.0.2.15:4001
User-Agent: Go 1.1 package http
Accept-Encoding: gzip


10166 16:41:39.538636659 1  (36ae6d09d26e) skydns (4617:1) > read fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=4096
10167 16:41:39.538638040 1  (36ae6d09d26e) skydns (4617:1) < read res=285 data=
HTTP/1.1 404 Not Found
Content-Type: application/json
X-Etcd-Cluster-Id: 7e27652122e8b2ae
X-Etcd-Index: 1259
Date: Thu, 08 Dec 2016 15:41:39 GMT
Content-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:53
10242 16:41:39.539005618 1  (36ae6d09d26e) skydns (17280:11) < recvmsg res=74 size=74 data=
backendcritical-appsvcclusterlocalsvcclusterlocal tuple=::ffff:172.17.0.7:35547->:::53
10247 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->:::53
10249 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=208
10274 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.1
Host: 10.0.2.15:4001
User-Agent: Go 1.1 package http
Accept-Encoding: gzip


10343 16:41:39.539465153 1  (36ae6d09d26e) skydns (4617:1) > read fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=4096
10345 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:53
10418 16:41:39.539755453 0  (36ae6d09d26e) skydns (17280:11) < recvmsg res=70 size=70 data=
backendcritical-appsvcclusterlocalclusterlocal tuple=::ffff:172.17.0.7:40788->:::53
10433 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->:::53
10437 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=204
10479 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.1
Host: 10.0.2.15:4001
User-Agent: Go 1.1 package http
Accept-Encoding: gzip


10523 16:41:39.540421040 1  (36ae6d09d26e) skydns (4617:1) > read fd=3(<4t>10.0.2.15:34108->10.0.2.15:4001) size=4096
10524 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:53
10702 16:41:39.541415384 1  (36ae6d09d26e) skydns (4639:8) > write fd=8(<4u>10.0.2.15:44249->8.8.8.8:53) size=68
10703 16:41:39.541531434 1  (36ae6d09d26e) skydns (4639:8) < write res=68 data=
Nbackendcritical-appsvcclusterlocallocaldomain
10717 16:41:39.541629507 1  (36ae6d09d26e) skydns (4639:8) > read fd=8(<4u>10.0.2.15:44249->8.8.8.8:53) size=512
10718 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-appsvcclusterlocallocaldomain
58293 16:41:43.542829001 1  (36ae6d09d26e) skydns (4640:9) > read fd=8(<4u>10.0.2.15:56371->8.8.8.8:53) size=512
58294 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->:::53
75927 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/back
end/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:80
108002 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=NULL
108005 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=128
108006 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 OK
Server: 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 localdomain
nameserver 10.0.2.15
options ndots:5
[...]

这是使用sysdig的一种新的方式:

-c echo_fds 使用Sysdig chisel——附加脚本——用以聚合信息并格式化输出。此外,过滤器仅包含文件描述符上的IO活动,该文件描述符是一个文件,名称为/etc/resolv.conf,正是我们所要寻找的。

通过系统调用,我们看到有一个选项叫做ndots。 此选项是curl不信任我们的FQDN并试图首先追加所有搜索域的原因。如果你阅读了manpage,就会知道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.1
Host: docker
[...]
"DnsSearch":["critical-app.svc.cluster.local","svc.cluster.local","cluster.local","localdomain"],
[...]

总结

准确地再现容器内发生的事情可能会非常具有挑战性,因为它们在进程死亡或刚刚结束时终止。Sysdig捕获通过系统调用包含所有信息,包括网络流量、文件系统I/O和进程行为,提供故障排除所需的所有数据。

在容器环境中进行故障排除时,能够过滤和添加容器上下文信息(如Docker容器名称或Kubernetes元数据)使我们的排查过程更加轻松。

Sysdis在所有主流Linux发行版、OSX以及Windows上都能使用,下载它获得最新版本。Sysdig是一个开源工具,但该项目背后的公司也提供了一个商业产品来监视和排除多个主机上的容器和微服务。

原文链接:Kubernetes troubleshooting service discovery(翻译:肖远昊)

0 个评论

要回复文章请先登录注册