java:線上問題排查常用手段

菩提樹下的楊過發表於2017-09-07

一、jmap找出佔用記憶體較大的例項

先給個示例程式碼:

import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.CountDownLatch;

/**
 * Created by 菩提樹下的楊過 on 05/09/2017.
 */
public class OOMTest {

    public static void main(String[] args) throws InterruptedException {
        CountDownLatch latch = new CountDownLatch(1);
        int max = 10000;
        List<Person> list = new ArrayList<>(max);
        for (int j = 0; j < max; j++) {
            Person p = new Person();
            p.setAge(100);
            p.setName("菩提樹下的楊過");
            list.add(p);
        }
        System.out.println("ready!");
        latch.await();
    }


    public static class Person {
        private String name;
        private int age;

        public String getName() {
            return name;
        }

        public void setName(String name) {
            this.name = name;
        }

        public int getAge() {
            return age;
        }

        public void setAge(int age) {
            this.age = age;
        }
    }
}  

List中放了1w個Person物件的例項,先把這段程式跑起來

javac OOMTest.java

java OOMTest

然後再開一個視窗,jps -l  找出該程式的pid

然後執行 jmap -histo:live 7320 (注:如果輸出內容太多,只想看排名前10的,可以加 | head -10)

輸出結果,會按記憶體使用量,從大到小依次把物件的實際個數,佔用記憶體數量(位元組數)列印出來,最後還會輸出彙總資訊

以上面的示例來說,OOMTest$Person這個類的例項數為10000個,總共佔用240000位元組(注:即每個例項24位元組),這個程式總佔用記憶體數為725464位元組,約:0.69M。

另外還有一些[C,[B這類class name,大概意思為:

[C is a char[]
[S is a short[]
[I is a int[]
[B is a byte[]
[[I is a int[][]

[C物件往往跟String有關,String其內部使用final char[]陣列來儲存資料的

constMethodKlass/ methodKlass/ constantPoolKlass/ constantPoolCacheKlass/ instanceKlassKlass/ methodDataKlass

與Classloader相關,常駐與Perm區。

 

二、找出某個java應用開啟的控制程式碼數及執行緒數

ll /proc/{pid}/fd | wc -l 檢視開啟的控制程式碼數

ll /proc/{pid}/task | wc -l 檢視執行緒數

 

三、jmap 檢視堆記憶體的各項配置

jmap -heap pid 可以看到類似下面的輸出:

using thread-local object allocation.
Parallel GC with 4 thread(s)  //當前使用的GC方式(並行GC)

Heap Configuration:  //堆記憶體配置
   MinHeapFreeRatio         = 0   //對應jvm啟動引數-XX:MinHeapFreeRatio設定JVM堆最小空閒比率(java8預設0)
   MaxHeapFreeRatio         = 100 //對應jvm啟動引數-XX:MaxHeapFreeRatio設定JVM堆最大空閒比率 
   MaxHeapSize              = 8388608 (8.0MB) //對應jvm啟動引數-XX:MaxHeapSize=設定JVM堆的最大大小(或-Xmx引數)
   NewSize                  = 5242880 (5.0MB) //對應jvm啟動引數-XX:NewSize=設定JVM堆的‘新生代’的預設
   MaxNewSize               = 5242880 (5.0MB) //對應jvm啟動引數-XX:MaxNewSize=設定JVM堆的‘新生代’的最大大小 
   OldSize                  = 3145728 (3.0MB) //對應jvm啟動引數-XX:OldSize=設定JVM堆的‘老生代’的大小 
   NewRatio                 = 2 //對應jvm啟動引數-XX:NewRatio=:‘新生代’和‘老生代’的大小比率 
   SurvivorRatio            = 8 //對應jvm啟動引數-XX:SurvivorRatio=設定年輕代中Eden區與Survivor區的大小比值 
   MetaspaceSize            = 21807104 (20.796875MB)
   CompressedClassSpaceSize = 1073741824 (1024.0MB)
   MaxMetaspaceSize         = 17592186044415 MB
   G1HeapRegionSize         = 0 (0.0MB)

Heap Usage: //堆記憶體使用情況 
PS Young Generation
Eden Space: //Eden區分佈
   capacity = 2621440 (2.5MB) //Eden區總容量
   used     = 2328088 (2.2202377319335938MB) //Eden區已使用
   free     = 293352 (0.27976226806640625MB) //Eden區剩餘容量
   88.80950927734375% used
From Space: //其中一個Survivor區的記憶體分佈
   capacity = 1572864 (1.5MB)
   used     = 360448 (0.34375MB)
   free     = 1212416 (1.15625MB)
   22.916666666666668% used
To Space: //另一個Survivor區的記憶體分佈
   capacity = 1048576 (1.0MB)
   used     = 0 (0.0MB)
   free     = 1048576 (1.0MB)
   0.0% used
PS Old Generation //當前的Old區記憶體分佈 
   capacity = 3145728 (3.0MB)
   used     = 1458968 (1.3913803100585938MB)
   free     = 1686760 (1.6086196899414062MB)
   46.37934366861979% used

3759 interned Strings occupying 298824 bytes.

注:5-16行是堆記憶體的主要配置,這些引數都可以通過 java -XX:引數名=引數值 來調整其大小,比如:

java -XX:MinHeapFreeRatio=20 -XX:MaxHeapFreeRatio=80 -Xmx100m -XX:MetaspaceSize=50M -XX:NewRatio=3 將影響MinHeapFreeRatio、MaxHeapFreeRatio、MaxHeapSize、MetaspaceSize、NewRatio的值

注意下NewRatio,這個值指的 老年代(Old Generation): 新生代(Young Generation)的比值,上面設定成3,所以OldSize為75m,而NewSize為25m,參考下圖:

注:這是jdk7的示意圖,jdk8中Permanent Generation被去掉了,新加入了Metaspace區,但這個區別不影響對 新生代、老生代的理解。

新生代(Young Generation)又可以細分為eden、s0、s1 三大塊。

java7與java8的記憶體變化,大致如上圖。

SurvirorRatio這個要難算一點,按Oracle官網的解釋:https://docs.oracle.com/cd/E19159-01/819-3681/abeil/index.html ,預設值是8,即:每塊survivor: eden區的大小為1:8,換句話說 s0 = s1 = 1 / (1+1+8) = 1/10

注:雖然官網這麼解釋,但是我實際算了下,好象並不是嚴格按這個比例來算的,只能大概說是這個分配比例。(結論就是:SurvirorRatio設定越大,eden區就越大)

 

四、找出佔用CPU最高的執行緒

先來一段演示程式碼:

import java.util.concurrent.CountDownLatch;

/**
 * Created by 菩提樹下的楊過 on 05/09/2017.
 */
public class OOMTest {

    public static void main(String[] args) throws InterruptedException {
        CountDownLatch latch = new CountDownLatch(1);
        int max = 100;
        for (int i = 0; i < max; i++) {
            Thread t = new Thread() {
                public void run() {
                    try {
                        Thread.sleep(50);
                    } catch (InterruptedException e) {
                        Thread.currentThread().interrupt();
                    }
                }
            };
            t.setName("thread-" + i);
            t.start();
        }
        Thread t = new Thread() {
            public void run() {
                int i = 0;
                while (true) {
                    i = (i++) / 10;
                }
            }
        };
        t.setName("BUSY THREAD");
        t.start();
        System.out.println("ready");
        latch.await();
    }

}

這裡面有100個執行緒是空轉的,另外還有一個執行緒BUSY THREAD在狂跑CPU。

javac OOMTest.java

java OOMTest

把程式跑起來,jps -l 找出pid,然後  top -Hp pid

可以看到pid 16813這個對應的執行緒,把CPU快跑滿了,達到了98.5%

接下來,將16813轉換成16進位制 ,即41ad (tips: printf "%x" 16813 ) ,然後

jstack pid | grep '41ad'

我們就把最忙的這個執行緒BUSY THREAD給找出來了(注:這個技巧再次說明了,給執行緒取個好名字相當重要!)

tips:如果使用spring-boot的話,直接在瀏覽器裡檢視/dump端點,也可以達到類似jstack的效果。

 

五、jvisualvm 檢視執行情況

JDK_HOME/bin下有一個自帶的jvisualvm工具,可以圖形化的檢視GC情況(注:要安裝外掛)

java.net這個網站已經被oracle關了,所以安裝外掛這裡,有點小麻煩,先到https://visualvm.github.io/pluginscenters.html 這裡找到jvisualvm對應的jdk版本號,以jdk8為例,地址就是 https://visualvm.github.io/uc/8u131/updates.xml.gz

然後,把這個地址在Plugins裡的Settings裡改一下,然後Available Plugin這裡,就能看到可用外掛了,選擇GC外掛並安裝。

點選檢視原圖

可以來一段程式碼,然後用jvisualvm來看下GC情況

import java.util.ArrayList;
import java.util.List;

/**
 * Created by 菩提樹下的楊過 on 05/09/2017.
 */
public class OOMTest {

    public static void main(String[] args) throws InterruptedException {
        List<String> list = new ArrayList<>();
        while (true) {
            Thread.sleep(10);
            list.add("菩提樹下的楊過" + System.currentTimeMillis());
        }
    }
}

 點選檢視原圖

可以直觀的看到Old區,Eden區,S0,S1以及Metaspace區的記憶體變化情況,以上圖為例:Old Gen區佔用記憶體一直在增加,表示可能有記憶體一直未被釋放,值得關注。

此外,還可以看到佔用記憶體最多的類(即:本文最開始提到的)

點選檢視原圖

還可以更進一步點選看詳情,比如下面的圖,就能發現Metaspace已經OOM了

點選檢視原圖

 

也可以檢視哪些執行緒最忙

點選檢視原圖

 

六、使用jstat 檢視GC

雖然jvisualvm很好用,但是通常伺服器是用終端連上的,無法執行圖形化介面,而且也並非所有應用都開啟了jmx,所以掌握jstat以命令列方式檢視GC情況也是蠻重要的

用法:jstat -gc pid 取樣間隔毫秒數,比如: jstat -gc 8544 5000,將每隔5s取樣一次pid為8544的gc情況

以上圖為例:紅剪頭的地方,S0區的已用量降到0,而S1區的已用量上漲,即說明發生了Young GC,物件從S0區被遷移到了S1區。

title欄的含義如下:

S0C - 新生代中第1塊survivor 的容量(Survivor 0 Capacity),KB單位
S1C - 新生代中第2塊survivor 的容量(Survivor 1 Capacity),KB單位
S0U - 新生代中第1塊survivor 已使用空間數(Survivor 0 Used),KB單位
S1U - 新生代中第2塊survivor 已使用空間數(Survivor 0 Used),KB單位
EC - Eden區的容量(KB)
EU - Eden區已使用(KB數)
OC - Old區的容量(KB)
OU - Old區已使用(KB數)
MC - Metaspace容量(KB)
MU - Metaspace已使用KB
CCSC - 壓縮類的記憶體容量(KB)
CCSU - 壓縮類的已用容量(KB)
YGC - (從應用啟動算起,到取樣時的) Young GC次數
YGCT - (從應用啟動算起,到取樣時的) Young GC所用時間(秒)
FGC - (從應用啟動算起,到取樣時的) Full GC次數
FGCT - (從應用啟動算起,到取樣時的) Full GC所用時間(秒) 
GCT - (從應用啟動算起,到取樣時的) Yong GC + Full GC的總時間

值得一提的是G1垃圾回收器,在大堆(>4G)時,用G1可能效果會更好,G1的開啟方法:

-XX:+UseG1GC -XX:MaxGCPauseMillis=200 

開啟後,再使用jmap -heap pid 

可以看到從預設的併發GC變成了G1.

jstat -gc pid 5000

看到S0全是0,這也是G1的一個特點,將新生代與老年代的劃分取消掉了,而是用region的新概念,把整個堆記憶體劃分成一個個region,每個region裡再分代,詳情見本文最後的參考文章。

 

七、匯出整個jvm的dump

jmap -dump:format=b,file=檔名 [pid]

最後這個算是放大招了,把整個jvm都匯出來分析,通常是其它手段都搞不定的時候,才找運維去搞這個,匯出的檔案體積大,而且匯出時會使應用停頓。把這個檔案弄到本地後,可以用eclipse的一個外掛MAT來分析,下載地址:http://www.eclipse.org/mat/downloads.php

 

參考文章:

Java GC系列 http://www.importnew.com/13504.html

深入理解 Java G1 垃圾收集器 http://blog.jobbole.com/109170/

jstat Oracle官方介紹 http://docs.oracle.com/javase/8/docs/technotes/tools/unix/jstat.html 

相關文章