背景
我们的额监控方案为: Kubernetes(K8S)+cAdvisor+Prometheus+Grafana. 然后, 用 cAdivor 是要监控容器的运行时信息 (比如 CPU, 内存, 网络流量等).
cAdvisor 是基于 Golang 编写的, 性能高稳定性也好.
其实, cAdivor 其实到现在的主流 K8S 版本中, Kubelet 进程已经将其内置了, 但是我们没有这么用, 因为没有必要因为让 Prometheus 定期去 Kubelet 上采集容器信息, 平白增添对 Kubelet 的压力. 相反, 我觉得, 还是应该还是应该单独部署 cAdvisor, 这样一来, 不论是定制化 cAdvisor, 还是版本更新, 都会更方面. 所以, 我使用 K8S 的 DaemonSet 部署了 cAdvisor.
问题
用 DaemonSet 的方式部署 cAdvisor, 本质上, 就是每个 K8S 的宿主机都启动了一个 pod, 实际观测, 发现这些 Pod 的状态, 会随着时间的推移, 开始频繁出现 Crash. 这个问题, 势必会导致 cAdvisor 无法正常监控容器信息. 下面是具体的排查过程.
排查初探
首先, Pod Crash 必然有其原因, 所以, 一开始是通过下面的方式, 看 cAdvisor 到底为何会 Crash, 通过
kubectl describe pod -n monitoring pod-xxxxx
找到 Last State 部分, 发现其为:
State: OOMKilled
这说明, 这个 Pod, 是因为内存不够, cAdvisor 在运行过程, 超出了 Pod 的资源限制, 被 OOM 杀掉了. 既然资源不够, 那么首先, 就是调大其内存限制.
一开始为这个 Pod 设置的上限资源为 1 核 CPU+1G 内存, 既然内存无法满足, 那么调大为 2G, 继续观测, 发现依然会 OOM. 然后又调整为 3G,4G,10G,20G(机器内存大, 土豪), 发现虽然内存变大了会有一些缓解, 但实际上, 即使内存上限设置为 20G, 还是会有 Crash 的情况, 那么, 这时候就需要反思一下几个问题了:
是否是 cAdvisor 存在 bug?
哪个机器上的 cAdvisor Pod 总是重启?
排查是否是 cAdvisor 版本问题
针对第一点, 我们升级了 cAdivor 镜像为最新版, 问题依旧.
排查是否是 cAdvisor 参数配置问题
google 一些文章, 有人提过类似的问题, 官方 issue 的解释中, 有人提到可能配置不对, 可能采集的指标过多等, 于是, 我 review 了一下我的配置, 调整后的完整配置如下:
- apiVersion: extensions/v1beta1
- kind: DaemonSet
- metadata:
- labels:
- name: cadvisor
- name: cadvisor
- namespace: monitoring
- spec:
- revisionHistoryLimit: 10
- selector:
- matchLabels:
- name: cadvisor
- template:
- metadata:
- annotations:
- prometheus.io/port: "28762"
- prometheus.io/scrape: "true"
- creationTimestamp: null
- labels:
- name: cadvisor
- spec:
- automountServiceAccountToken: false
- containers:
- - args:
- - -allow_dynamic_housekeeping=true
- - -global_housekeeping_interval=1m0s
- - -housekeeping_interval=3s
- - -disable_metrics=udp,tcp,percpu,sched
- - -storage_duration=15s
- - -profiling=true
- - -port=28762
- - -max_procs=1
- image: mine/cadvisor-test:v0.0.2
- imagePullPolicy: IfNotPresent
- name: cadvisor
- ports:
- - containerPort: 28762
- hostPort: 28762
- name: http
- protocol: TCP
- resources:
- limits:
- CPU: "1"
- memory: 3000Mi
- requests:
- CPU: "1"
- memory: 500Mi
- terminationMessagePath: /dev/termination-log
- terminationMessagePolicy: File
- volumeMounts:
- - mountPath: /rootfs
- name: rootfs
- readOnly: true
- - mountPath: /var/run
- name: var-run
- readOnly: true
- - mountPath: /sys
- name: sys
- readOnly: true
- - mountPath: /var/lib/docker
- name: docker
- readOnly: true
- - mountPath: /dev/disk
- name: disk
- readOnly: true
- dnsPolicy: ClusterFirst
- hostNetwork: true
- restartPolicy: Always
- schedulerName: default-scheduler
- securityContext: {
- }
- terminationGracePeriodSeconds: 30
- volumes:
- - hostPath:
- path: /
- type: ""
- name: rootfs
- - hostPath:
- path: /var/run
- type: ""
- name: var-run
- - hostPath:
- path: /sys
- type: ""
- name: sys
- - hostPath:
- path: /DATA/docker
- type: ""
- name: docker
- - hostPath:
- path: /dev/disk
- type: ""
- name: disk
- templateGeneration: 6
- updateStrategy:
- rollingUpdate:
- maxUnavailable: 1
- type: RollingUpdate
我调整的部分主要集中在:
- // 这个是禁用哪些指标, 默认只有 udp,tcp
- - -disable_metrics=udp,tcp,percpu,sched
- // 存储最近多久的数据, 原来是 1 分多钟, 调整为 15s
- - -storage_duration=15s
- // 是否开启性能测试, 默认为关闭, 之所以开启, 是要一会儿 debug 内存占用
- - -profiling=true
- // 使用多少 CPU, 默认不到 1 个
- - -max_procs=1
上面的方式, 是减少了一些采集指标, 以及采集数据的最多保留时长, 稍微有些效果, 但是发现效果不大, 原来某些机器上频繁 Crash 的 cAdvisor Pod, 还是 Crash, 另外某些机器上从来不 Crash 的, 也不会 Crash. 那么, 说明参数配置没什么用, 问题应该出现某些机器上.
排查为何 cAdivosr Pod 在某些机器上 Crash
我回顾了一下我们的 K8S 节点, 发现 cAdvisor Pod 不 OOM 的机器上面, 容器都比较少. 越是容器多的机器, 这机器上的 cAdvisor Pod 就越容易 OOM Crash.
那么, 我们看一下 cAdvisor 的 Pod 日志, 发现其频繁报一个错误:
fsHandler.go:135] du and find on following dirs took 57.562700809s: [/rootfs/DATA/docker/overlay2/d8c002c4dc33c22129124e70bf7ca15fd312cd8867c040708d11d7d462ee58df/diff /rootfs/DATA/docker/containers/16eb9120ce2da24d867ee287c093ce7221f1d3ed39e69c3a8d128313a5dc0d63]; will not log again for this container unless duration exceeds 4s
这说明, cAdvisor 会统计每一个容器占用的磁盘使用大小, 这个大小是通过 du 命令来处理的, 而且, 这个统计耗费的时间很长. 我们可以实际去看一下, 发现这个目录, 确实比较大, 有些在 2-3G. 这说明, 这个机器上, 必然存在一些容器, 里边在搞事情, 写了很多的文件, 导致 du 命令在统计的时候, 比较耗时.
问题初步总结
K8S 节点, 有些容器存储或写入了比较多的文件, 造成 cAdvisor 统计容器磁盘使用耗时, 进而引发此 cAdivosr 内存占用升高.
排查深入探究
既然上面已经初步定为问题, 但是我们依然会疑惑, 为什么 cAdivosr 统计容器磁盘耗时会引发内存飙升呢?
我们需要借助一些工具来进一步排查
通过 go tool pprof 分析内存
通过查看 cAdvisor 源码分析流程
在源码中, 打断点, 验证猜想
通过 go tool pprof 分析内存
首先, 将 DaemonSet 启动的 cAdvisor, 使用 Host 模式启动, 这样我们就可以直接通过访问宿主机上, cAdvisor 开放的端口, 来做性能采样了.
go tool pprof -cum -svg -alloc_space http://x.x.x.x:28762/debug/pprof/heap
上面的步骤, 会生成内存性能采样图, 类似如下:
详细采样图, 可以通过此连接查看: https://hansedong.github.io/2018/10/24/5/5-2.svg
从图中, 先看红色部分, 颜色越深, 表示这部分资源消耗越严重, 我们这个采样图是采集的内存, 可以看到, 有 2366.70M, 是 Gather 函数的, 但其实, 这个函数本身, 并没有多少内存消耗, 它的内存占用这么大, 是 collectContainersInfo 函数分配的. 其实不论怎样, Gather 函数都脱离不了干系. 那么, 我们从源码看一下
源码分析
首先, 入口函数 main 中, 注册了 / metrics 对应的 handler, 因为 cAdvisor 要开发 /metirics 路径, 让 Prometheus 来定时采集
- // cadvisor.go#82
- func main() {
- defer glog.Flush()
- flag.Parse()
- // 注册 HTTP 路径 *prometheusEndpoint 值就是 /metirics
- cadvisorhttp.RegisterPrometheusHandler(mux, containerManager, *prometheusEndpoint, containerLabelFunc, includedMetrics)
- glog.V(1).Infof("Starting cAdvisor version: %s-%s on port %d", version.Info["version"], version.Info["revision"], *argPort)
- addr := fmt.Sprintf("%s:%d", *argIp, *argPort)
- glog.Fatal(http.ListenAndServe(addr, mux))
- }
然后, 看一下, 是谁在处理 /metrics 路由对应的操作
- // 代码文件: http/handler.go#97
- func RegisterPrometheusHandler(mux httpmux.Mux, containerManager manager.Manager, prometheusEndpoint string,
- f metrics.ContainerLabelsFunc, includedMetrics container.MetricSet) {
- r := prometheus.NewRegistry()
- r.MustRegister(
- metrics.NewPrometheusCollector(containerManager, f, includedMetrics),
- prometheus.NewGoCollector(),
- prometheus.NewProcessCollector(os.Getpid(), ""),
- )
- // 可以看到, 真正执行 /metrics 的函数, 是 promhttp.HandlerFor
- mux.Handle(prometheusEndpoint, promhttp.HandlerFor(r, promhttp.HandlerOpts{
- ErrorHandling: promhttp.ContinueOnError
- }))
- }
可以看到, 真正执行 /metrics 的函数, 是 promhttp.HandlerFor, 具体深入 HandlerFor 看一下
- // 代码文件: vendor/GitHub.com/prometheus/client_golang/prometheus/promhttp/http.go#82
- func HandlerFor(reg prometheus.Gatherer, opts HandlerOpts) http.Handler {
- return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
- // 这里就是真正的 Gather 调用
- mfs, err := reg.Gather()
- ...
- })
- }
至此, 可以说明, 每一次 HTTP 调用 (调用 x.x.x.x:8080/metrics), 都会又一次 Gather 调用.
所以我们猜想, 之所以 Gather 函数有这么大的内存占用, 主要是因为 Gather 函数调用次数多, 而每次 Gather 函数执行之间长, 导致形成了并发调用, 这种情况下, Gather 函数从执行到结束期间, 都不会释放内存, 并发调用, 就会导致内存积压.
修改源码, 重新构建部署, 验证猜想
那么, 我们在 Gather 调用处, 打断点, 看一下执行时间:
- // 代码文件: vendor/GitHub.com/prometheus/client_golang/prometheus/promhttp/http.go#82
- func HandlerFor(reg prometheus.Gatherer, opts HandlerOpts) http.Handler {
- return http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
- pp.Println("请求开始 --------")
- start:=time.Now()
- // 这里就是真正的 Gather 调用
- mfs, err := reg.Gather()
- ...
- timeCost := time.Since(start)
- pp.Println(fmt.Sprintf("请求结束, 耗时 %v", timeCost))
- })
- }
我们打印了 Gather 执行的耗时, 然后重新构建 cAdvisor 源码, 打一个私有镜像出来, 推送到私有镜像仓库. 然后我们使用这个测试镜像, 重新部署 cAdvisor.
现在, 我们挑一台之前 cAdvisor 频发 OOM Crash 的机器, 看一下它的 log
kubectl logs -n monitoring cadvisor-k9kpt -f
日志输出大致如下:
- "请求开始 --------"
- I1023 14:21:19.126794 1 fsHandler.go:135] du and find on following dirs took 15.420205027s: [/rootfs/var/lib/docker/overlay2/67ec1868b2c0ed5ce5b22ee014eb4d08993accd68546a3de6aa2a6355bdc1a78/diff /rootfs/var/lib/docker/containers/cd910753386b3325af8bd5a69fc01b261ca14c1bfaf754677662e903b755d34f]; will not log again for this container unless duration exceeds 56s
- I1023 14:21:19.305938 1 fsHandler.go:135] du and find on following dirs took 15.278733582s: [/rootfs/var/lib/docker/overlay2/10621b60f26962cb1a90d7a7dc1ce4e3c8a15f6e4e30861b8433c5c37727bb9e/diff /rootfs/var/lib/docker/containers/b2a4d11c37aa9c63b4759c5728956253fad46fa174c7fe4d91336a4ac7532127]; will not log again for this container unless duration exceeds 1m34s
- I1023 14:21:19.827757 1 fsHandler.go:135] du and find on following dirs took 13.897447077s: [/rootfs/var/lib/docker/overlay2/29b3b0dfc22053937e9c40e004a6d31af489573ff3a385020feb22d88d1a3d0a/diff /rootfs/var/lib/docker/containers/af962971a0643418d28c03b374e31a0c58dd6302524ea06dc8a23c4eccf5d663]; will not log again for this container unless duration exceeds 1m20s
- I1023 14:21:20.042949 1 fsHandler.go:135] du and find on following dirs took 14.514122984s: [/rootfs/var/lib/docker/overlay2/27f1d3cb3d421567754cb7abb986c16c3f3bec0874e983a2604aa7eda8834d9a/diff /rootfs/var/lib/docker/containers/60cad8688e31b557e2e98c47beaa1f3af2ea2e6cbfab0c1f399887b3eecec86c]; will not log again for this container unless duration exceeds 1m56s
- "请求结束, 耗时 58.093771464s"
日志其实我只是截图了一部分, 基本上可以看出来, Gather 请求十分耗时, 这个耗时, 就是由 du 操作耗时造成的, 有时候, du 耗时非常严重, 能将近 2 分钟.
这样, 基本上, 就印证了, Gather 函数处理慢, 而 Prometheus 每隔 3s 请求一次, 造成同时有非常多的 Gather 函数在并发处理, 也就导致了内存积压的情况.
彻底解决
综上, 其实我们只需要让 du 磁盘统计快了就可以了, du 的快慢, 是一个 CPU 密集和磁盘 IO 密集的操作, 要加快 du 操作, 就需要给到足够的运算能力.
回顾之前我们的 cAdvisor 的 DaemonSet 的 YAML 配置, 我们在资源的 limit 部分, 仅给到了一个 CPU, 我们加 CPU 核数增加到 6. 如下:
- resources:
- limits:
- CPU: "6"
- memory: 3000Mi
- requests:
- CPU: "2"
- memory: 500Mi
然后, 更新 DaemonSet 部署
kubectl apply -f cadvisor.ds.YAML
再次去观察 cAdvisor 的 pod 日志, 发现 du 耗时明显缩短到 2 秒钟以内, pod 内存占用过高的情况, 再也没有出现过. 问题得解!
来源: https://juejin.im/entry/5c996d22f265da610e5ed992