【译】分析java线程(analyze java thread)

看见一篇比较不错的关于java线程的文章，决定翻译一下，顺便体会一下翻译外文是啥感觉。

原文链接如下呵呵。

        http://www.cubrid.org/blog/dev-platform/how-to-analyze-java-thread-dumps/

 

 

当遇到问题或者基于java web的程序跑的比期望中慢，这时候我们需要使用线程dump。如果thread dump对你感觉比较复杂，这篇文章将会帮助你。这里我将先简单介绍一下java线程中的一些简单概念等，然后如何从一个正在跑的程序里面dump thread，之后分析这些线程的各个状态，然后优化性能。

web类服务使用数以百计的线程来处理大量用户的并发请求。如果两个或者更多的线程需要使用相同的资源，这时候就不可避免的出现线程间的竞争或者死锁现象。

线程竞争是指一个线程等待被另外一个线程占用的锁，例如在web应用中，不同的线程要获取共享资源。

线程死锁是指两个或多线线程互相等待对方完成任务，进入了无限的等待中。

为了分析线程的dump信息，需要了解线程的各个状态，下面这张图形象的介绍了几种状态。 

NEW: 线程被创建，但是没有被执行

RUNNABLE: 线程获取到了CPU的分片，处理任务（有可能处于WAITING状态，这取决于操作系统）

BLOCKED:线程等带其他线程释放锁

WAITING:程序调用wait/join方法，使线程处于等待状态

TIMED_WAITING: 线程等待特定的时间，程序调用sleep、wait、join，并带有时间参数

（一）获取线程的dump信息

（1）通过使用JDK自带的jstack获取线程dump信息；

（2）通过可视化工具，例如jconsole、visoleVM来获取

通过可视化工具非常简单，这里不做介绍，线上环境还是用命令行的形式搞定。

1、获取进程的PID，(jps or ps –ef | grep jva  or pgrep java)

2、jstack 打印文件，可以重定向到一个文件保存起来

 

 

Jstack中的参数：

-F 强制进行线程dump，当执行jstack pid没有反应的时候，可以执行此命令

-m 打印java线程还有本地线程

-l 打印线程的锁附加信息

（二）线程信息中各个字段的含义

"pool-1-thread-13" prio=6 tid=0x000000000729a000 nid=0x2fb4 runnable [0x0000000007f0f000] java.lang.Thread.State: RUNNABLE

              at java.net.SocketInputStream.socketRead0(Native Method)

 

        Thread name: When using Java.lang.Thread class to generate a thread, the thread will be named Thread-(Number), whereas when using java.util.concurrent.ThreadFactory class, it will be named pool-(number)-thread-(number).

Priority: 代表线程的优先级

Thread ID: 线程的唯一标示，通过这个ID可以获取一些有用的信息，例如CPU以及内存使用情况

Thread status: 线程的状态

Thread callstack: 方法栈中的信息

线程处于BLOCKED状态

例如下面的信息，线程在等待锁。

 

"BLOCKED_TEST pool-1-thread-2" prio=6 tid=0x0000000007673800 nid=0x260c waiting for monitor entry [0x0000000008abf000]

   java.lang.Thread.State: BLOCKED (on object monitor)

                at com.nbp.theplatform.threaddump.ThreadBlockedState.monitorLock(ThreadBlockedState.java:43)

                - waiting to lock <0x0000000780a000b0> (a com.nbp.theplatform.threaddump.ThreadBlockedState)

                at com.nbp.theplatform.threaddump.ThreadBlockedState$2.run(ThreadBlockedState.java:26)

                at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

                at java.lang.Thread.run(Thread.java:662)

 

   Locked ownable synchronizers:

                - <0x0000000780b0c6a0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

 

"

（三）死锁的情况

线程A需要获取线程B的锁才能完成它的任务，同时线程B需要获取线程A的锁来进行任务。

例如下面的信息中，

 线程 DEADLOCK_TEST-1 thread 有 0x00000007d58f5e48 这个锁,试图获取这个锁 0x00000007d58f5e60 .

 线程 DEADLOCK_TEST-2 thread 有0x00000007d58f5e60 这个锁,试图获取这个锁 0x00000007d58f5e78 .

 线程DEADLOCK_TEST-3 thread 有 0x00000007d58f5e78 这个锁,试图获取这个锁 0x00000007d58f5e48 l

从而导致死锁。

"DEADLOCK_TEST-1" daemon prio=6 tid=0x000000000690f800 nid=0x1820 waiting for monitor entry [0x000000000805f000]

   java.lang.Thread.State: BLOCKED (on object monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.goMonitorDeadlock(ThreadDeadLockState.java:197)

                - waiting to lock <0x00000007d58f5e60> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.monitorOurLock(ThreadDeadLockState.java:182)

                - locked <0x00000007d58f5e48> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)

 

   Locked ownable synchronizers:

                - None

 

"DEADLOCK_TEST-2" daemon prio=6 tid=0x0000000006858800 nid=0x17b8 waiting for monitor entry [0x000000000815f000]

   java.lang.Thread.State: BLOCKED (on object monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.goMonitorDeadlock(ThreadDeadLockState.java:197)

                - waiting to lock <0x00000007d58f5e78> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.monitorOurLock(ThreadDeadLockState.java:182)

                - locked <0x00000007d58f5e60> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)

 

   Locked ownable synchronizers:

                - None

 

"DEADLOCK_TEST-3" daemon prio=6 tid=0x0000000006859000 nid=0x25dc waiting for monitor entry [0x000000000825f000]

   java.lang.Thread.State: BLOCKED (on object monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.goMonitorDeadlock(ThreadDeadLockState.java:197)

                - waiting to lock <0x00000007d58f5e48> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.monitorOurLock(ThreadDeadLockState.java:182)

                - locked <0x00000007d58f5e78> (a com.nbp.theplatform.threaddump.ThreadDeadLockState$Monitor)

                at com.nbp.theplatform.threaddump.ThreadDeadLockState$DeadlockThread.run(ThreadDeadLockState.java:135)

 

   Locked ownable synchronizers:

                - None

（四）程序反常的比较慢时，如何来处理？

在多次dump之后，发现有以下几个线程处于阻塞状态

" DB-Processor-13" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f000]

java.lang.Thread.State: BLOCKED (on object monitor)

                at beans.ConnectionPool.getConnection(ConnectionPool.java:102)

                - waiting to lock <0xe0375410> (a beans.ConnectionPool)

                at beans.cus.ServiceCnt.getTodayCount(ServiceCnt.java:111)

                at beans.cus.ServiceCnt.insertCount(ServiceCnt.java:43)

 

"DB-Processor-14" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f020]

java.lang.Thread.State: BLOCKED (on object monitor)

                at beans.ConnectionPool.getConnection(ConnectionPool.java:102)

                - waiting to lock <0xe0375410> (a beans.ConnectionPool)

                at beans.cus.ServiceCnt.getTodayCount(ServiceCnt.java:111)

                at beans.cus.ServiceCnt.insertCount(ServiceCnt.java:43)

 

" DB-Processor-3" daemon prio=5 tid=0x00928248 nid=0x8b waiting for monitor entry [0x000000000825d080]

java.lang.Thread.State: RUNNABLE

                at oracle.jdbc.driver.OracleConnection.isClosed(OracleConnection.java:570)

                - waiting to lock <0xe03ba2e0> (a oracle.jdbc.driver.OracleConnection)

                at beans.ConnectionPool.getConnection(ConnectionPool.java:112)

                - locked <0xe0386580> (a java.util.Vector)

                - locked <0xe0375410> (a beans.ConnectionPool)

                at beans.cus.Cue_1700c.GetNationList(Cue_1700c.java:66)

                at org.apache.jsp.cue_1700c_jsp._jspService(cue_1700c_jsp.java:120)

从上面的信息中可以看出，线程阻塞在获取数据库连接，这时候分析可能有两个原因：

第一个是错误的配置；

第二个是反常的数据库连接；

 

（五）为了方便排查问题，编写多线程代码的时候，最好对线程进行命名

 

（六）通过使用Mbean获取更多的线程信息

核心的代码如下：

ThreadMXBean mxBean = ManagementFactory.getThreadMXBean();

long[] threadIds = mxBean.getAllThreadIds();

ThreadInfo[] threadInfos =mxBean.getThreadInfo(threadIds);

 

（七）处理CPU利用率突然特别高的问题，看看CPU最高的那个线程在做什么

例子：查看特定java线程的情况：

（一）通过top命令，查看消耗内存较高的线程的id，

         运行top,shift+h来显示所有进程的信息，包含进程中线程的情况，从中找出占用内存最大的那个java线程。

         也可直接运行：top -H -p  pid  来显示java进程中的各个线程的情况(p是显示特定的进程号，H是显示进程中的所有线程)

（二）进制间的转换：

         printf '0x%x\n'   pid

         获取线程ID的另外一中展现形式

（三）dump线程，然后搜搜索线程为上述ID的线程的信息

总结：

对于这篇文章，我主要对于开发者介绍了一些关于多线程处理的经验，这些对于一些经验丰富的开发者来说可能是一些简单的知识。我感觉对于线程没有提供丰富的背景信息，而是直接介绍了thread dump，我希望这篇文章能够给更多的开发者带来帮助。

 

 

评论

1 楼 baso4233 2012-12-27  

学习了。