记一次 go 应用在 k8s pod 已用内存告警不准确分析
一、背景
起因：
自监控应用凌晨告警：Pod 内存使用率大于 80%（规格为 1c1G）。内存缓慢增长，持续到早上内存使用率停止在 81%左右。
疑点：
此模块是一个轻任务模块（基于 go 开发），请求量很低并且数据量非常少，平常内存占用一直以来都在 100MB 左右，出现内存不足的概率极小，而且运行了几个月无故障。
初步定位：
登录平常查看指标，确实有一个节点内存异常，但另一个节点正常（这模块有个特性是主备模式，同一时间只有一个节点工作，通过日志确定异常的节点正是工作节点）。
二、初步分析过程
登录 k8s 查看内存情况，通过 kubectl top pod 查看内存占用果然已经有 800MB+，但理论上这模块不应该占用这么多内存（截图时间点不一样，有部分回收）。
继续登录 pod 内，通过 cat /sys/fs/cgroup/memory/ 查看内存统计 （注意，在 pod 中使用 free -m 等类似的命令只能统计到宿主机的内存信息，固无用）
其中的 rss 标识当前应用进程实际使用内存量，55017472 = 约 52MB，此数据证实了一般的设定：这个应用一般占用都在 100MB 以内。
三、怀疑监控指标不准确？
通过了解到，激活自监控告警的指标是通过 k8s 的 container_memory_working_set_bytes 指标超过 80%告警。
通过查阅 k8s 源码 promethus.go 的 Memory.WorkingSet 相关引用发现，此参数是通过计算 Memory.Usage - total_inactive_file 得出（即本案例是 962097152 - 111620096 = 811MB）
（其中的 Memory.Usage 即为 memory.usage_in_bytes 文件中的值：962097152 ）
按照此情况看，数据取值确实没问题，同时，关注到一个指标 total_active_file （795275264 = 75.8MB），此参数加上 rss 刚好与已用内存接近，源码中未找到此指标的相关信息，通过查阅官方资料发现，此参数认为是一个不能被计算为可用内存的值。
也就是说 k8s 作者们认为 此 active_file 内存不认定为可用内存（官方地址为：https://kubernetes.io/docs/concepts/scheduling-eviction/node-pressure-eviction/#active-file-memory-is-not-considered-as-available-memory ）
此参数作为文件缓存是否要被计算进已用内存中，github 上的讨论已经有了 6 年之久仍然是 Open 状态 (地址为： https://github.com/kubernetes/kubernetes/issues/43916)。
四、应用分析
此应用只有日志才用到写文件的操作，是否是日志文件导致的 file cache 呢？ 进入到日志文件目录 ，通过 > xxx.log 清理文件后，再次 cat memory.stat
其中的 total_active_file 立即缩小，在通过之前的命令查看内存占用，立即恢复正常，也就是 日志文件导致的 total_active_file 增长从而导致 Pod 内存使用量增大。
五、回溯代码 & 修复措施
此应用使用了 zap 日志框架，通过配置 MaxSize 设定日志轮转文件大小为 1G，在故障时日志文件大小已经达到了 889M。
日志一直要达到 1G 才会激活轮转，此前系统将此 cache 住，但是 k8s 认为此内存无法被利用，就导致了内存一直在增长，直到产生告警。
解决方案：
为保证 Pod 不被 OOM Kill，通过修改 MaxSize 修改文件大小进行轮转（比如改为 200-300M），file cache 即可在日志轮转后释放。
文章转载自：mikevictor
还未添加个人签名 2023-06-19 加入
还未添加个人简介
评论