一、問題說明
業務上接到報警提示服務器內存爆了，登錄查看發現機器剩餘內存還很多，懷疑是被OOM了，查看/var/log/messages：
kernel: [25918282.632003] Out of memory: Kill process 18665 (redis-server) score 919 or sacrifice child
kernel: [25918282.637201] Killed process 18665 (redis-server) total-vm:17749556kB, anon-rss:14373204kB, file-rss:1236kB
kernel: [25918791.441427] redis-server invoked oom-killer: gfp_mask=0x24280ca, order=0, oom_score_adj=0
發現redis-server被oom kill了，但是登錄查看發現redis-server並沒有down掉.
二、問題排查
既然redis-server並沒有被kill，那被kill的有可能是redis的子進程。
進入redis的data目錄查看：
-rw-rw-r-- 1 myuser myuser 18044223152 4月 8 12:01 appendonly.aof
-rw-rw-r-- 1 myuser myuser 3603981186 4月 8 12:01 temp-rewriteaof-25595.aof
-rw-rw-r-- 1 myuser myuser 4083774382 4月 8 11:46 temp-rewriteaof-18665.aof
-rw-rw-r-- 1 myuser myuser 4326578230 4月 8 11:21 temp-rewriteaof-8116.aof
發現有好幾個temp-rewriteaof文件，這是redis在進行aofrewrite時產生的臨時文件。
注意看其中一個的名字：temp-rewriteaof-18665.aof ，後面的18665即rewrite子進程的pid，上面被oom kill的進程ID也是18665，說明是redis的aofrewrite子進程被kill了。
而多個temp文件，而且時間都是最近的，說明redis已經嘗試了多次rewrite，都因為內存不足被中途kill。
查看監控發現，近期確實多次出現了內存突增的情況：
為什麼aof重寫會導致內存爆漲？這要從它的原理說起。
AOF 是redis的一種持久化方式，用來記錄所有的寫操作，但是隨著時間增加，aof文件會越來越大，所以需要進行重寫，將內存中的數據重新以命令的方式寫入aof文件。
在重寫的過程中，由於redis還會有新的寫入，為了避免數據丟失，會開闢一塊內存用於存放重寫期間產生的寫入操作，等到重寫完畢後會將這塊內存中的操作再追加到aof文件中。
從原理中可以瞭解到，如果在重寫過程中redis的寫入很頻繁或寫入量很大，就會導致佔用大量額外的內存來緩存寫操作，導致內存爆漲。
查看redis的訪問情況：
從監控中可以看到，redis實際的訪問OPS並不高，那麼剩下的可能性就只有寫入量了。
登錄Redis使用monitor監控了一段時間的訪問，記錄到文件中：
[myuser@redis-00 ~]$ time redis-cli -p 6379 monitor > monitor.log
^C
real 0m24.219s
user 0m0.552s
sys 0m0.036s
通過查看monitor.log發現，存在這樣一條語句：
1523351418.461744 [0 10.10.10.10:6379] "SET" "xx_xx_id_17791"
"[615249,615316,615488,616246,616498,616580,617117,617291,617510,617879,
618052,618377,618416,619010,619185,619603,619816,620190,620230,620387,
620445,620524,621012,621214,621219,621589,621596,621616,621623,621669,
621670,621682,621683,621820,621994,622168,622207,622245,622384,622442,
622450,622608,622644,622654,622658,622704,622784,622785,622786,622810,
622834,622876,622887,622934,622936,622937,622939,622943,622967,......]"
- 為了看起來方便，我做了換行處理，並且省略了大部分的key內容，但實際上該set命令的內容一直拉不到頭。
過濾該key進行分析：
# monitor.log 大小
[myuser@redis-00 ~]$ du -sh monitor.log
62M monitor.log
[myuser@redis-00 ~]$ wc -l monitor.log
12114 monitor.log
[myuser@redis-00 ~]$ grep 'xx_xx_id_17791' monitor.log | grep -v 'GET' > xx_xx_id_17791.log
# xx_xx_id_17791 key 大小
[myuser@redis-00 ~]$ du -sh xx_xx_id_17791.log
61M xx_xx_id_17791.log
[myuser@redis-00 ~]$ wc -l xx_xx_id_17791.log
17 xx_xx_id_17791.log
62M的monitor文件，17行 xx_xx_id_17791 的set命令一共佔了61M，很明顯就是這個key搞的鬼了，去找開發確認，果然是程序出了問題。
三、處理結果
1. 臨時處理
在接到報警時是在夜間，而aof rewrite一直失敗，因此做了臨時處理：
127.0.0.1:6379> config get auto-aof-rewrite-percentage
1) "auto-aof-rewrite-percentage"
2) "200"
127.0.0.1:6379> config set auto-aof-rewrite-percentage 800
OK
auto-aof-rewrite-percentage 是設置aof rewrite觸發時機的一個參數，噹噹前的aof文件大小超過上一次rewrite後aof文件的百分比後觸發rewrite。
200 改為 800 ，即當前的aof文件超過上一次重寫後aof文件的8倍時才會再次rewrite，這樣可以保證短期內不會再次進行重寫操作。
2. 問題解決
找開發進行確認後，將該key進行了刪除，開發也說已經修改了程序，auto-aof-rewrite-percentage重新改為200。
結果只是消停了一陣子，不久後又出現一個類似的超大key，還是半夜報的警。
又找開發再次修改才真的算是改好了，和開發確認了下業務場景，發現該redis現在當做純緩存來用了，不需要數據持久化，於是果斷關掉AOF。
關閉aof持久化：
redis-03:6379> config get appendonly
1) "appendonly"
2) "yes"
redis-03:6379> config set appendonly no
OK
問題解決，萬事大吉。
四、後記
這個問題導致了多次的夜間報警，弄的心裡還是比較煩躁的，但是針對線上暴露的一些問題還是要和開發詳細溝通，一方面對於問題的原因、相關原理要儘可能的給開發講清楚，而不是隻要解決問題就萬事大吉，這樣可以避免類似的問題重複發生；另一方面，對於運維人員而言也要充分了解相關的業務場景才行。
閱讀更多 劉弋 的文章
