记一次go应用在k8s pod已用内存告警不准确分析
<p>版权说明： 本文章版权归本人及博客园共同所有，转载请在文章前标明原文出处( https://www.cnblogs.com/mikevictor07/p/17968696.html )，以下内容为个人理解，仅供参考。</p><p> </p>
<p><span style="font-size: 18px"><strong>一、背景</strong></span></p>
<p><span style="font-size: 15px"><strong>起因：</strong>自监控应用凌晨告警：<span style="color: rgba(255, 0, 0, 1)">Pod 内存使用率大于80%（规格为1c1G）</span>。内存缓慢增长，持续到早上内存使用率停止在81%左右。</span></p>
<p><span style="font-size: 15px"><strong>疑点：</strong>此模块是一个轻任务模块（基于go开发），请求量很低并且数据量非常少，平常内存占用一直以来都在100MB左右，出现内存不足的概率极小，而且运行了几个月无故障。</span></p>
<p><span style="font-size: 15px"><strong>初步定位：</strong>登录平常查看指标，确实有一个节点内存异常，但另一个节点正常（这模块有个特性是主备模式，<strong>同一时间只有一个节点工作</strong>，通过日志确定异常的节点正是工作节点）。</span></p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240116230801256-1293738661.png" alt="" width="506" height="117" loading="lazy"></p>
<p> </p>
<p> </p>
<p> </p>
<p><span style="font-size: 18px"><strong>二、初步分析过程</strong></span></p>
<p><span style="font-size: 15px">登录k8s查看内存情况，通过 kubectl top pod 查看内存占用果然已经有800MB+，但理论上这模块不应该占用这么多内存（截图时间点不一样，有部分回收）。</span></p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240117003622785-468555105.png" alt="" loading="lazy"></p>
<p> </p>
<p><span style="font-size: 15px"> 继续登录pod内，通过 cat /sys/fs/cgroup/memory/ 查看内存统计 （注意，在pod中使用 free -m 等类似的命令只能统计到宿主机的内存信息，固无用）</span></p>
<div class="cnblogs_code">
<pre># cd/sys/fs/cgroup/memory/<br># cat memory.usage_in_bytes<br><span style="color: rgba(255, 0, 0, 1)">显示输出 962097152（即约917MB，即将超过1GB限额，超过则会激活OOM Kill）</span><br><br># cat memory.stat后输出如下图</pre>
</div>
<p> </p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240116225259308-1019551658.png" alt="" width="260" height="416" loading="lazy"></p>
<p><span style="font-size: 15px"> 其中的 <strong>rss</strong> 标识当前应用进程实际使用内存量，<span style="color: rgba(255, 0, 0, 1)">55017472 = 约52MB</span>，此数据证实了一般的设定：这个应用一般占用都在100MB以内。</span></p>
<p> </p>
<p><span style="font-size: 18px"><strong>三、怀疑监控指标不准确？</strong></span></p>
<p><span style="font-size: 15px">通过了解到，激活自监控告警的指标是通过k8s的 <span style="color: rgba(255, 0, 0, 1)"><strong>container_memory_working_set_bytes</strong> </span>指标超过80%告警。</span></p>
<p><span style="font-size: 15px">通过查阅k8s源码 promethus.go 的 Memory.WorkingSet 相关引用发现，此参数是通过计算 <strong>Memory.Usage - total_inactive_file</strong> 得出（即本案例是 <span style="color: rgba(255, 0, 0, 1)">962097152 - 111620096 = 811MB</span>）</span></p>
<p><span style="font-size: 15px"> （其中的 <strong>Memory.Usage 即为memory.usage_in_bytes文件中的值：962097152 </strong>）</span></p>
<p> </p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240117000908372-1496934016.png" alt="" width="547" height="422" loading="lazy"></p>
<p> </p>
<p> </p>
<p><span style="font-size: 15px">按照此情况看，数据取值确实没问题，同时，关注到一个指标 <span style="color: rgba(255, 0, 0, 1)"> <strong>total_active_file</strong> （795275264 = 758MB），此参数加上rss刚好与已用内存接近</span>，源码中未找到此指标的相关信息，通过查阅官方资料发现，此参数认为是一个不能被计算为可用内存的值。</span></p>
<p>也就是说 k8s 作者们认为 <strong><span style="color: rgba(255, 0, 0, 1)">此active_file内存不认定为可用内存</span></strong>（官方地址为：https://kubernetes.io/docs/concepts/scheduling-eviction/node-pressure-eviction/#active-file-memory-is-not-considered-as-available-memory ）</p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240117004851012-245339478.png" alt="" width="584" height="325" loading="lazy"></p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240117004926226-216910388.png" alt="" width="512" height="384" loading="lazy"></p>
<p> </p>
<p><span style="font-size: 15px">此参数作为文件缓存是否要被计算进已用内存中，github上的讨论已经有了6年之久仍然是Open状态 (地址为： https://github.com/kubernetes/kubernetes/issues/43916)。</span></p>
<p> </p>
<p><strong><span style="font-size: 18px">四、应用分析</span></strong></p>
<p>此应用只有日志才用到写文件的操作，是否是日志文件导致的file cache呢？ 进入到日志文件目录 ，通过 > xxx.log 清理文件后，再次 cat memory.stat</p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240117004414340-55130811.png" alt="" width="302" height="490" loading="lazy"></p>
<p> </p>
<p><span style="font-size: 15px">其中的 total_active_file 立即缩小，在通过之前的命令查看内存占用，立即恢复正常，也就是 <strong><span style="color: rgba(255, 0, 0, 1)">日志文件导致的 total_active_file 增长从而导致Pod内存使用量增大</span></strong>。</span></p>
<p> </p>
<p><span style="font-size: 18px"><strong>五、回溯代码 & 修复措施</strong></span></p>
<p><span style="color: rgba(255, 0, 0, 1)">此应用使用了 zap日志框架，通过配置 MaxSize 设定日志轮转文件大小为1G，在故障时日志文件大小已经达到了 889M。</span></p>
<p><img src="https://img2024.cnblogs.com/blog/422439/202401/422439-20240117005046795-817856219.png" alt="" width="474" height="160" loading="lazy"></p>
<p> </p>
<p>日志一直要达到1G才会激活轮转，此前系统将此cache住，但是k8s认为此内存无法被利用，就导致了内存一直在增长，直到产生告警。</p>
<p><span style="color: rgba(255, 0, 0, 1)"><strong>解决方案：</strong></span>为保证Pod 不被 OOM Kill，通过修改MaxSize 修改文件大小进行轮转（比如改为200-300M），file cache即可在日志轮转后释放。</p>
<p> </p><br><br>
来源：https://www.cnblogs.com/mikevictor07/p/17968696
頁:
[1]