問題

最近線上有一個服務，執行個一兩天，就會變得很慢。這裡很慢指的是經常對於請求的響應時間很大，有時甚至有二三十秒，導致別人調介面，經常出現超時問題。這裡簡單介紹些這個問題的定位方法過程以及最後怎麼解決的。
很多時候，我們更應該積累分析問題、解決問題的方法，這也是一個人工作能力的表現吧。當然專業知識的積累也是必不可少的，這是基礎。就像本文的分析，要是沒有點JVM的知識基礎，這個問題肯定是解決不了的。

分析與解決

1. 看日誌

這是最基本的，一般線上服務出現問題，第一反應應該就是看日誌。看看是不是程式丟擲了異常。當然這裡是服務響應比較慢，並不是不返回，也不是http返回500。果不其然，線上服務是沒有異常程式日誌的。因為程式是部署在tomcat上的，再看看tomcat的日誌，發現也是正常的，沒有異常日誌。

2. 看服務監控

現在好多的公司都有服務監控系統，有cpu、記憶體、網絡卡、磁碟、url請求的響應時間請求併發、jvm相關等等的監控。當然公司沒有監控系統也不用慌，監控系統只是看起來直觀一點。就算沒有監控系統，還是可以通過linux命令以及jdk裡面帶的JVM除錯工具來看。可能url請求響應時間和請求併發量沒有現成的命令工具，其他的都有，最基本的top命令看cpu、記憶體，JVM相關的就是用jdk自帶的工具，像jps，jmap，jstat，jstack等。

看了監控，發現cpu、網絡卡啥的都沒問題，線上機器記憶體16G，記憶體也完全夠。看Url響應時間發現有問題，最大呼叫時間很大，平均響應時間也偏大：

這裡就可以猜測是服務本身有問題了。這裡首先想到的就是服務在某個時間點卡住了，能想到的一個就是JVM在fullGC的時候stop the world。因此去看下jvm監控：
垃圾回收：

這裡能看到的是fullGC太頻繁了，而且點在上面還可以看到fullGC的時間很長，一次fullGC平均都用了27S的樣子。這也跟上面監控的url和方法監控的最慢呼叫時間相吻合。因為JVM在進行fullGC的時候，使用者執行緒都會被暫停等到fullGC完成再回來繼續執行。
看下虛擬機器記憶體：

那麼接下來就要分析為什麼fullGC不能實現記憶體的有效回收呢。

首先服務執行的虛擬機器引數：

-Xmn2048M 
-XX:ParallelGCThreads=6 
-XX:SurvivorRatio=2 
-XX:CMSFullGCsBeforeCompaction=0 
-XX:CMSInitiatingOccupancyFraction=75 
-XX:InitiatingHeapOccupancyPercent=50 
-XX:MaxGCPauseMillis=200 
-XX:+UseG1GC 
-XX:+PrintGCApplicationConcurrentTime 
-XX:+PrintGCApplicationStoppedTime 
-XX:+PrintGCDateStamps

從這上面好像也看不出有什麼問題。那我們用jdk工具看看線上服務執行的記憶體資訊：

jmap -heap <pid>

其中上面的pid可以使用jps檢視，是java程序的一個程序id。堆記憶體資訊如下：

可以看到很奇怪的一點就是老年代滿的，這個跟剛剛監控看到的也是符合的。如果沒有監控看堆記憶體的垃圾回收資訊，可以使用jdk的工具：

jstat -gcutil <pid> 10000

表示的是每10秒輸出一次記憶體回收資訊，對gc進行統計。

這裡解釋下：
S0:新生代的susvivor0區，空間使用率為0%
S1:新生代的susvivor1區，空間使用率為100%(因為還沒有執行第二次minor收集)
E:eden區，空間使用率28.02%
O:老年代，空間使用率65.76%
YGC:minor gc執行次數215次
YGCT:minor gc耗費的時間37.996毫秒
FGC:full gc執行次數0
FGCT:full gc耗費的時間0毫秒
GCT:gc耗費的總時間37.996毫秒

當然這個並不是那個服務線上的環境的輸出，這裡只是做一下解釋這些引數表示什麼意思。

迴歸正題，這裡為什麼老年代一直都是滿的，fullGC對於老年代的回收基本起不到作用，而且上面看到的Survivor空間一直都是0，沒有分配空間。能想到兩種可能：1. 程式碼問題，程式碼裡面有大物件，而且是分配的時候直接進入老年代，而且這些物件被一直引用著沒有釋放，所以fullGC的作用不是很明顯。2. 虛擬機器引數有問題，是引數的設定導致的。

先說第一種可能，結合上面的輸出，Eden空間的大小是1872M，大物件在這裡面肯定是能得到分配的，而且看虛擬機器引數的設定，-XX:SurvivorRatio=2 表示Eden和Survivor的比例為2，但是上面的jmap看到的對記憶體資訊裡面Survivor空間為0，這顯然跟設定的引數是矛盾的。然後再去看程式碼，也不存在大物件一直引用沒有釋放的情況，所以基本排除第一種情況。

其中第一篇是java 的官方文件，裡面有個最佳實踐裡就提到：

裡面提到不要設定年輕代大小：

假若通過 -Xmn 顯式地指定了年輕代的大小, 則會干擾到 G1收集器的預設行為.
G1在垃圾收集時將不再關心暫停時間指標.所以從本質上說,設定年輕代的大小將禁用暫停時間目標. G1在必要時也不能夠增加或者縮小年輕代的空間.
因為大小是固定的,所以對更改大小無能為力.

而我們的程式虛擬機器引數剛好就設定了新生代大小：-Xmn2048M。會不會就是這個原因導致的。我先把這個引數和-XX:SurvivorRatio=2 這個引數去掉，然後再部署服務，發現現在垃圾回收變得很正常，已經一天了，服務並沒有變慢。問題得到解決。中午吃飯的時候還跟同事討論是不是G1收集器的問題，讀了其他幾篇關於介紹G1收集器的部落格後，完全否定了這種想法。

後面jstat -gcutil 10000 觀察垃圾收集很正常，而且G1收集器fullGC真的很少。

以上就是解決這個線上服務執行時間長變慢問題的一個過程。

總結

我們在定位問題的時候，要根據自己已有的知識和經驗進行猜想和判斷，然後對猜想和判斷就行驗證，一步一步的去接近真相。

ps. G1收集器是一個不錯的收集器，能夠很大程度減少fullGC的次數，分配空間時不需要一個連續的記憶體區間，老年代新生代的區間（region）是不固定的，新生代回收過後空間可用下次可以作為老年代空間來儲存。但是在使用的時候，如果不理解原理機制，還是可能會出現問題的。其他的收集器也是一樣的，其實對於技術知識點都是這樣的，不僅要會用，還要理解。

後面有時間會寫一篇關於JVM各個GC收集器的部落格。