常見線上故障的最優(yōu)解法，運(yùn)維老司機(jī)也未必都懂
很多人在面試時(shí)，會(huì)被問到這樣的問題： 遇到過什么系統(tǒng)故障？ 怎么解決的？ 下面是筆者根據(jù)自己15年互聯(lián)網(wǎng)研發(fā)經(jīng)歷總結(jié)的多個(gè)線上故障真實(shí)案例。
本文圖不多，但內(nèi)容很干！理解為主，學(xué)以致用！
故障一：JVM頻繁FULL GC快速排查
在分享此案例前，先聊聊哪些場(chǎng)景會(huì)導(dǎo)致頻繁Full GC：
-
內(nèi)存泄漏（代碼有問題，對(duì)象引用沒及時(shí)釋放，導(dǎo)致對(duì)象不能及時(shí)回收）。
-
死循環(huán)。
-
大對(duì)象。
尤其是大對(duì)象，80%以上的情況就是他。
那么大對(duì)象從哪里來的呢？
-
數(shù)據(jù)庫(kù)（包括MySQL和MongoDB等NoSQL數(shù)據(jù)庫(kù)），結(jié)果集太大。
-
第三方接口傳輸?shù)拇髮?duì)象。
-
消息隊(duì)列，消息太大。
根據(jù)多年一線互聯(lián)網(wǎng)經(jīng)驗(yàn)，絕大部分情況是數(shù)據(jù)庫(kù)大結(jié)果集導(dǎo)致。
好，現(xiàn)在我們開始介紹這次線上故障：
在沒有任何發(fā)布的情況下，POP服務(wù)（ 接入 第三方商家的服務(wù)）突然開始瘋狂Full GC，觀察堆內(nèi)存監(jiān)控沒內(nèi)存泄漏，回滾到前一版本，問題仍然存在，尷尬了?。。?/p>
按照常規(guī)做法，一般先用jmap導(dǎo)出堆內(nèi)存快照（jmap -dump:format=b,file=文件名 [pid]），然后用mat等工具分析出什么對(duì)象占用了大量空間，再查看相關(guān)引用找到問題代碼。這種方式定位問題周期會(huì)比較長(zhǎng)，如果是關(guān)鍵服務(wù)，長(zhǎng)時(shí)間不能定位解決問題，影響太大。
下面來看看我們的做法：
先按照常規(guī)做法分析堆內(nèi)存快照，與此同時(shí)另外的同學(xué)去查看數(shù)據(jù)庫(kù)服務(wù)器網(wǎng)絡(luò)IO監(jiān)控，如果 數(shù)據(jù)庫(kù)服務(wù)器 網(wǎng)絡(luò)IO有明顯上升，并且時(shí)間點(diǎn)吻合，基本可以確定是數(shù)據(jù)庫(kù)大結(jié)果集導(dǎo)致了Full GC，趕緊找DBA快速定位大SQL（對(duì)DBA來說很簡(jiǎn)單，分分鐘搞定，如果DBA不知道怎么定位，那他要被開除了，哈哈），定位到SQL后再定位代碼就非常簡(jiǎn)單了。
按照這種辦法，我們很快定位了問題。原來是一個(gè)接口必傳的參數(shù)沒傳進(jìn)來，也沒加校驗(yàn)，導(dǎo)致SQL語句where后面少了兩個(gè)條件，一次查幾萬條記錄出來，真坑??！ 這種方法是不是要快很多，哈哈，5分鐘搞定。
當(dāng)時(shí)的DAO層是基于Mybatis實(shí)現(xiàn)的，出問題的SQL語句如下：
- <select id="selectOrders" resultType="com.***.Order" >
- select * from user where 1=1 <if test=" orderID != null "> and order_id = #{orderID} </if >
- <if test="userID !=null"> and user_id=#{userID} </if > <if test="startTime !=null"> and create_time >= #{createTime} </if > <if test="endTime !=null"> and create_time <= #{userID} </if > </select>
上面SQL語句意思是根據(jù)orderID查一個(gè)訂單，或者根據(jù)userID查一個(gè)用戶所有的訂單，兩個(gè)參數(shù)至少要傳一個(gè)。但是兩個(gè)參數(shù)都沒傳，只傳了startTime和endTime。所以一次Select就查出了幾萬條記錄。
所以我們?cè)谑褂肕ybatis的時(shí)候一定要慎用if test，一不小心就會(huì)帶來災(zāi)難。后來我們將上面的SQL拆成了兩個(gè)：
根據(jù)訂單ID查詢訂單：
- <select id="selectOrderByID" resultType="com.***.Order" >
- select * from user where
- order_id = #{orderID} </select>
根據(jù)userID查詢訂單：
- <select id="selectOrdersByUserID" resultType="com.***.Order" >
- select * from user where user_id=#{userID}
- <if test="startTime !=null"> and create_time >= #{createTime} </if > <if test="endTime !=null"> and create_time <= #{userID} </if > </select>
故障二：內(nèi)存泄漏
介紹案例前，先了解一下內(nèi)存泄漏和內(nèi)存溢出的區(qū)別。
內(nèi)存溢出：程序沒有足夠的內(nèi)存使用時(shí)，就會(huì)發(fā)生內(nèi)存溢出。內(nèi)存溢出后程序基本上就無法正常運(yùn)行了。
內(nèi)存泄漏：當(dāng)程序不能及時(shí)釋放內(nèi)存，導(dǎo)致占用內(nèi)存逐漸增加，就是內(nèi)存泄漏。內(nèi)存泄漏一般不會(huì)導(dǎo)致程序無法運(yùn)行。不過持續(xù)的內(nèi)存泄漏，累積到內(nèi)存上限時(shí)，就會(huì)發(fā)生內(nèi)存溢出。在Java中，如果發(fā)生內(nèi)存泄漏，會(huì)導(dǎo)致GC回收不徹底，每次GC后，堆內(nèi)存使用率逐漸增高。
下圖是JVM發(fā)生內(nèi)存泄漏的監(jiān)控圖，我們可以看到每次GC后堆內(nèi)存使用率都比以前提高了：
圖片來源于網(wǎng)絡(luò)
當(dāng)時(shí)內(nèi)存泄漏的場(chǎng)景是，用本地緩存（公司基礎(chǔ)架構(gòu)組自己研發(fā)的框架）存放了商品數(shù)據(jù)，商品數(shù)量不算太多，幾十萬的樣子。如果只存熱點(diǎn)商品，內(nèi)存占用不會(huì)太大，但是如果存放全量商品，內(nèi)存就不夠了。
初期我們給每個(gè)緩存記錄都加了7天的過期時(shí)間，這樣就可以保證緩存中絕大部分都是熱點(diǎn)商品。不過后來本地緩存框架經(jīng)過一次重構(gòu)，過期時(shí)間被去掉了。沒有了過期時(shí)間，日積月累本地緩存越來越大，很多冷數(shù)據(jù)也被加載到了緩存。
直到有一天接到告警短信，提示堆內(nèi)存過高。趕緊通過jmap（ jmap -dump:format=b,file=文件名 [pid] ）下載了堆內(nèi)存快照，然后用eclipse的mat工具分析快照，發(fā)現(xiàn)了本地緩存中有大量的商品記錄。定位問題后趕緊讓架構(gòu)組加上了過期時(shí)間，然后逐個(gè)節(jié)點(diǎn)重啟了服務(wù)。
虧了我們加了服務(wù)器內(nèi)存和JVM堆內(nèi)存監(jiān)控，及時(shí)發(fā)現(xiàn)了內(nèi)存泄漏的問題。否則隨著泄漏問題日積月累，如果哪天真的OOM就慘了。
所以技術(shù)團(tuán)隊(duì)除了做好CPU，內(nèi)存等運(yùn)維監(jiān)控，JVM監(jiān)控也非常重要。
故障三：冪等問題
很多年前，筆者在一家大型電商公司做Java程序員，當(dāng)時(shí)開發(fā)了積分服務(wù)。當(dāng)時(shí)的業(yè)務(wù)邏輯是，用戶訂單完結(jié)后，訂單系統(tǒng)發(fā)送消息到消息隊(duì)列，積分服務(wù)接到消息后給用戶積分，在用戶現(xiàn)有的積分上加上新產(chǎn)生的積分。
由于網(wǎng)絡(luò)等原因會(huì)有消息重復(fù)發(fā)送的情況，這樣也就導(dǎo)致了消息的重復(fù)消費(fèi)。當(dāng)時(shí)筆者還是個(gè)初入職場(chǎng)的小菜鳥，并沒有考慮到這種情況。所以上線后偶爾會(huì)出現(xiàn)重復(fù)積分的情況，也就是一個(gè)訂單完結(jié)后會(huì)給用戶加兩次或多次積分。
后來我們加了一個(gè)積分記錄表，每次消費(fèi)消息給用戶增加積分前，先根據(jù)訂單號(hào)查一遍積分記錄表，如果沒有積分記錄才給用戶增加積分。這也就是所謂的“冪等性”，即多次重復(fù)操作不影響最終的結(jié)果。
實(shí)際開發(fā)中很多需要重試或重復(fù)消費(fèi)的場(chǎng)景都要實(shí)現(xiàn)冪等，以保證結(jié)果的正確性。例如，為了避免重復(fù)支付，支付接口也要實(shí)現(xiàn)冪等。
故障四：緩存雪崩
我們經(jīng)常會(huì)遇到需要初始化緩存的情況。比如，我們?cè)?jīng)經(jīng)歷過用戶系統(tǒng)重構(gòu)，用戶系統(tǒng)表結(jié)構(gòu)發(fā)生了變化，緩存信息也要變。重構(gòu)完成后上線前，需要初始化緩存，將用戶信息批量存入Reids。
每條用戶信息緩存記錄過期時(shí)間是1天，記錄過期后再?gòu)臄?shù)據(jù)庫(kù)查詢最新的數(shù)據(jù)并拉取到Redis中?；叶壬暇€時(shí)一切正常，所以很快就全量發(fā)布了。整個(gè)上線過程非常順利，碼農(nóng)們也很開心。
不過，第二天，災(zāi)難發(fā)生了！到某一個(gè)時(shí)間點(diǎn)，各種報(bào)警紛至沓來。用戶系統(tǒng)響應(yīng)突然變得非常慢，甚至一度沒有任何響應(yīng)。查看監(jiān)控，用戶服務(wù) CPU突然飆高（IO wait很高），MySQL訪問量激增， MySQL 服務(wù)器壓力也隨之暴增，Reids緩存命中率也跌到了極點(diǎn)。
依賴于我們強(qiáng)大的監(jiān)控系統(tǒng)（運(yùn)維監(jiān)控，數(shù)據(jù)庫(kù)監(jiān)控，APM全鏈路性能監(jiān)控），很快定位了問題。原因就是Reids中大量用戶記錄集中失效，獲取用戶信息的請(qǐng)求在Redis中查不到用戶記錄，導(dǎo)致大量的請(qǐng)求穿透到數(shù)據(jù)庫(kù)，瞬間給數(shù)據(jù)庫(kù)帶來巨大壓力。同時(shí)用戶服務(wù)和相關(guān)聯(lián)的其他服務(wù)也都受到了影響。
這種緩存集中失效，導(dǎo)致大量請(qǐng)求同時(shí)穿透到數(shù)據(jù)庫(kù)的情況，就是所謂的“緩存雪崩”。如果沒到緩存失效時(shí)間點(diǎn)，性能測(cè)試也測(cè)不出問題。所以一定要引起大家注意。
所以，需要初始化緩存數(shù)據(jù)時(shí)，一定 要保證每個(gè)緩存記錄過期時(shí)間的離散性。 例如，我們給這些用戶信息設(shè)置過期時(shí)間， 可以采用一個(gè)較大的固定值加上一個(gè)較小的隨機(jī)值。比如過期時(shí)間可以是：24小時(shí) + 0到3600秒的隨機(jī)值。
故障五：磁盤IO導(dǎo)致線程阻塞
問題發(fā)生在2017年下半年，有一段時(shí)間地理網(wǎng)格服務(wù)時(shí)不常的會(huì)響應(yīng)變慢，每次持續(xù)幾秒鐘到幾十秒鐘就自動(dòng)恢復(fù)。
如果響應(yīng)變慢是持續(xù)的還好辦，直接用jstack抓線程堆棧，基本可以很快定位問題。關(guān)鍵持續(xù)時(shí)間只有最多幾十秒鐘，而且是偶發(fā)的，一天只發(fā)生一兩次，有時(shí)幾天才發(fā)生一次，發(fā)生時(shí)間點(diǎn)也不確定，人盯著然后用jstack手工抓線程堆棧顯然不現(xiàn)實(shí)。
好吧，既然手工的辦法不現(xiàn)實(shí)，咱們就來自動(dòng)的，寫一個(gè)shell腳本自動(dòng)定時(shí)執(zhí)行jstack，5秒執(zhí)行一次jstack，每次執(zhí)行結(jié)果放到不同日志文件中，只保存20000個(gè)日志文件。
Shell腳本如下：
- #!/bin/bash num=0 log="/tmp/jstack_thread_log/thread_info"
- cd /tmp if [ ! -d "jstack_thread_log" ]; then mkdir jstack_thread_log fi
- while ((num <= 10000)); do ID=`ps -ef | grep java | grep gaea | grep -v "grep" | awk '{print $2}'` if [ -n "$ID" ]; then jstack $ID >> ${log} fi num=$(( $num + 1 )) mod=$(( $num%100 )) if [ $mod -eq 0 ]; then back=$log$num mv $log $back fi sleep 5 done
下一次響應(yīng)變慢的時(shí)候，我們找到對(duì)應(yīng)時(shí)間點(diǎn)的jstack日志文件，發(fā)現(xiàn)里面有很多線程阻塞在logback輸出日志的過程，后來我們精簡(jiǎn)了log，并且把log輸出改成異步，問題解決了，這個(gè)腳本果真好用！建議大家保留，以后遇到類似問題時(shí)，可以拿來用！
故障六：數(shù)據(jù)庫(kù)死鎖問題
在分析案例之前，我們先了解一下MySQL InnoDB。 在MySQL InnoDB 引擎中主鍵是采用聚簇索引的形式，即在B樹的葉子節(jié)點(diǎn)中既存儲(chǔ)了索引值也存儲(chǔ)了數(shù)據(jù)記錄，即數(shù)據(jù)記錄和主鍵索引是存在一起的。
而普通索引的葉子節(jié)點(diǎn)存儲(chǔ)的只是主鍵索引的值，一次查詢找到普通索引的葉子節(jié)點(diǎn)后，還要根據(jù)葉子節(jié)點(diǎn)中的主鍵索引去找到聚簇索引葉子節(jié)點(diǎn)并拿到其中的具體數(shù)據(jù)記錄，這個(gè)過程也叫“回表”。
故障發(fā)生的場(chǎng)景是關(guān)于我們商城的訂單系統(tǒng)。有一個(gè)定時(shí)任務(wù)，每一小時(shí)跑一次，每次把所有一小時(shí)前未支付訂單取消掉。而客服后臺(tái)也可以批量取消訂單。
訂單表t_order結(jié)構(gòu)大至如下：
|
id |
訂單id，主鍵 |
|
status |
訂單狀態(tài) |
|
created_time |
訂單創(chuàng)建時(shí)間 |
id是表的主鍵，created_time字段上是普通索引。
聚簇索引（主鍵id）。
|
id （索引） |
status |
created_time |
|
1 |
UNPAID |
2020-01-01 07:30:00 |
|
2 |
UNPAID |
2020-01-01 08:33:00 |
|
3 |
UNPAID |
2020-01-01 09:30:00 |
|
4 |
UNPAID |
2020-01-01 09:39:00 |
|
5 |
UNPAID |
2020-01-01 09:50:00 |
普通索引（created_time字段）。
|
created_time （索引） |
id（主鍵） |
|
2020-01-01 09:50:00 |
5 |
|
2020-01-01 09:39:00 |
4 |
|
2020-01-01 09:30:00 |
3 |
|
2020-01-01 08:33:00 |
2 |
|
2020-01-01 07:30:00 |
1 |
定時(shí)任務(wù)每一小時(shí)跑一次，每次把所有一小時(shí)前兩小時(shí)內(nèi)的未支付訂單取消掉，比如上午11點(diǎn)會(huì)取消8點(diǎn)到10點(diǎn)的未支付訂單。SQL語句如下：
- update t_order set status = 'CANCELLED' where created_time > '2020-01-01 08:00:00' and created_time < '2020-01-01 10:00:00' and status = 'UNPAID'
客服批量取消訂單SQL如下：
- update t_order set status = 'CANCELLED' where id in (2, 3, 5) and status = 'UNPAID'
上面的兩條語句同時(shí)執(zhí)行就可能發(fā)生死鎖。我們來分析一下原因。
第一條定時(shí)任務(wù)的SQL，會(huì)先找到created_time普通索引并加鎖，然后再在找到主鍵索引并加鎖。
第一步，created_time普通索引加鎖。
第二步，主鍵索引加鎖。
第二條客服批量取消訂單SQL，直接走主鍵索引，直接在主鍵索引上加鎖。
我們可以看到，定時(shí)任務(wù)SQL對(duì)主鍵加鎖順序是5，4，3，2。客服批量取消訂單SQL對(duì)主鍵加鎖順序是2，3，5。當(dāng)?shù)谝粋€(gè)SQL對(duì)3加鎖后，正準(zhǔn)備對(duì)2加鎖時(shí)，發(fā)現(xiàn)2已經(jīng)被第二個(gè)SQL加鎖了，所以第一個(gè)SQL要等待2的鎖釋放。
而此時(shí)第二個(gè)SQL準(zhǔn)備對(duì)3加鎖，卻發(fā)現(xiàn)3已經(jīng)被第一個(gè)SQL加鎖了，就要等待3的鎖釋放。兩個(gè)SQL互相等待對(duì)方的鎖，也就發(fā)生了“死鎖”。
解決辦法就是從SQL語句上保證加鎖順序一致?；蛘甙芽头咳∠唵蜸QL改成每次SQL操作只能取消一個(gè)訂單，然后在程序里多次循環(huán)執(zhí)行SQL，如果批量操作的訂單數(shù)量不多，這種笨辦法也是可行的。
故障七：域名劫持
先看看DNS解析是怎么回事，當(dāng)我們?cè)L問www.baidu.com時(shí)，首先會(huì)根據(jù)www.baidu.com到DNS域名解析服務(wù)器去查詢百度服務(wù)器對(duì)應(yīng)的IP地址，然后再通過http協(xié)議訪問該IP地址對(duì)應(yīng)的網(wǎng)站。
而 DNS劫持是互聯(lián)網(wǎng)攻擊的一種方式，通過攻擊域名解析服務(wù)器（DNS）或者偽造域名解析服務(wù)器，把目標(biāo)網(wǎng)站域名解析到其他的IP。從而導(dǎo)致請(qǐng)求無法訪問目標(biāo)網(wǎng)站或者跳轉(zhuǎn)到其他網(wǎng)站。如下圖：
下面這張圖是我們?cè)?jīng)經(jīng)歷過的DNS劫持的案例：
看圖中的紅框部分，本來上方的圖片應(yīng)該是商品圖片，但是卻顯示成了廣告圖片。是不是圖片配錯(cuò)了？不是，是域名（DNS）被劫持了。
原本應(yīng)該顯示存儲(chǔ)在CDN上的商品圖片，但是被劫持之后卻顯示了其他網(wǎng)站的廣告鏈接圖片。由于當(dāng)時(shí)的CDN圖片鏈接采用了不安全的http協(xié)議，所以很容易被劫持。后來改成了https，問題就解決了。
當(dāng)然域名劫持有很多方式，https也不能規(guī)避所有問題。所以，除了一些安全防護(hù)措施，很多公司都有自己的備用域名，一旦發(fā)生域名劫持可以隨時(shí)切換到備用域名。
故障八：帶寬資源耗盡
帶寬資源耗盡導(dǎo)致系統(tǒng)無法訪問的情況，雖然不多見，但是也應(yīng)該引起大家的注意。來看看，之前遇到的一起事故。
場(chǎng)景是這樣的。社交電商每個(gè)分享出去的商品圖片都有一個(gè)唯一的二維碼，用來區(qū)分商品和分享者。所以二維碼要用程序生成，最初我們?cè)诜?wù)端用Java生成二維碼。
前期由于系統(tǒng)訪問量不大，系統(tǒng)一直沒什么問題。但是有一天運(yùn)營(yíng)突然搞了一次優(yōu)惠力度空前的大促，系統(tǒng)瞬時(shí)訪問量翻了幾十倍。問題也就隨之而來了，網(wǎng)絡(luò)帶寬直接被打滿，由于帶寬資源被耗盡，導(dǎo)致很多頁面請(qǐng)求響應(yīng)很慢甚至沒任何響應(yīng)。
原因就是二維碼生成數(shù)量瞬間也翻了幾十倍，每個(gè)二維碼都是一張圖片，對(duì)帶寬帶來了巨大壓力。
怎么解決呢？如果服務(wù)端處理不了，就考慮一下客戶端。把生成二維碼放到客戶端APP處理，充分利用用戶終端手機(jī)，目前Andriod，IOS或者React都有相關(guān)生成二維碼的SDK。
這樣不但解決了帶寬問題，而且也釋放了服務(wù)端生成二維碼時(shí)消耗的CPU資源（生成二維碼過程需要一定的計(jì)算量，CPU消耗比較明顯）。
外網(wǎng)帶寬非常昂貴，我們還是要省著點(diǎn)用?。?/p>
本文分享的案例都是筆者的親身經(jīng)歷，希望對(duì)各位讀者有所幫助。
