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命令观察系统资源状况

Mandy Chung's Blog 有一篇关于Thread Dump and Concurrency Locks的blog，摘来如下：
Thread dumps are very useful for diagnosing synchronization related problems such as deadlocks on object monitors. Ctrl-/ on Solaris/Linux or Ctrl-Break on Windows has been a common way to get a thread dump of a running application. On Solaris or Linux, you can send a QUIT signal to the target application. The target application in both cases prints a thread dump to the standard output and also detects if there is any deadlock involving object monitors.
jstack, a new troubleshooting utility introduced in Tiger (J2SE 5.0), provides another way to obtain a thread dump of an application. Alan Bateman has a nice blog about jstack and its several improvements in Mustang (Java SE 6). Mustang jstack works like a remote Ctrl-/ or Ctrl-Break if you are on Windows.
jconsole is JMX-complaint GUI tool which allows you to get a thread dump on the fly. The "Using JConsole to Monitor Applications" article gives you an overview of the Tiger monitoring and management functionality.
Mustang extends the thread dump, jstack, and jconsole to support java.util.concurrent.locks to improve its diagnosability. For example, the Threads tab in the Mustang jconsole now shows which synchronizer a thread is waiting to acquire when the thread is blocked to lock a ReentrantLock and also which thread is owning that lock.

In addition, it has a new "detect deadlock" button (in the bottom). When you click on the "detect deadlock" button, it will send a request to the target application to perform the deadlock detection operation. If the target application is running on Mustang, it finds deadlocks involving both object monitors as well as the java.util.concurrent.locks. If the target application is running on Tiger, it finds deadlocks involving object monitors only. Each deadlock cycle will be displayed in a separate Deadlock tab.

Click here to see a wider form of this screenshot.
JDK 6 has a nice demo FullThreadDump under $JDK_HOME/demo/management/FullThreadDump where JDK_HOME is the location of your JDK 6. This demo has been included in JDK 5.0 and is updated to use the new Mustang API. It demonstrates the use of the java.lang.management API to get the thread dump and detect deadlock programmatically.