如何在eclipse dump Java內存佔用狀況和打印GC LOG

 當使用java開發應用程序發生內存泄露的時候，常常會須要dump內存，而後使用內存分析工具，好比Eclipse Memory Analyzer(通常稱做MAT)工具。

本文將介紹如何在eclipse中dump 內存。

提早準備：

1、下載ＭＡＴ ： http://www.eclipse.org/mat/

       2、測試代碼以下：

  

package com.memoryLeakAnalysis;

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

public class MemoryLeakDemo {

	public static void main(String[] args) {

		List<String> list = new ArrayList<String>();
		while (true) {
			list.add("OutOfMemoryError soon");
		}
	}

}

右鍵選擇 run configurations 

找到Arguments ----->VM arguments 

輸入：

-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=c:/memoryLeakDemo.hprof
-XX:+PrintGCDetails 
-XX:+PrintGCDateStamps 
-XX:+PrintGCApplicationConcurrentTime
-XX:+PrintGCApplicationStoppedTime  
-Xloggc:c:/memoryLeakDemoGc.log

如圖：

點擊Run運行。便可出現內存dump現象：

在c:/test目錄下會出現兩個文件：

以下圖：

其中memoryLeakDemo.hprof爲dump的內存狀況。

memoryleakDemoGc.log爲打印的jvm gc 垃圾回收狀況

使用 Eclipse Memory Analyzer（MAT)打開memoryLeakDemo.hprof ，便可看到可疑的內存泄露狀況，以下圖：

打開 memoryleakDemoGc.log日誌：

出現相似於下圖狀況，可根據日誌分析垃圾回收狀況，從而分析JVM 內存使用狀況。關於GC日誌如何分析，請google之，未來會寫文章介紹。

Application time: 0.0072104 seconds
2013-06-21T18:08:09.518+0800: 0.079: [GC 0.079: [DefNew: 4017K->261K(4928K), 0.0020189 secs] 4017K->1425K(15872K), 0.0020804 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Total time for which application threads were stopped: 0.0118427 seconds
Application time: 0.0015514 seconds
2013-06-21T18:08:09.531+0800: 0.092: [GC 0.092: [DefNew: 2095K->0K(4928K), 0.0022178 secs] 3258K->3170K(15872K), 0.0022986 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Total time for which application threads were stopped: 0.0023873 seconds
Application time: 0.0021970 seconds
2013-06-21T18:08:09.536+0800: 0.097: [GC 0.097: [DefNew: 2618K->0K(4928K), 0.0027436 secs] 5788K->5788K(15872K), 0.0027797 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Total time for which application threads were stopped: 0.0029137 seconds
Application time: 0.0033047 seconds
2013-06-21T18:08:09.542+0800: 0.103: [GC 0.103: [DefNew: 3927K->0K(4928K), 0.0040692 secs]0.107: [Tenured: 9715K->4188K(10944K), 0.0078907 secs] 9715K->4188K(15872K), [Perm : 376K->376K(12288K)], 0.0120529 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Total time for which application threads were stopped: 0.0121337 seconds
Application time: 0.0051220 seconds
2013-06-21T18:08:09.559+0800: 0.120: [GC 0.120: [DefNew: 0K->0K(4992K), 0.0019689 secs]0.122: [Tenured: 10078K->6151K(10944K), 0.0086661 secs] 10078K->6151K(15936K), [Perm : 376K->376K(12288K)], 0.0107276 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
Total time for which application threads were stopped: 0.0108428 seconds
Application time: 0.0088859 seconds
2013-06-21T18:08:09.579+0800: 0.140: [GC 0.140: [DefNew: 0K->0K(4992K), 0.0026499 secs]0.143: [Tenured: 14987K->9097K(19780K), 0.0113583 secs] 14987K->9097K(24772K), [Perm : 376K->376K(12288K)], 0.0141102 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
Total time for which application threads were stopped: 0.0142300 seconds
Application time: 0.0131855 seconds
2013-06-21T18:08:09.606+0800: 0.167: [GC 0.167: [DefNew: 0K->0K(8960K), 0.0041453 secs]0.172: [Tenured: 22350K->13514K(33036K), 0.0153709 secs] 22350K->13514K(41996K), [Perm : 376K->376K(12288K)], 0.0196298 secs] [Times: user=0.01 sys=0.00, real=0.02 secs] 
Total time for which application threads were stopped: 0.0197569 seconds
Application time: 0.0192821 seconds
2013-06-21T18:08:09.646+0800: 0.207: [GC 0.207: [DefNew: 0K->0K(14976K), 0.0057633 secs]0.212: [Tenured: 33395K->20141K(52920K), 0.0206766 secs] 33395K->20141K(67896K), [Perm : 376K->376K(12288K)], 0.0265551 secs] [Times: user=0.03 sys=0.00, real=0.03 secs] 
Total time for which application threads were stopped: 0.0266673 seconds
Application time: 0.0289176 seconds
2013-06-21T18:08:09.701+0800: 0.262: [GC 0.262: [DefNew: 0K->0K(23872K), 0.0086104 secs]0.271: [Tenured: 49962K->30081K(52920K), 0.0294036 secs] 49962K->30081K(76792K), [Perm : 376K->376K(12288K)], 0.0380994 secs] [Times: user=0.03 sys=0.00, real=0.04 secs] 
Total time for which application threads were stopped: 0.0382799 seconds
Application time: 0.0436154 seconds
2013-06-21T18:08:09.783+0800: 0.344: [GC 0.344: [DefNew: 0K->0K(23872K), 0.0131421 secs]0.357: [Tenured: 74812K->44992K(97652K), 0.0415558 secs] 74812K->44992K(121524K), [Perm : 376K->376K(12288K)], 0.0548393 secs] [Times: user=0.05 sys=0.00, real=0.06 secs] 
Total time for which application threads were stopped: 0.0550578 seconds
Application time: 0.0657430 seconds
2013-06-21T18:08:09.904+0800: 0.465: [GC 0.465: [DefNew: 0K->0K(43968K), 0.0198380 secs]0.485: [Tenured: 112088K->67357K(164752K), 0.0608105 secs] 112088K->67357K(208720K), [Perm : 376K->376K(12288K)], 0.0807997 secs] [Times: user=0.08 sys=0.00, real=0.08 secs] 
Total time for which application threads were stopped: 0.0809335 seconds
Application time: 0.0991039 seconds
2013-06-21T18:08:10.084+0800: 0.645: [GC 0.645: [DefNew: 0K->0K(74240K), 0.0293317 secs]0.674: [Tenured: 168002K->100905K(174784K), 0.0895410 secs] 168002K->100905K(249024K), [Perm : 376K->376K(12288K)], 0.1189829 secs] [Times: user=0.12 sys=0.00, real=0.12 secs] 
2013-06-21T18:08:10.203+0800: 0.764: [Full GC 0.764: [Tenured: 100905K->100892K(174784K), 0.0861601 secs] 100905K->100892K(253440K), [Perm : 376K->371K(12288K)], 0.0862167 secs] [Times: user=0.08 sys=0.00, real=0.09 secs] 
Total time for which application threads were stopped: 0.2053870 seconds
Application time: 0.0006161 seconds
Total time for which application threads were stopped: 0.5625090 seconds
Heap
 def new generation   total 78656K, used 2190K [0x24690000, 0x29be0000, 0x29be0000)
  eden space 69952K,   3% used [0x24690000, 0x248b3bd8, 0x28ae0000)
  from space 8704K,   0% used [0x28ae0000, 0x28ae0000, 0x29360000)
  to   space 8704K,   0% used [0x29360000, 0x29360000, 0x29be0000)
 tenured generation   total 174784K, used 100892K [0x29be0000, 0x34690000, 0x34690000)
   the space 174784K,  57% used [0x29be0000, 0x2fe67208, 0x2fe67400, 0x34690000)
 compacting perm gen  total 12288K, used 371K [0x34690000, 0x35290000, 0x38690000)
   the space 12288K,   3% used [0x34690000, 0x346ecf38, 0x346ed000, 0x35290000)
    ro space 10240K,  55% used [0x38690000, 0x38c11140, 0x38c11200, 0x39090000)
    rw space 12288K,  55% used [0x39090000, 0x397344c8, 0x39734600, 0x39c90000)
Application time: 0.0016332 seconds