记一次Linux server偶发CPU飙升问题的跟进与解决
- 2022 年 7 月 31 日
- 笔记
- kafka batch send, linger_ms, linux, linux watermark
背景
进入6月后，随着一个主要功能版本api的上线，服务端的QPS翻了一倍，平时服务器的CPU使用稳定在30%上下，高峰期则在60%上下，但是偶尔会有单台机器出现持续数分钟突然飙到90%以上，导致大量api响应缓慢超过客户端等待时间，触发其主动断开连接产生大量nginx499。
问题分析与解决
问题期间器资源情况
仔细查看问题期间的zabbix监控数据，发现90%的CPU占用中有10%上下是sys time, 5%上下是softirq time，两者相加可占到接近20%, interrupt和context switch数由之前的10k/s飙升至20k+/s。
定位kafka log发送代码
首先猜测就是某个新加功能实现有bug，可能造成长时间未执行完成，多个类似请求长期占用CPU而后又被切换为其他线程，反复在这些耗时请求中来回切换却没法完成任意一个请求，并造成后续请求在队列中排队等待，导致大量请求超时响应。
直接入手分析定位新增的某个复杂功能接口，确认不存在死循环的可能，怀疑是接口太耗性能长期占用CPU导致后续请求来不及处理最终连锁反应导致雪崩。
仔细分析其实现，发现总共会触发30+次kafka log发送，之前一直认为使用异步批量发送kafka log的情况下，多发几次log应该不会存在什么问题，不过这里一个请求触发30+次 kafka log发送确实有点太多了。
本着怀疑的精神决定实际验证一番kafka log发送耗时，结果发现每次kafka调用耗时居然在0.2-2ms之间波动，这相当于该复杂接口功能请求光是发送kafka消息就需要6-60ms时间，与之前认为应该很快的假设不符！
进一步分析原因，发现原来沿用的kafka producer初始化配置有大坑，其设置了batch_size=20之前一直理解为是每20条log触发一次实际发送，结果起始batch_size的单位是字节，其表示的是每满20字节触发一次实际发送==！所以实际效果是每次kafka log send都会触发实际发送。通过修改batch_size为64k并设置linger_ms为500ms，验证kafka log一边为批量发送模式后，再次测试kafka消息单次调用耗时变为了<0.1ms。
修改线上api服务kafka参数，并将复杂接口kafka send操作从30+次优化为10+次，reload服务后，意外发现内存占用居然还降了50%（2G=>1G)，但是对于日常interrupt、context switch次数未观察到明显下降。
修改后连续几天未再出现CPU飙升偶发问题，但是坚持不到一周再次有机器出现类似问题，优化前平均1~2天一次，多的时候一天就有两三次，优化后出现频率降低为一周两三次，从这个角度来看优化具有一定效果。
尝试扩容解决
由于刚上了一个大版本功能，客户端确实新增了很多api调用，随着新版本覆盖用户数逐步升高，单机负载逐步升高，于是考虑再扩个容看能否解决问题，在某天下午快速扩容一台机器后，晚上又出现了该问题，该简单方案宣告失败。
定位Linux内存水位
在前两个方案尝试解决问题失败后，开始细究一下每5分钟打印一次的机器top快照，仔细硬瞅之下还真发现点端倪：查看了单台机器过去近10次CPU飙涨时段的指标，发现free内存一般在CPU飙涨前剩余不到200M，而CPU恢复正常后free内存一般都剩余>1G，这个看上去有点不同寻常。进一步按图索骥观察到kswapd_low_wmark_hit_quickly取值每天增长上千次，直觉上感觉是偏高的。
难道问题是free内存不足、回收引起的？然而zabbix监控上显示的可用内存一直都是>5G，理论上不应该存在不足才对，进一步探究了解到了free内存回收与内存水位的概念。
内存水位作用
Linux的设计思路是尽量多的使用空闲内存，除了保留一定量的真正空闲立马可用的内存作为free内存保证系统正常运转外，其他空闲内存会尽量用于系统缓存(buffer+cache)，当free内存不足时则从buffer、cache中回收为free内存即可，而一般我们说linux的可用内存都是指available内存，其实际包括free+可回收的buffer+cache内存，这也是zabbix监控中可用内存使用的指标。
那实际应该保留多少free内存以及何时触发回收free内存呢？这里就需要引入linux的内存水位(watermark)概念了，具体可参考这篇文章–Linux内核调整watermark_scale_factor以缓解direct reclaim。简单来说就是linux设置了min/low/high三个内存水位，对应free内存在不同水位线的行为如下：
- free > high，内存充足，什么都不用做
- free内存由>high下降至<low，唤醒kswapd开始内存回收–其他进程依然可以正常申请内存
- 若free内存一直下降至<min, 分配新内存的进程会直接触发自己同步内存回收操作–direct claim
- kswapd终于回收free内存至>high，休眠100ms
- 休眠100ms期间若free又下降至<low，则再次唤醒kswapd，并自增kswapd_low_wmark_hit_quickly值
- 休眠100ms后若free变为<high，kswapd需继续回收内存至>high，而后继续休眠100ms，并自增kswapd_low_wmark_hit_quickly值
- 休眠100ms后若free依然>high，kswapd将进入长期sleep等待下次被唤醒
内存水位计算与调整
而watermark的min/low/high三者的取值具体是由两个内核参数min_free_kbytes和watermark_scale_factor决定的，简单来说–参考
vm内核参数之内存水位min_free_kbytes和保留内存lowmem_reserve_ratio
:
watermark[WMARK_MIN] = (min_free_kbytes/4) * zone.pages/zone.allpages
watermark[WMARK_LOW] = 5/4watermark[WMARK_MIN]
watermark[WMARK_HIGH] = 3/2*watermark[WMARK_MIN]
min水位直接由min_free_kbytes决定(后面的zone.pages/zone.allpages表示不同内存区按占总物理内存的比例均分对应水位值)，而后min/low/high之间的差值则=1/4low，所以在一台8G(7969M)的线上机器上min/low/high取值默认为：
Node 0, zone DMA
per-node stats
nr_inactive_anon 21704
nr_active_anon 171130
nr_inactive_file 1490263
nr_active_file 153139
--
Node 0, zone DMA32
pages free 58451
min 6322
low 7902
high 9482
node_scanned 0
--
Node 0, zone Normal
pages free 13169
min 10540
low 13175
high 15810
node_scanned 0
主要的Normal区域的min/low/high差值也就105400.254KB=10M左右，如果线上有突增流量，很可能一下子就跑到low乃至min水位之下了。
内存水位调整效果
通过watermark_scale_factor参数将默认值10/10000调整为200/10000，内存水位取值变为：
Node 0, zone DMA
per-node stats
nr_inactive_anon 21910
nr_active_anon 278859
nr_inactive_file 1366921
nr_active_file 150022
--
Node 0, zone DMA32
pages free 56340
min 6342
low 21660
high 36978
node_scanned 0
--
Node 0, zone Normal
pages free 35915
min 10520
low 35926
high 61332
node_scanned 0
Normal zone内存水位min/low/high差值变为:low-min=99MB，调整完后对单台机器逐步放量至近期峰值的150%流量测试，未再出现该问题，至今2周过去了，线上机器未再出现该问题。
另一个验证水位调整效果的数据是查看并自增kswapd_low_wmark_hit_quickly值变化值，在调整水位值之前，每天kswapd_low_wmark_hit_quickly新增在1000左右，调整后变为100次，降低了一个数量级。
转载请注明出处，原文地址： //www.cnblogs.com/AcAc-t/p/linux_watermark_and_kafka_batch_send.html
参考
//zhuanlan.zhihu.com/p/440688960
//help.aliyun.com/document_detail/316788.html
//unix.stackexchange.com/questions/211646/what-is-kswapd-low-wmark-hit-quickly-from-proc-vmstat
//blog.csdn.net/u010039418/article/details/105281933
//kafka-python.readthedocs.io/en/master/apidoc/KafkaProducer.html
//doc.opensuse.org/documentation/leap/archive/42.3/tuning/html/book.sle.tuning/cha.tuning.memory.html
