排查Java线上服务故障的方法和实例分析
2019獨角獸企業重金招聘Python工程師標準>>>
前言
作為在線系統負責人或者是一個技術專家，你可能剛剛接手一個項目就需要處理緊急故障，或者被要求幫忙處理一些緊急的故障，這個時候的情景是：
(1)你可能對這個業務僅僅是聽說過，而不怎么真正了解；
(2)你可能沒有這個故障的詳細信息，比如可能僅僅是有使用方反饋服務中斷了10分鐘；
(3)你對代碼細節還沒有仔細研究過。
這個時候該怎么解決問題呢？根據以前的經驗，工程師們常常傾向于直接登上服務器檢查代碼，試圖立刻修改問題。或者是把某些可能是問題的配置做修改，但并不是100%確認這就是問題的根本原因。但結果往往是在解決問題的同時引入了新的問題，或者是沒有找到問題的根本原因，導致用戶的再次投訴。
?
正文
處理和排除故障分為4個必須的步驟：
(1)?緊急處理
(2)?添加監控
(3)?使用JDK性能監控工具
(4)?分析源代碼。從治標不治本，到治標又治本。
?
緊急處理
緊急處理，顧名思義，是檢查和評度當前故障的影響范圍，并盡快使服務先恢復起來。其中檢查和評估當前故障的影響范圍是非常重要的。
以微博系統舉例，一般用戶的投訴率為千分之1，如果有超過10起用戶投訴，就可能是大面積故障。如果只是負責線上跟蹤的QA人員反饋的問題，而沒有用戶投訴，則可以有較多的時間去處理。
對于緊急的大面積故障，首先想到的不應該是檢查問題。而是需要立刻追查最近線上系統是否有更改，我們的經驗是95%的故障都是在新代碼上線后的12小時內發生的。此時應該立刻回滾新更改。另外5%的故障大部分是由于業務擴展導致的。互聯網業有一個規律，線上系統每半年需要重構一次，否則無法對應業務量的增長。對于這種業務量增長造成的故障，通常可以通過重啟服務來緊急處理。
因此，緊急處理的首選是立刻回滾新更改。
?
添加監控
緊急處理之后，服務已經恢復了，但是問題并沒有找到。如果是新代碼上線造成的故障，回滾之后，工程師會有各種手段，在測試環境追查問題。而針對系統容量不足造成的故障，需要特別添加監控作為追查問題的重要手段。因為互聯網業務請求高峰和低谷差別非常明顯，微博業務中的請求高峰往往出現在晚上10點左右，而且不是穩定的出現。要求工程師們每天悲催的坐在電腦前守到晚上10點，卻不見得能發現問題，是非常低效的。監控一般用一個簡單的腳本就可以搞定，比如http服務監控，Shell腳本代碼如下:
MAX_LATENCY_TIME=5????
curl?-m?$MAX_LATENCY_TIME?"http://1.2.3.4:8011/...."????
if?[?$??-ne?0?]?;?then??
???????? sIp=`hostname`??
???????? errmsg="gexin?install?latency?>?"$MAX_LATENCY_TIME"s"??
???????? //?具體告警的處理??
???????? echo?$errmsg??
???????? echo?send?success??
fi??
?
使用JDK性能監控工具
剛剛添加的監控開始報警了。登上服務器，該做些什么呢？一般需要做如下動作，
(1)首先要查看日志，看看有沒有Exception。另外日志中常常有對接口調用，緩存使用的監控告警信息。
(2)看看目前gc的狀況如何，使用JDK自帶的工具就可以。jstat?-gc?-h?10?vmid?5000，每5秒打出一次。我遇到過兩次線上故障，都是簡單的通過jstat就找到了問題。一次是Permanent區分配過小，JVM內存溢出。另一次是發生了過多的Full?GC，使得系統停止響應。內存造成的問題通過簡單的重啟服務就可以使得服務恢復，但重啟之后往往很快又出現問題。這個期間你要監控gc，看看期間發生了什么事情。如果是old區增長的過快，就可能是內存泄露。這個時候，你需要看看到底是什么對象占用了你的內存。
(3)jmap?-histo?vmid?>?jmap.log，該命令會打出所有對象，包括占用的byte數和實例個數。分享一個線上jmap實例，
Jmap.log代碼??
num?????#instances?????????#bytes??class?name??
---------------------------------------------??
1:??????10540623??????668712400??[B??
?? 2:??????10532610??????252782640??com.google.protobuf.ByteString??
? ? ? 3:???????4305941??????234036872??[Ljava.lang.Object;??
? ? ? 4:???????1066822??????170691520??cn.abc.data.protobuf.UserWrap$User??
? ? ? 5:???????3950998??????158039920??java.util.TreeMap$Entry??
? ? ? 6:???????3950159??????126405088??com.google.protobuf.UnknownFieldSet$Field??
? ? ? 7:????????780773??????118677496??cn.abc.data.protobuf.StatusWrap$Status??
? ? ? 8:???????4305047??????103321128??java.util.ArrayList??
? ? ? 9:???????4301379??????103233096??java.util.Collections$UnmodifiableRandomAccessList??
? ? 10:???????3207948??????102654336??java.util.HashMap$Entry??
? ? 11:???????2571737???????82300280??[C??
? ? 12:???????2569460???????82222720??java.lang.String??
? ? 13:???????3952892???????63246272??java.lang.Integer??
? ? 14:???????1314438???????63093024??java.util.TreeMap??
? ? 15:???????2533229???????60797496??java.lang.Long??
? ? 16:???????1065093???????51124464??cn.abc.data.protobuf.PostSourceWrap$PostSource??
? ? 17:???????1314430???????42061760??java.util.Collections$UnmodifiableMap??
? ? 18:????????284198???????40924512??cn.sina.api.data.protobuf.CommentWrap$Comment??
? ? 19:??????????4273???????34273568??[Ljava.util.HashMap$Entry;??
? ? 20:????????459983???????33118776??cn.abc.data.protobuf.AbcMessageWrap$AbcMessage??
? ? 21:????????458776???????22021248??java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask??
? ? 22:????????458776???????22021248??java.util.concurrent.FutureTask$Sync??
? ? 23:???????1314416???????21030656??com.google.protobuf.UnknownFieldSet??
? ? ?24:????????459982???????11039568??cn.sina.datapush.notifier.core.DispatcherBase$MessageProcessor??
? ? ?25:????????458776???????11010624??java.util.concurrent.Executors$RunnableAdapter??
? ? ?26:????????458776????????7340416??cn.abc.datapush.notifier.core.DispatcherBase$MessageProcessor$1??
? ? ?27:?????????40897????????5909152??<constMethodKlass>??
? ? ?28:?????????40897????????4917592??<methodKlass>??
? ? ?29:??????????3193????????3748688??<constantPoolKlass>??
? ? ?30:?????????62093????????3274344??<symbolKlass>??
? 排名前幾位的都是Byte，Char，String，Integer之類的，不要灰心，繼續往下看，后面會出現一些有趣的對象。第22位發現了45萬個FutureTask，很顯然這是不正常的。應該是某線程響應過慢，造成待處理任務出現了堆積。查看代碼，果然處理線程只有4條，大量的請求得不到響應。通過gc分析，每5秒鐘會產生100M左右的對象得不到處理，所以JVM?heap很快就被耗盡。將線程數改為36條，問題立刻得到了解決。
?
(4)檢查目前cpu占用情況，top?-H，然后按“1”，會看到當前進程中每個線程所占CPU的比例。注意觀察前幾名，然后jstack?-l?vmid?>?jstack.log打出線程堆棧，看看是什么線程占用了CPU。這里需要注意的是，top?-H顯示的線程id是十進制，而jstack打出的線程堆棧是16進制。看看那些最忙的thread是不是那些真正應該忙的thread，如果是一些“黑馬”線程，則要考慮是否是代碼有死循環或者是意外的問題。
?
分析源代碼
分析源代碼是最有技術含量的事情，也是比較耗時而且不見得有效果的事情。所以我把源碼分析放到解決線上問題的最后一步，因為必須要做到“有的放矢”。帶著問題去分析代碼，會比較容易。通過20%代碼的修改，就可以解決80%的性能問題。比如上面這個線上問題，肯定是線程處理慢造成的問題。需要針對線程的調用，同步異步等進行分析。
轉載于:https://my.oschina.net/javahongxi/blog/1524089
總結
以上是生活随笔為你收集整理的排查Java线上服务故障的方法和实例分析的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： linux运行jar文件
- 下一篇： Android PullToRefres