首页 > 代码库 > 使用jdk的jps、jstack工具检测代码问题,提高程序性能

使用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




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