1. 程式人生 > >Java記憶體洩漏案例

Java記憶體洩漏案例

1.問題現象

某系統在執行幾天之後,變得非常的慢,所有功能幾乎不能用,偶爾會報OutOfMemory。

2.問題解決過程

注:

  • 系統執行在linux環境
  • 文中涉及命令:jps、jstat、jmap命令都在xxx/java/jdk1.5.0_15/bin路徑下,且要用root使用者執行。
    • jps   — 顯示系統中的java程序資訊
    • jstat — 對垃圾回收過程進行取樣
    • jmap  — 匯出java記憶體到二進位制檔案

2.1.檢視tomcat的程序號(jps或者ps命令都可以)

root:/xxx/java/jdk1.5.0_15/bin # ./jps
18830 Jps
28360 Bootstrap
root:/xxx/java/jdk1.5.0_15/bin # ps -ef | grep java
root     28360

     1  1 Oct25 ?        07:12:12 /xxx/java/java/bin/java -Djava.util.logging.config.file=/home/zxin10/tomcat/conf/logging.properties -Xms800m -Xmx800m -XX:PermSize=128m -XX:MaxPermSize=512m -Xdebug -Xrunjdwp:transport=dt_socket,address=8348,server=y,suspend=n -Djava.endorsed.dirs=/home/zxin10/tomcat/common/endorsed -classpath :/home/zxin10/tomcat/bin/bootstrap.jar:/home/zxin10/tomcat/bin/commons-logging-api.jar -Dorg.apache.jasper.compiler.Parser.STRICT_QUOTE_ESCAPING=false -Dcatalina.base=/home/zxin10/tomcat -Dcatalina.home=/home/zxin10/tomcat -Djava.io.tmpdir=/home/zxin10/tomcat/temp org.apache.catalina.startup.Bootstrap start
root     19028 16771  0 14:06 pts/0    00:00:00 grep java

2.2.檢查垃圾回收情況

root:/xxx/java/jdk1.5.0_15/bin # ./jstat -gcutil 28360 500 0
S0     S1     E      O      P     YGC     YGCT    FGC    FGCT     GCT
4.46   0.00  58.34  79.17  72.21   4966  116.404  1146 2764.054 2880.458
4.46   0.00  58.87  79.17  72.21   4966  116.404  1146 2764.054 2880.458
4.46   0.00  58.87  79.17  72.21   4966  116.404  1146 2764.054 2880.458
4.46   0.00  58.87  79.17  72.21   4966  116.404  1146

 2764.054 2880.458
4.46   0.00  66.27  79.17  72.21   4966  116.404  1147 2764.054 2880.458
4.46   0.00  66.27  79.17  72.21   4966  116.404  1147 2764.054 2880.458
4.46   0.00  66.27  79.17  72.21   4966  116.404  1147 2764.054 2880.458
4.46   0.00  66.27  79.17  72.21   4966  116.404  1147 2764.054 2880.458
4.46   0.00  66.27  79.17  72.21   4966  116.404  1147 2764.054 2880.458
4.46   0.00  66.27  79.17  72.21   4966  116.404  1147 2764.054 2880.458
0.00   0.00   5.00  79.98  72.22   4966  116.404  1148 2767.206 2883.610
0.00   0.00   5.00  79.98  72.22   4966  116.404  1148 2767.206 2883.610
0.00   0.00   5.00  79.98  72.22   4966  116.404  1148 2767.206 2883.610

jstat命令中:

28360 — tomcat的程序號

500  — 取樣間隔,單位毫秒

    — 取樣次數,0表示一直進行取樣

取樣資料中:S0、S1、E共同組成Young區。

S0  — Heap上的 Survivor space 0 區已使用空間的百分比

S1  — Heap上的 Survivor space 1 區已使用空間的百分比

E   — Heap上的 Eden space 區已使用空間的百分比

O   — Heap上的 Old space 區已使用空間的百分比

P   — Perm space 區已使用空間的百分比

YGC — 從應用程式啟動到取樣時發生 Young GC 的次數

YGCT– 從應用程式啟動到取樣時 Young GC 所用的時間(單位秒)

FGC — 從應用程式啟動到取樣時發生 Full GC 的次數

FGCT– 從應用程式啟動到取樣時 Full GC 所用的時間(單位秒)

GCT — 從應用程式啟動到取樣時用於垃圾回收的總時間(單位秒)

一次YGC,會對Young區(S0、S1、E)進行一次垃圾回收。

一次FGC,會對Young區、Old區進行垃圾回收。

但是,看到的取樣資料中,進行了2次FGC(紅色部分中的藍色部分),但是Old區並沒有被回收,大體說明:Old區的記憶體幾乎不會被回收,存在洩露。

2.3.匯出heap.bin

在系統慢時的記憶體資料heap.bin進行匯出。
./jmap -histo 980
可以簡單的檢視記憶體狀況

該命令執行的時候,會導致jvm假死,所以現場環境謹慎使用。有時候這個命令不能執行成功,多執行幾次。(不成功原因:jvm繁忙之類)
root:/xxx/java/jdk1.5.0_15/bin # ./jmap -heap:format=b  28360
28360 — tomcat的程序號

成功之後在此目錄下,會生成heap.bin。

2.4.heap.bin分析

將這個檔案下載到windows的本機環境,使用進行分析。

2.4.1.檢視統計資訊

下圖紅色部分表明Logger物件異常多。

  • ArrayList、Object[]多,很可能是Logger物件多引起,因此著重檢查本系統相關程式碼。

memory-leak-jvmmat-1

2.4.2.檢視洩露的程式碼

memory-leak-jvmmat-2

點選上圖的按鈕Leak Suspects,出現洩露的介面:

memory-leak-jvmmat-3

點選Details連結後,可以看到洩露的物件:

memory-leak-jvmmat-4

2.4.3.檢查程式碼中loggers變數的洩露

LoggerFactory.java中:

protected void addLogger(Logger logger)
{
    if (null != logger)
    {
        synchronized (this.loggers)
        {
            this.loggers.add(logger);
        }
        for (Outputter o : this.outputters)
        {
            logger.addOutputter(o);
        }
    }
}

其中

  • loggers是一個final物件,會永久儲存。
  • 而函式的入參logger是臨時物件,生命週期會很快結束。

把一個臨時變數永久儲存,就出現記憶體回收不了,記憶體洩露的問題。

2.4.4.解決方法

  1. 直接註釋掉 this.loggers.add(logger);
  2. 限制加入loggers集合的logger物件的數目即可