一、背景
起因:
自监控应用凌晨告警:Pod 内存使用率大于80%(规格为1c1G)。内存缓慢增长,持续到早上内存使用率停止在81%左右。
疑点:
此模块是一个轻任务模块(基于go开发),请求量很低并且数据量非常少,平常内存占用一直以来都在100MB左右,出现内存不足的概率极小,而且运行了几个月无故障。
初步定位:
登录平常查看指标,确实有一个节点内存异常,但另一个节点正常(这模块有个特性是主备模式,同一时间只有一个节点工作,通过日志确定异常的节点正是工作节点)。
二、初步分析过程
登录k8s查看内存情况,通过 kubectl top pod 查看内存占用果然已经有800MB+,但理论上这模块不应该占用这么多内存(截图时间点不一样,有部分回收)。
继续登录pod内,通过 cat /sys/fs/cgroup/memory/ 查看内存统计 (注意,在pod中使用 free -m 等类似的命令只能统计到宿主机的内存信息,固无用)
# cd /sys/fs/cgroup/memory/
# cat memory.usage_in_bytes
显示输出 962097152(即约917MB,即将超过1GB限额,超过则会激活OOM Kill)
# cat memory.stat 后输出如下图
其中的 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