Thread Dump 和Java应用诊断

Thread Dump 和Java应用诊断

 

Thread Dump是非常有用的诊断Java应用问题的工具，每一个Java虚拟机都有及时生成显示所有线程在某一点状态的thread-dump的能力。虽然 各个Java虚拟机thread dump打印输出格式上略微有一些不同，但是Thread dumps出来的信息包含线程；线程的运行状态、标识和调用的堆栈；调用的堆栈包含完整的类名，所执行的方法，如果可能的话还有源代码的行数。

Thread Dump特点：

• 能在各种操作系统下使用
• 能在各种Java应用服务器下使用
• 可以在生产环境下使用而不影响系统的性能
• 可以将问题直接定位到应用程序的代码行上

Thread Dump能诊断的问题包括：

• 查找内存泄露，常见的是程序里load大量的数据到缓存
• 发现死锁线程

Sun的JVM用下列方法可以产生Thread Dump堆栈信息：

1，Solaris OS
<ctrl>-’\’ (Control-Backslash)
 kill -QUIT <pid>

2, HP-UX/UNIX/Linux
Kill -3 PID 
PID通过下面方法获取
ps -efHl | grep 'java' **. **

3，Windows
直接对MSDOS窗口的程序按Ctrl-break

有些Java应用服务器是在控制台上运行，如Weblogic，为了方便获取threaddump信息，在weblogic启动的时候，最好将其标准输出重定向到一个文件，用"nohup sh startWebLogic.sh > start.log &"命令，执行"kill -3 <pid>"，Stack trace就会输出到start.log里。Tomcat的Thread Dump会输出到命令行控制台或者logs的catalina.out文件里。为了 反映线程状态的动态变化，需要接连多次做thread dump，每次间隔10-20s。

IBM JVM下产生Thread Dump：

在AIX上用IBM的JVM，内存溢出时默认地会产生javacore文件（关于cpu的）和heapdump文件(关于内存的)。如果没有参照下列方法：
1 choose one cluster member, set the following before this server start:
在was启动前设置下面环境变量（可以加在启动脚本中）
export IBM_HEAPDUMP=true
export IBM_HEAP_DUMP=true
export IBM_HEAPDUMP_OUTOFMEMORY=true
export IBM_HEAPDUMPDIR=<directory path>

2 please use set command to make sure you do not have DISABLE_JAVADUMP parameter
then start this cluster member.
用set命令检查参数设置，确保没有设置DISABLE_JAVADUMP，然后启动server

3 when you find free memory < 50% when no heavy access, please run kill -3 <pid>
执行kill -3 <pid>命令可以生成javacore文件和heapdump文件（pid为was java进程的id号，可以用ps -ef|grep java 查到），可以多执行几次，按照下面操作进行

ps -ef > psef1.txt
ps aux > psaux1.txt
vmstat 5 10 > vmstat.txt
kill -3 <app server id>
wait for 2 mins
kill -3 <app server id>
wait for 2 mins
kill -3 <app server id>
netstat -an> netstat2.txt
ps -ef > psef2.txt
ps aux > psaux2.txt
将上面产生的 txt 文件和/usr/WebSphere/AppServer/javacore*文件和heapdump文件拷贝到本地，然后删除这些文件，因为这些文件会占用较大的文件系统空间。
将/usr/WebSphere/AppServer/logs/wlmserver1(或2)目录下当天产生的日志拷贝出来

在IBM JVM产生的javacore或者Threaddump文件中应用服务器Web容器的常见线程状态：

Idle线程：一个已经准备好接受请求的线程，但是没有和插件或者客户端建立连接
Keep-Alive线程：是一个已经准备好接受请求的线程，并且已经和插件或者客户端建立连接
正在接受请求的线程：是一个线程正在读取request的内容或者头部

下面就给出各种线程在javacore或者Threaddump中的表现形式：

Idle线程：
"Servlet.Engine.Transports : 20" (TID:0x427F190, sys_thread_t:0x15D175E8, state:R, native ID:0xBB8) prio=5
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:429)
at com.ibm.ws.util.BoundedBuffer.take(BoundedBuffer.java:161)
at com.ibm.ws.util.ThreadPool.getTask(ThreadPool.java(Compiled Code)) at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java(Compiled Code))

Keep-alive线程 (非SSL模式)：
"Servlet.Engine.Transports : 20" (TID:0x427F190, sys_thread_t:0x15D175E8, state:R, native ID:0xBB8) prio=5
at java.net.SocketInputStream.socketRead(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:86)
at com.ibm.ws.io.Stream.read(Stream.java)
at com.ibm.ws.io.ReadStream.readBuffer(ReadStream.java)
at com.ibm.ws.io.ReadStream.read(ReadStream.java)
at com.ibm.ws.http.HttpRequest.readRequestLine(HttpRequest.java)
at com.ibm.ws.http.HttpRequest.readRequest(HttpRequest.java)
at com.ibm.ws.http.HttpConnection.readAndHandleRequest(HttpConnection.java)
at com.ibm.ws.http.HttpConnection.run(HttpConnection.java)
at com.ibm.ws.util.CachedThread.run(ThreadPool.java)

Keep-alive线程 (SSL模式)：
"Servlet.Engine.Transports : 12" (TID:0x458DBA18, sys_thread_t:0x60B297C0, state:R, native ID:0x427E) prio=5
at java.net.SocketInputStream.socketRead(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java(Compiled Code))
at com.ibm.sslite.s.a(Unknown Source)(Compiled Code)
at com.ibm.sslite.s.b(Unknown Source)(Compiled Code)
at com.ibm.sslite.s.a(Unknown Source)(Compiled Code)
at com.ibm.sslite.a.read(Unknown Source)(Compiled Code)
at com.ibm.jsse.a.read(Unknown Source)(Compiled Code)
at com.ibm.ws.io.Stream.read(Stream.java(Compiled Code))
at com.ibm.ws.io.ReadStream.readBuffer(ReadStream.java(Inlined Compiled Code))
at com.ibm.ws.io.ReadStream.read(ReadStream.java(Inlined Compiled Code))
at com.ibm.ws.http.HttpRequest.readRequestLine(HttpRequest.java(Compiled Code))
at com.ibm.ws.http.HttpRequest.readRequest(HttpRequest.java(Compiled Code))
at com.ibm.ws.http.HttpConnection.readAndHandleRequest(HttpConnection)
at com.ibm.ws.http.HttpConnection.run(HttpConnection.java(Compiled Code))
at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:672)


正在接受请求的线程：
at java.net.SocketInputStream.socketRead(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:85)
at com.ibm.ws.io.Stream.read(Stream.java:17)
at com.ibm.ws.io.ReadStream.readBuffer(ReadStream.java:411)
at com.ibm.ws.io.ReadStream.read(ReadStream.java:110)
at com.ibm.ws.http.HttpConnection.run(HttpConnection.java:448)
at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:672)

Sun JVM的常见线程状态：

对于thread dump信息，主要关注的是线程的状态和其执行堆栈
线程的状态一般为三类
Runnable（R）：当前可以运行的线程
Waiting on monitor（CW）：线程主动wait
Waiting for monitor entry（MW）：线程等锁
一般关注的都是第一和第三种状态的线程
Cpu很忙则关注runnable的线程
Cpu闲则关注waiting for monitor entry的线程
一种典型的死锁是由于在server端应用（比如servlet）中请求由同一weblogic实例server的资源
解决办法就是将该servlet放到另外的执行队列里去执行

下面给出一个典型的死锁线程（注意STUCK关键字 ）：

"[STUCK ] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=02fe9a18 nid=35 lwp_id=7518924 runnable [440dd000..440db878]
 at java.net.SocketInputStream.socketRead0(Native Method)
 at java.net.SocketInputStream.read(SocketInputStream.java:134)
 at weblogic.jdbc.oracle.net8.OracleDataProvider.getArrayOfBytesFromSocket(Unknown Source)
 at weblogic.jdbc.oracle.net8.OracleDataProvider.readFirstPacketInBuffer(Unknown Source)
 at weblogic.jdbc.oracle.net8.OracleDataProvider.readPacket(Unknown Source)
 at weblogic.jdbc.oracle.net8.OracleDataProvider.receive(Unknown Source)
 at weblogic.jdbc.oracle.net8.OracleNet8NSPTDAPacket.sendRequest(Unknown Source)
 at weblogic.jdbc.oracle.OracleImplStatement.fetchNext(Unknown Source)
 at weblogic.jdbc.oracle.OracleImplStatement.fetchNext2(Unknown Source)
 at weblogic.jdbc.oracle.OracleImplResultset.fetchAtPosition(Unknown Source)
 at weblogic.jdbc.base.BaseImplResultSet.next(Unknown Source)
 at weblogic.jdbc.base.BaseResultSet.next(Unknown Source)
 - locked <55f25550> (a weblogic.jdbc.oracle.OracleConnection)
 at weblogic.jdbc.wrapper.ResultSet_weblogic_jdbc_base_BaseResultSet.next(Unknown Source)
 at org.hibernate.loader.Loader.doQuery(Loader.java:685)

UNIX/Linux下可用top、vmstat或prstat 命令观察系统资源状况