記一次Linux server偶發CPU飆升問題的跟進與解決

2022-07-31 18:01:42

背景

進入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次,降低了一個數量級。
轉載請註明出處,原文地址: https://www.cnblogs.com/AcAc-t/p/linux_watermark_and_kafka_batch_send.html

參考

https://zhuanlan.zhihu.com/p/440688960
https://help.aliyun.com/document_detail/316788.html
https://unix.stackexchange.com/questions/211646/what-is-kswapd-low-wmark-hit-quickly-from-proc-vmstat
https://blog.csdn.net/u010039418/article/details/105281933
https://kafka-python.readthedocs.io/en/master/apidoc/KafkaProducer.html
https://doc.opensuse.org/documentation/leap/archive/42.3/tuning/html/book.sle.tuning/cha.tuning.memory.html