使用jdk的jps、jstack工具检测代码问题，提高程序性能



今天给大家分享怎样利用jdk的jps和jstack工具结合定位代码的问题，提高程序的稳定性、健壮性和性能。

在jdk的bin，目录下面有很多的工具如图：



jps、jstack工具介绍:

jps:
是JDK1.5提供的一个显示当前所有java进程pid的命令，简单实用，非常适合在linux/unix平台上简单察看当前java进程的一些简单情况。
命令格式：jps [options ] [ hostid ]
[options]选项 ：
-q：仅输出VM标识符，不包括classname,jar name,arguments in main method 
-m：输出main method的参数 
-l：输出完全的包名，应用主类名，jar的完全路径名 
-v：输出jvm参数 
-V：输出通过flag文件传递到JVM中的参数(.hotspotrc文件或-XX:Flags=所指定的文件 
-Joption：传递参数到vm,例如:-J-Xms1024m
用-l作示例:


在图中，第一例是进程号，第二例是进程名（运行的程序），比如activemq（/home/activeMq/apache-activemq-5.5.1/bin/run.jar）、dubbo服务（com.alibaba.dubbo.container.Main）、tomcat(org.apache.catalina.startup.Bootstrap)等等。
jstack:jstack是java虚拟机自带的一种堆栈跟踪工具。jstack用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。
 线程出现停顿的时候通过jstack来查看各个线程的调用堆栈，就可以知道没有响应的线程到底在后台做什么事情，或者等待什么资源。命令格式:jstack [ option ] pid[options]选项 ：-F :当’jstack [-l] pid’没有响应的时候强制打印栈信息;-l :长列表. 打印关于锁的附加信息,例如属于java.util.concurrent的ownable synchronizers列表.-m: 打印java和native c/c++框架的所有栈信息. -h | -help打印帮助信息pid :需要被打印配置信息的java进程id,可以用jps工具查询用-l作示例：
命令：

运行结果：


从图中我们可以查看各个线程的调用堆栈，就可以知道没有响应的线程到底在后台做什么事情，或者等待什么资源。
jps、jstack查找代码问题
原理：通过jps命令查找到对应程序的进程，记录进程号，通过jstack命令把该进程号所在的程序的线程堆栈信息输出到文件，然后对文件里面的信息进行分析，找到原因并解决问题。注：这种方式尽量在并发的时候进行使用这样更容易找出代码问题。
步骤：
1).进入到jdk的bin目录，如图：


2).使用jps工具查看tomcat的进程（如果是linux环境建议使用ps命令）；因为只安装了一个tomcat，使用jps -m命令（如果安装了多个tomcat ，请使用jps -v命令，该命令运行的结果中可以看到各个tomcat的路径）



3).执行jstack命令，并把输出结果输出到日志文件；
命令：
[root@s4 bin]# jstack 28501 >log1.log

打开文件log1.log文件看里面内容：
[root@s4 bin]# tail -200f log1.log
- locked <0x00000007058fc4b0> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)
at java.lang.Thread.run(Thread.java:662)

"http-8090-11" daemon prio=10 tid=0x00002aaab4047000 nid=0x7181 in Object.wait() [0x000000004238b000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000007056433f0> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:458)
- locked <0x00000007056433f0> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)
at java.lang.Thread.run(Thread.java:662)

"http-8090-10" daemon prio=10 tid=0x00002aaab46ec000 nid=0x7180 in Object.wait() [0x000000004228a000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000705643610> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:458)
- locked <0x0000000705643610> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)
at java.lang.Thread.run(Thread.java:662)

"http-8090-9" daemon prio=10 tid=0x00002aaab4525800 nid=0x717f in Object.wait() [0x000000004078a000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000705643898> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at java.lang.Object.wait(Object.java:485)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.await(JIoEndpoint.java:458)
- locked <0x0000000705643898> (a org.apache.tomcat.util.net.JIoEndpoint$Worker)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:484)
at java.lang.Thread.run(Thread.java:662)

4).日志文件进行分析
由于上面的tomcat没有进行压力测试，所以看到的都是tomcat的线程没有自己程序代码的线程。因此使用前段时间的进过
压力测试后导出的日志进行分析。部分日志内容如下："DubboClientHandler-192.168.6.162:2099-thread-2" daemon prio=10 tid=0x00002aaac069a000 nid=0x14c1 waiting on condition [0x000000004867f000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000782c4d8e0> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:662)

"DubboClientHandler-192.168.6.162:2099-thread-2" daemon prio=10 tid=0x000000005be86000 nid=0x14c0 waiting on condition [0x000000004863e000]
java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000782c61ac0> (a java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:662)

"http-portal%2F192.168.6.162-8097-184" daemon prio=10 tid=0x00002aaab0ecc800 nid=0x2d7a waiting for monitor entry [0x0000000045fa9000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:204)
- waiting to lock <0x00000007800020a0> (a org.apache.log4j.spi.RootLogger)
at org.apache.log4j.Category.forcedLog(Category.java:391)
at org.apache.log4j.Category.log(Category.java:856)
at org.slf4j.impl.Log4jLoggerAdapter.info(Log4jLoggerAdapter.java:304)


从最后的日志中我们可以看出这个日志线程处于BLOCKED状态，进入org.apache.log4j.Category类的callAppenders方法，代码如下：/**
Call the appenders in the hierrachy starting at
<code>this</code>. If no appenders could be found, emit a
warning.

<p>This method calls all the appenders inherited from the
hierarchy circumventing any evaluation of whether to log or not
to log the particular log request.

@param event the event to log.
*/
public void callAppenders(LoggingEvent event) {
int writes = 0;

for(Category c = this; c != null; c=c.parent) {
// Protected against simultaneous call to addAppender, removeAppender,...
synchronized(c) {
if(c.aai != null) {
writes += c.aai.appendLoopOnAppenders(event);
}
if(!c.additive) {
break;
}
}
}

if(writes == 0) {
repository.emitNoAppenderWarning(this);
}
}

从上面可以看出在该方法中有synchronized同步锁，同步锁会导致线程竞争，那么在大并发情况下将会出现性能问题，同时
会引起线程BLOCKED问题。可以使用Apache log 解决这个问题，代码如下：private static final Log log = LogFactory.getLog("xxx");

通过测试,org.apache.log4j.Category.callAppenders线程BLOCKED问题没有了。
上面只是一个非常简单的示例，现实开发过程中可以根据线程的状态能够找出很多问题。大家不妨尝试一下。
---------------------------------------------------------------------------版权声明------------------------------------------------------------------------------------------
版权声明：本文为博主原创文章，未经博主允许不得转载。博客地址:http://blog.csdn.net/mr_smile2014