本文是跟安信证券容器云技术团队独特进行问题排查的最佳实际。

问题背景

咱们发现客户的Kubernetes集群环境中所有的worker节点的Kubelet过程的CPU使用率长时间占用过高,通过pidstat能够看到CPU使用率高达100%。本文记录下了本次问题排查的过程。

集群环境

排查过程

应用strace工具对kubelet过程进行跟踪

1、因为Kubelet过程CPU使用率异样,能够应用strace工具对kubelet过程动静跟踪过程的调用状况,首先应用strace -cp <PID>命令统计kubelet过程在某段时间内的每个零碎调用的工夫、调用和谬误状况。

从上图能够看到,执行零碎调用过程中,futex抛出了五千多个errors,这并不是一个失常的数量,而且该函数占用的工夫达到了99%,所以须要进一步查看kubelet过程相干的调用。

2、因为strace -cp命令只能查看过程的整体调用状况,所以咱们能够通过strace -tt -p <PID>命令打印每个零碎调用的工夫戳,如下:

从strace输入的后果来看,在执行futex相干的零碎调用时,有大量的Connect timed out,并返回了-1和ETIMEDOUT的error,所以才会在strace -cp中看到了那么多的error。

futex是一种用户态和内核态混合的同步机制,当futex变量通知过程有竞争产生时,会执行零碎调用去实现相应的解决,例如wait或者wake up,从官网的文档理解到,futex有这么几个参数:

futex(uint32_t *uaddr, int futex_op, uint32_t val,                 const struct timespec *timeout,   /* or: uint32_t val2 */                 uint32_t *uaddr2, uint32_t val3);

官网文档给出ETIMEDOUT的解释:

ETIMEDOUT       The operation in futex_op employed the timeout specified in       timeout, and the timeout expired before the operation       completed.

意思就是在指定的timeout工夫中,未能实现相应的操作,其中futex_op对应上述输入后果的FUTEX_WAIT_PRIVATEFUTEX_WAIT_PRIVATE,能够看到根本都是产生在FUTEX_WAIT_PRIVATE时产生的超时。

从目前的零碎调用层面能够判断,futex无奈顺利进入睡眠状态,然而futex进行了哪些操作还是不分明,因而仍无奈判断kubeletCPU飙高的起因,所以咱们须要进一步从kubelet的函数调用中去看到底是执行卡在了哪个中央。

FUTEX_PRIVATE_FLAG:这个参数通知内核futex是过程专用的,不与其余过程共享,这里的FUTEX_WAIT_PRIVATE和FUTEX_WAKE_PRIVATE就是其中的两种FLAG;

futex相干阐明1: https://man7.org/linux/man-pa...
fuex相干阐明2: https://man7.org/linux/man-pa...

应用go pprof工具对kubelet函数调用进行剖析

晚期的Kubernetes版本,能够间接通过debug/pprof 接口获取debug数据,前面思考到相干安全性的问题,勾销了这个接口,具体信息能够参考CVE-2019-11248(https://github.com/kubernetes/kubernetes/issues/81023)。因而咱们将通过kubectl开启proxy进行相干数据指标的获取:

1、首先应用kubectl proxy命令启动API server代理

kubectl proxy --address='0.0.0.0'  --accept-hosts='^*$'

这里须要留神,如果应用的是Rancher UI上复制的kubeconfig文件,则须要应用指定了master IP的context,如果是RKE或者其余工具装置则能够疏忽。

2、构建Golang环境。go pprof须要在golang环境下应用,本地如果没有装置golang,则能够通过Docker疾速构建Golang环境

docker run -itd --name golang-env --net host golang bash

3、应用go pprof工具导出采集的指标,这里替换127.0.0.1为apiserver节点的IP,默认端口是8001,如果docker run的环境跑在apiserver所在的节点上,能够应用127.0.0.1。另外,还要替换NODENAME为对应的节点名称。

docker exec -it golang-env bashgo tool pprof -seconds=60 -raw -output=kubelet.pprof http://127.0.0.1:8001/api/v1/nodes/${NODENAME}/proxy/debug/pprof/profile

4、输入好的pprof文件不不便查看,须要转换成火焰图,举荐应用FlameGraph工具生成svg图

git clone https://github.com/brendangregg/FlameGraph.gitcd FlameGraph/./stackcollapse-go.pl kubelet.pprof > kubelet.out./flamegraph.pl kubelet.out > kubelet.svg

转换成火焰图后,就能够在浏览器直观地看到函数相干调用和具体调用工夫比了。

5、剖析火焰图

从kubelet的火焰图能够看到,调用工夫最长的函数是k8s.io/kubernetes/vendor/github.com/google/cadvisor/manager.(*containerData).housekeeping,其中cAdvisor是kubelet内置的指标采集工具,次要是负责对节点机器上的资源及容器进行实时监控和性能数据采集,包含CPU应用状况、内存应用状况、网络吞吐量及文件系统应用状况。

深刻函数调用能够发现k8s.io/kubernetes/vendor/github.com/opencontainers/runc/libcontainer/cgroups/fs.(Manager).GetStats这个函数占用k8s.io/kubernetes/vendor/github.com/google/cadvisor/manager.(containerData).housekeeping这个函数的工夫是最长的,阐明在获取容器CGroup相干状态时占用了较多的工夫。

6、既然这个函数占用工夫长,那么咱们就剖析一下这个函数具体干了什么。

查看源代码:
https://github.com/kubernetes/kubernetes/blob/ded8a1e2853aef374fc93300fe1b225f38f19d9d/vendor/github.com/opencontainers/runc/libcontainer/cgroups/fs/memory.go#L162

func (s *MemoryGroup) GetStats(path string, stats *cgroups.Stats) error {  // Set stats from memory.stat.  statsFile, err := os.Open(filepath.Join(path, "memory.stat"))  if err != nil {    if os.IsNotExist(err) {      return nil    }    return err  }  defer statsFile.Close()  sc := bufio.NewScanner(statsFile)  for sc.Scan() {    t, v, err := fscommon.GetCgroupParamKeyValue(sc.Text())    if err != nil {      return fmt.Errorf("failed to parse memory.stat (%q) - %v", sc.Text(), err)    }    stats.MemoryStats.Stats[t] = v  }  stats.MemoryStats.Cache = stats.MemoryStats.Stats["cache"]  memoryUsage, err := getMemoryData(path, "")  if err != nil {    return err  }  stats.MemoryStats.Usage = memoryUsage  swapUsage, err := getMemoryData(path, "memsw")  if err != nil {    return err  }  stats.MemoryStats.SwapUsage = swapUsage  kernelUsage, err := getMemoryData(path, "kmem")  if err != nil {    return err  }  stats.MemoryStats.KernelUsage = kernelUsage  kernelTCPUsage, err := getMemoryData(path, "kmem.tcp")  if err != nil {    return err  }  stats.MemoryStats.KernelTCPUsage = kernelTCPUsage  useHierarchy := strings.Join([]string{"memory", "use_hierarchy"}, ".")  value, err := fscommon.GetCgroupParamUint(path, useHierarchy)  if err != nil {    return err  }  if value == 1 {    stats.MemoryStats.UseHierarchy = true  }  pagesByNUMA, err := getPageUsageByNUMA(path)  if err != nil {    return err  }  stats.MemoryStats.PageUsageByNUMA = pagesByNUMA  return nil}

从代码中能够看到,过程会去读取memory.stat这个文件,这个文件寄存了cgroup内存应用状况。也就是说,在读取这个文件破费了大量的工夫。这时候,如果咱们手动去查看这个文件,会是什么成果?

# time cat /sys/fs/cgroup/memory/memory.stat >/dev/nullreal 0m9.065suser 0m0.000ssys 0m9.064s

从这里能够看出端倪了,读取这个文件破费了9s,显然是不失常的。

基于上述后果,咱们在cAdvisor的GitHub上查找到一个issue(https://github.com/google/cadvisor/issues/1774),从该issue中能够得悉,该问题跟slab memory 缓存有肯定的关系。从该issue中得悉,受影响的机器的内存会逐步被应用,通过/proc/meminfo看到应用的内存是slab memory,该内存是内核缓存的内存页,并且其中绝大部分都是dentry缓存。从这里咱们能够判断出,当CGroup中的过程生命周期完结后,因为缓存的起因,还存留在slab memory中,导致其相似僵尸CGroup一样无奈被开释。

也就是每当创立一个memory CGroup,在内核内存空间中,就会为其创立调配一份内存空间,该内存蕴含以后CGroup相干的cache(dentry、inode),也就是目录和文件索引的缓存,该缓存实质上是为了进步读取的效率。然而当CGroup中的所有过程都退出时,存在内核内存空间的缓存并没有清理掉。

内核通过搭档算法进行内存调配,每当有过程申请内存空间时,会为其调配至多一个内存页面,也就是起码会调配4k内存,每次开释内存,也是依照起码一个页面来进行开释。当申请调配的内存大小为几十个字节或几百个字节时,4k对其来说是一个微小的内存空间,在Linux中,为了解决这个问题,引入了slab内存调配管理机制,用来解决这种小量的内存申请,这就会导致,当CGroup中的所有过程都退出时,不会轻易回收这部分的内存,而这部分内存中的缓存数据,还会被读取到stats中,从而导致影响读取的性能。

解决办法

1、清理节点缓存,这是一个长期的解决办法,临时清空节点内存缓存,可能缓解kubelet CPU使用率,然而前面缓存上来了,CPU使用率又会升上来。

echo 2 > /proc/sys/vm/drop_caches

2、降级内核版本

其实这个次要还是内核的问题,在GitHub上这个commit(https://github.com/torvalds/linux/commit/205b20cc5a99cdf197c32f4dbee2b09c699477f0)中有提到,在5.2+以上的内核版本中,优化了CGroup stats相干的查问性能,如果想要更好的解决该问题,倡议能够参考本人操作系统和环境,正当的降级内核版本。
另外Redhat在kernel-4.18.0-176(https://bugzilla.redhat.com/show_bug.cgi?id=1795049)版本中也优化了相干CGroup的性能问题,而CentOS 8/RHEL 8默认应用的内核版本就是4.18,如果目前您应用的操作系统是RHEL7/CentOS7,则能够尝试逐步替换新的操作系统,应用这个4.18.0-176版本以上的内核,毕竟新版本内核总归是对容器相干的体验会好很多。

kernel相干commit:
https://github.com/torvalds/linux/commit/205b20cc5a99cdf197c32f4dbee2b09c699477f0
redhat kernel bug fix:
https://bugzilla.redhat.com/show_bug.cgi?id=1795049