JAVA问题定位技术

常用的JAVA调试技巧：
线程堆栈解读
性能瓶颈分析
远程调试
内存泄露检测

常用工具集：
proc工具集
系统跟踪命令truss/strace
Core文件管理coreadm
进程状态监控prstat
网络状态监控netstat
磁盘监控iostat
CPU和内存监控vmstat抓包工具……

输出线程堆栈：
Windows:在运行java的控制台上按ctrl+break组合键
Unix:保留启动java的控制台，使用kill -3 <pid>
*:启动时进行重定向是一个不错的习惯：run.sh > start.log 2>@1

堆栈的作用：
线程死锁分析
辅助CPU过高分析
线程资源不足分析
性能瓶颈分析
关键线程异常退出

解读线程堆栈：
wait() ————会释放监视锁
sleep() ————与锁操作无关，继续保持监视锁
当一个线程占有一个锁的时候，会打印- locked <0xe7402c48>
当该线程正在等待别的线程释放该锁，就会打印：waiting to lock <0xe7402c48>
如果代码中有wait()调用的话，首先是locked，然后又会打印 - waiting on <0xe7402c48>
例如：
"http-0.0.0.0-27443-Processor4" daemon prio=5 tid=0x599a7520 nid=0x1858 in Object.wait() [5c9ef000..5c9efd88]
at java.lang.Object.wait(Native Method)
- waiting on <0x1693d2f8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Object.wait(Object.java:429)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:655)
- locked <0x1693d2f8> (a org.apache.tomcat.util.threads.ThreadPool$ControlRunnable)
at java.lang.Thread.run(Thread.java:534)
其中- waiting on <0x1693d2f8>表示线程正停在该对象的wait上面。同时wait会自动释放该锁；- locked <0x1693d2f8>表示该线程锁住了该锁。

"smpp02:Sender-108" daemon prio=5 tid=0x59a751a0 nid=0x13fc waiting for monitor entry [6066f000..6066fd88]
at org.apache.log4j.Category.callAppenders(Category.java:185)
- waiting to lock <0x14fdfe98> (a org.apache.log4j.spi.RootCategory)
at org.apache.log4j.Category.forcedLog(Category.java:372)
at org.apache.log4j.Category.log(Category.java:864)
at org.apache.commons.logging.impl.Log4JLogger.debug(Log4JLogger.java:137)
at com.huawei.uniportal.comm.base.server.AbstractHandler.send(AbstractHandler.java:407)
at com.huawei.tellin.usr.uc.sendmessage.UCSMPPTransaction.send(UCSMPPTransaction.java:102)
at com.huawei.tellin.usr.uc.sendmessage.UCServerProxy.synSend(UCServerProxy.java:134)
at com.huawei.uniportal.comm.base.proxy.SendWorker.run(AbstractProxy.java:666)
at com.huawei.uniportal.utilities.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
at java.lang.Thread.run(Thread.java:534)
其中- waiting to lock <0x14fdfe98> waiting to lock <0x14fdfe98> 表示该锁已经被别的线程使用，正在等待该锁被释放。

线程死锁分析：
Found one Java-level deadlock:
=============================
"thread1":
  waiting to lock monitor 0x009fccb4 (object 0x10032710, a java.lang.Object),
  which is held by "thread1"
"thread1":
  waiting to lock monitor 0x009fcc94 (object 0x10032718, a java.lang.Object),
  which is held by "thread1"

Java stack information for the threads listed above:
===================================================
"thread0":
        at DeadLockTest.run(DeadLockTest.java:44)
        - waiting to lock <0x10032710> (a java.lang.Object)
        - locked <0x10032718> (a java.lang.Object)
        at java.lang.Thread.run(Unknown Source)
"thread1":
        at DeadLockTest.run(DeadLockTest.java:24)
        - waiting to lock <0x10032718> (a java.lang.Object)
        - locked <0x10032710> (a java.lang.Object)
        at java.lang.Thread.run(Unknown Source)
0x10032710 和 0x10032718 都在等待对方释放，双方都被饿死.

用户代码导致CPU过高/热点线程分析：

首先可以通过kill -3 pid(unix下) 或 <ctrl>+<break>( windows下) 获取一个堆栈信息，
几分钟之后再获取一个，通过两个堆栈信息对比，将一直在忙的线程找出来。
通过分析对应的代码，确认不正常的线程。

第一步：通过kill -3 java_pid 获取当前堆栈信息。
第二步：等待一段时间后。再获取一下当前堆栈信息。
第三步：预处理前两个获取的堆栈信息，去掉处于sleeping或waiting的状态的线程。
例如如下线程处于wait或者sleep状态，
这种线程是不消耗CPU的，因此这些线程可以直接忽略掉，重点关注其它线程：
"EventManager-Worker-1" daemon prio=8 tid=0x00c3ea58 nid=0x14a in Object.wait() [935ff000..935ffc28]
at java.lang.Object.wait(Native Method)   //该线程已挂起，忽略掉
- waiting on <0xbb9515a8> (a org.exolab.core.util.FifoQueue)
at java.lang.Object.wait(Object.java:429)
第五步：对比预处理后的1，2堆栈信息，找出处于busy状态的线程，该类线程可能是导致cpu高占用率的可疑线程。
例如：(下面的是在第一个堆栈信息中找到的处于active 活跃状态的线程)

"http-80-Processor6" daemon prio=5 tid=0x013ea770 nid=0x143 runnable [92eff000..92f019c0]
at com.huawei.u_sys.common.licmgr.LicenseIntf.nativeCheckLicense(Native Method)
at com.huawei.u_sys.common.licmgr.LicenseIntf.checkLicense(LicenseIntf.java:168)
at com.huawei.u_sys.meetingone.sysmgr.ejb.LicRelateBean.updateLic(LicRelateBean.java:80)

同一个线程在第二个堆栈信息中仍处于活跃状态。
"http-80-Processor6" daemon prio=5 tid=0x013ea770 nid=0x143 runnable [92eff000..92f019c0]
at com.huawei.u_sys.common.licmgr.LicenseIntf.nativeCheckLicense(Native Method)
at com.huawei.u_sys.common.licmgr.LicenseIntf.checkLicense(LicenseIntf.java:168)
at com.huawei.u_sys.meetingone.sysmgr.ejb.LicRelateBean.updateLic(LicRelateBean.java:80)
两次打印堆栈该线程一直在运行，说明该线程已运行了5分钟，请在代码中检查该线程是否属于长时间运行线程？如果属于暂态线程，如此长时间运行说明可能有死循环等导致的CPU过高。

评论

1 楼 stardust1900 2012-08-14  

at com.huawei.u_sys.common.licmgr.LicenseIntf.nativeCheckLicense(Native Method)
at com.huawei.u_sys.common.licmgr.LicenseIntf.checkLicense(LicenseIntf.java:168)
at com.huawei.u_sys.meetingone.sysmgr.ejb.LicRelateBean.updateLic(LicRelateBean.java:80)

妹纸，你这不违反信息安全咩？