总帖数

每页帖数

1/1页

返回列表

发起投票

查看: 3364 | 回复: 0

主题： [原创]实例分析heapDump、threadDump与gc日志

tianyuan.liu

注册用户

等级：上尉
经验：766
发帖：33
精华：0
注册：1970-1-1
状态：离线
发送短消息息给tianyuan.liu

加好友发送短消息息给tianyuan.liu

发消息

发表于：

2015-3-5 11:03:45 | [全部帖] [楼主帖]

楼主

在 http://bbs.landingbj.com/showtopic.jsp?rootid=252641&CPages=1 介绍过threadDump，下面介绍heapDump与gc日志。

获取heapDump的方法：

heapDump即堆内存快照。通过分析heapDump文件可以找出OOM错误的原因。

通过jVisualVM获取

我在这篇帖子http://bbs.landingbj.com/showtopic.jsp?rootid=252641& CPages=1（JVM线程快照的获取与分析）中介绍了通过jVisualVM远程监测服务器上Java程序的方法。通过图形化的方式右键对应程序就可以实时获取heapDump。

通过命令$JAVA_HOME/bin/jmap -dump获取

jmap -dump:file=/home/tianyuan/heamdump.hprof,format=b pid

file后面跟文件存放路径，pid为进程id

通过修改Java启动参数获取

这里给出修改weblogic修改启动参数的方法，

找到对应的/Middleware/user_projects/domains/base_domain/bin/setDomainEnv.sh文件，在文件末尾添加以下参数，重启weblogic，在发生OOM时会自动生成heapDump文件。

JAVA_OPTIONS="${JAVA_OPTIONS} -XX:+HeapDumpOnOutOfMemoryError"
export JAVA_OPTIONS

获取gc日志

找到对应的/Middleware/user_projects/domains/base_domain/bin/setDomainEnv.sh文件，在文件末尾添加以下参数，重启weblogic

#JAVA_OPTIONS="${JAVA_OPTIONS} -verbose:gc -Xloggc:log/gc.log -XX:+PrintGC "
export JAVA_OPTIONS

JVM的GC日志的主要参数包括如下几个：
-XX:+PrintGC 输出GC日志
-XX:+PrintGCDetails 输出GC的详细日志
-XX:+PrintGCTimeStamps 输出GC的时间戳（以基准时间的形式）
-XX:+PrintGCDateStamps 输出GC的时间戳（以日期的形式，如 2013-05-04T21:53:59.234+0800）
-XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
-Xloggc:../logs/gc.log 日志文件的输出路径

实例分析

运行环境：Red Hat Enterprise Linux Server release 5.4 (Tikanga) + weblogic 12.1.1.

测试代码为index.jsp：

<%@ page language="java" contentType="text/html; charset=UTF-8"
pageEncoding="UTF-8"%>
<%@page import="java.util.*"%>
<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN" "http://www.w3.org/TR/html4/loose.dtd">
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=UTF-8">
<title>Insert title here</title>
<%
List<String> list = new ArrayList<String>();
int start = 1;
for (int i =start; i <=start+1; i++){
      list.add(new String("test"));
      out.print(list.size());
      System.out.println(list.size());
}
while(start!=0){
list.add(new String("test"));
out.print(list.size());
System.out.println(list.size());
}
%>
</head>
<body>
test
</body>
</html>

很明显，这是一个死循环。启动weblogic在本地用jVisualVM监测。然后访问JSP文件，

现象

heap内存急剧消耗，频繁gc。此时手动生成threadDump与heapDump，然后关闭浏览器，停止访问。

heap内存下降，gc频率也下降。

分析

用IBMHeapAnalyzer打开heapDump文件。用java -Xmx256m -jar ha456.jar启动IBMHeapAnalyzer，由于heapDump文件比较大，如果启动过程出现OOM，加大-Xmx256m的值。效果如下：

点击analysis view，
北京联动北方科技有限公司

可以看出是ArrayList中存放了太多的对象。
再看threadDump文件，发现如下线程：

"[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x81fee000 nid=0x5081 runnable [0x82154000]
java.lang.Thread.State: RUNNABLE
at java.io.FileOutputStream.writeBytes(Native Method)
at java.io.FileOutputStream.write(FileOutputStream.java:282)
at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
- locked <0x90053878> (a java.io.BufferedOutputStream)
at java.io.PrintStream.write(PrintStream.java:432)
- locked <0x90028210> (a java.io.PrintStream)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:202)
at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:272)
at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:85)
- locked <0x900538b8> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:168)
at java.io.PrintStream.write(PrintStream.java:477)
- locked <0x90028210> (a java.io.PrintStream)
at java.io.PrintStream.print(PrintStream.java:547)
at java.io.PrintStream.println(PrintStream.java:686)
- locked <0x90028210> (a java.io.PrintStream)
at jsp_servlet.__index._jspService(__index.java:89)
at weblogic.servlet.jsp.JspBase.service(JspBase.java:34)
at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:242)
at weblogic.servlet.internal.StubSecurityHelper$ServletServiceAction.run(StubSecurityHelper.java:216)
at weblogic.servlet.internal.StubSecurityHelper.invokeServlet(StubSecurityHelper.java:132)
at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:338)
at weblogic.servlet.internal.ServletStubImpl.onAddToMapException(ServletStubImpl.java:453)
at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:364)
at weblogic.servlet.internal.ServletStubImpl.execute(ServletStubImpl.java:221)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3284)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3254)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
at weblogic.servlet.provider.WlsSubjectHandle.run(WlsSubjectHandle.java:57)
at weblogic.servlet.internal.WebAppServletContext.doSecuredExecute(WebAppServletContext.java:2163)
at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2089)
at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2074)
at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1513)
at weblogic.servlet.provider.ContainerSupportProviderImpl$WlsRequestExecutor.run(ContainerSupportProviderImpl.java:254)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:256)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)
Locked ownable synchronizers:
- None

“ at jsp_servlet.__index._jspService(__index.java:89)”通过这一句可以定位到index.jsp文件的问题，然后结合代码，基本可以判断问题所在。
通过IBM Pattern Modeling and Analysis Tool for Java Garbage Collector工具打开gc日志，观察垃圾回收的相关信息
北京联动北方科技有限公司
用graphic view all 视图，观察gc频率与内存回收，