Java线程Dump分析(TDA-Thread Dump Analyzer)
线程栈是JVM瞬时快照,包含线程状态以及调用关系,借助堆栈信息主要目的分析定位线程出现长时间停顿的原因,比如线程死锁,锁争用,死循环,识别耗时操作等等。线程出现停顿的时候通过jstack来查看各个线程的调用堆栈,就可以知道没有响应的线程到底在后台做什么事情,或者等待什么资源。线程栈是瞬时记录,所以没有历史消息的回溯,一般我们都需要结合程序的日志进行跟踪,一般线程栈能分析如下性能问题:
- 系统无缘无故的cpu过高
- 系统挂起,无响应
- 系统运行越来越慢
- 性能瓶颈(如无法充分利用cpu等)
- 线程死锁,死循环等
- 由于线程数量太多导致的内存溢出(如无法创建线程等)
一、如何获取、解读线程Dump文件
1、visualVM等可视化工具也可以获取线程Dump,但是生产环境一般还是用命令来获取,生成Dump文件后从服务器上取下来,使用工具来分析。
方式一:jstack命令,要分析多个转储,只需将它们附加(>>)到日志文件中即可。
#命令格式:jstack -l PID > pid.tdump -l打印关于锁的其他信息,比如拥有的java.util.concurrent ownable同步器的列表。pstack PID 查看本地栈Dump.(pstack在gdb中,需要安装 yum install -y gdb) [wjy@node101 ~]# jps 16108 Jps 12203 math-game.jar [wjy@node101 ~]# jstack -l 12203 > 12203.tdump [wjy@node101 ~]# sz 12203.tdump *B00000000000000 #线程栈是瞬时快照 如果要分析问题 最好要连续间隔多次日志来分问题 比如每20秒输出一次线程Dump,这里使用watch命令每隔20秒输出一次线程Dump 注意被执行的命令加前后引号 [wjy@node101 ~]# watch -n 20 "jstack -l 12203 >> 12203.tdump"
方式二:向Java虚拟机发送一个终止QUIT信号,命令格式:kill -QUIT <PID>
JDK将把线程转储写入标准输出。例如,如果您的应用程序在tomcat中运行,则在默认的tomcat安装中为“catalina.out”。在其他情况下,这可能只是启动应用程序的控制台。
方式三:使用JMX
JConsole、VisualVM使用JMX连接到正在运行的应用程序来直接获取线程转储文件。
2、线程Dump日志解读
1 2023-12-07 23:23:23 2 Full thread dump OpenJDK 64-Bit Server VM (25.382-b05 mixed mode): 3 4 "XNIO-1 task-10" #415 prio=5 os_prio=0 tid=0x00007f3eb4214800 nid=0x38d7 waiting on condition [0x00007f3e63fbc000] 5 java.lang.Thread.State: TIMED_WAITING (parking) 6 at sun.misc.Unsafe.park(Native Method) 7 - parking to wait for <0x00000006cd39ae40> (a org.jboss.threads.EnhancedQueueExecutor) 8 at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) 9 at org.jboss.threads.EnhancedQueueExecutor$PoolThreadNode.park(EnhancedQueueExecutor.java:2234) 10 at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1493) 11 at org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282) 12 at java.lang.Thread.run(Thread.java:750) 13 14 Locked ownable synchronizers: 15 - None
第1行:时间表示Dump提取时间;
第2行:表示JVM版本、模式;
第4行:
"XNIO-1 task-10":代表线程的名称。在实际开发中,最好取一个和业务相关的、见名知意的名字便于排查问题。
#415 :
daemon:如果有daemon 当前线程是守护线程 否则就是普通线程
"prio=5":表示当前java线程的优先级。
"os_prio=0":表示操作系统级别的优先级。
"tid=0x00007f3eb4214800":表示当前java线程十六进制id。
"nid=0x38d7":native thread id表示操作系统映射的本地线程十六进制id。
"waiting on condition":表示线程动作,至于具体动作解释在栈里有描述,这个例子关联的是第7行动作说明。
"[0x00007f3e63fbc000]":表示线程栈的起始地址。
第5行:线程状态
TIMED_WAITING:线程状态,有时限的等待;
(parking):线程状态具体描述:线程处于挂起中。
第6-12行:线程运行代码栈,调用顺序自下而上。
第7行:线程Dump分析的重要信息,线程动作说明,也叫调用修饰,表示线程在方法调用时,额外的重要的操作,修饰上方的方法调用。比如:
locked <地址> 目标:使用synchronized申请对象锁成功,监视器的拥有者。
waiting to lock <地址> 目标:使用synchronized申请对象锁未成功,在进入区等待。
waiting on <地址> 目标:使用synchronized申请对象锁成功后,释放锁并在等待区等待。
parking to wait for <地址> 目标,park是基本的线程阻塞原语,不通过监视器在对象上阻塞。随concurrent包会出现的新的机制,与synchronized体系不同。
第14-15行:jstack使用-l参数才会输出。打印当前线程拥有的java.util.concurrent ownable同步器的列表。
二、线程Dump分析基础-线程状态
1、NEW
线程通过new创建但还未被调用start()方法,未启动,不会出现在线程Dump中。
2、RUNNABLE (重点关注IO类型)
从虚拟机角度看,线程正在运行状态,可能会有某种耗时计算、IO等待、CPU时间片切换等, 但这个状态下发生的等待一般是其他系统资源, 而不是锁, Sleep等。处于RUNNABLE状态的线程是不一定消耗cpu,像socket IO操作,线程正在从网络上读取数据,线程绝大多数时间是被挂起的,只有当数据到达后,线程才会被唤起。挂起发生在本地代码(native)中,和虚拟机不一致,不像显式的调用sleep和wait方法,虚拟机才能知道线程的真正状态,但在本地代码中的挂起,虚拟机无法知道真正的线程状态,因此一概显示为RUNNABLE,线程动作一般显示runnable。
代码:
1 Socket socket = new Socket(); 2 socket.connect(new InetSocketAddress(InetAddress.getByAddress(new byte[] { (byte) 192, (byte) 168, 1, 14 }), 5678));
线程栈:
1 "IOThread" #10 prio=5 os_prio=0 tid=0x00000000187c7800 nid=0x8b0 runnable [0x00000000192ee000] 2 java.lang.Thread.State: RUNNABLE 3 at java.net.DualStackPlainSocketImpl.connect0(Native Method) 4 at java.net.DualStackPlainSocketImpl.socketConnect(DualStackPlainSocketImpl.java:79) 5 at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) 6 - locked <0x00000000eb6c0fa8> (a java.net.DualStackPlainSocketImpl) 7 at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) 8 at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) 9 at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:172) 10 at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) 11 at java.net.Socket.connect(Socket.java:589) 12 at java.net.Socket.connect(Socket.java:538) 13 at com.test.threadpool.TestThreadState$IOThread.run(TestThreadState.java:83)
虽然线程处在RUNNABLE的状态,但是还是有可能在等待IO。这样就很浪费CPU资源了,所以在使用线程池处理多线程任务的时候,如果是涉及到数据计算可以考虑使用多线程,如果是每个线程中都有网络请求的操作,切不可使用多线程来做,因为网络比较慢,会导致其他线程一直得不到执行,而那边线程数却一直在上涨,最后会导致线程挤压cpu会飚高,这种情况非常常见。常见网络IO调用栈:SocketInputStream、SocketImpl、socketRead0等方法,如果调用栈包含了jdbc相关的包,很可能发生了数据库死锁。网络耗时有三种可能:带宽被占满、网络故障无法路由、下游系统故障无法联通;
3、BLOCKED (重点关注waiting for monitor entry)
受阻塞并等待监视器锁。线程处于阻塞状态,正在等待一个监视器锁(monitor lock)。通常情况下,是因为本线程与其他线程公用了一个锁。其他在线程 已经正在使用这个锁 进入了某个synchronized同步方法块或者方法,而本线程进入这个同步代码块也需要这个锁,最终导致本线程处于阻塞状态。
"druid-consumer-pool-3" prio=10 tid=0x00007f9750e4d800 nid=0x2feb waiting for monitor entry [0x000070000511C000] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.Java:201) - waiting to lock <0x000000077f2891a0> (a org.apache.logj.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:388)
a)BLOCKED (on object monitor)说明线程处于阻塞状态,正在等待一个monitor lock。
阻塞原因:是因为本线程与其他线程公用了一个锁,这时,已经有其他在线程正在使用这个锁进入某个synchronized同步方法块或者方法。当本线程想要进入这个同步代码块时,也需要这个锁,但锁已被占用,从而导致本线程处于阻塞状态。
b)waiting for monitor entry:表明了线程在等待进入monitor。
Monitor是Java中用以实现线程之间的互斥与协作的主要手段,它可以看成是对象或者Class的锁。每一个对象都有,也仅有一个 monitor。每 Monitor在某个时刻,只能被一个线程拥有,该线程就是 “Active Thread”,而其它线程都是 “Waiting Thread”,分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”,而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。目前线程状态为:waiting for monitor entry,说明它是“Entry Set”里面的线程。我们称被 synchronized保护起来的代码段为临界区。当一个线程申请进入临界区时,它就进入了 “Entry Set”队列。
这时有两种可能性:
(1)该 monitor不被其它线程拥有, Entry Set里面也没有其它等待线程。本线程即成为相应类或者对象的 Monitor的 Owner,执行临界区的代码,在第种情况下,线程将处于 “Runnable”的状态;
(2)该 monitor被其它线程拥有,本线程在 Entry Set队列中等待,在第种情况下,线程Dump会显示处于 “waiting for monitor entry”。
根据以上分析,可以看出,线程想要调用log4j,目的是打印日志,但由于调用log4j写日志有锁机制,于是线程被阻塞了。再排查项目使用的log4j版本,得知此版本存在性能bug,优化手段为升级log4j版本或者调整日志级别、优化日志打印的内容,或者添加缓存。
c)waiting to lock:说明线程使用synchronized申请对象锁未成功,于是开始等待别的线程释放锁。线程在监视器的进入区等待。这条一般在调用栈顶出现,线程状态一般对应为Blocked。
4、WATING
无限期等待另一个线程执行特定操作。这个状态下是指线程拥有了某个锁之后,调用了他的wait方法, 等待其他线程/锁拥有者调用 notify / notifyAll一遍该线程可以继续下一步操作, 这里要区分BLOCKED 和 WATING 的区别, 一个是在临界点外面等待进入, 一个是在理解点里面wait等待别人notify,线程调用了join方法 join了另外的线程的时候, 也会进入WAITING状态,等待被他join的线程执行结束,处于waiting状态的线程基本不消耗CPU。当线程调用以下方法时会进入WAITING状态:Object#wait() 而且不加超时参数、Thread#join() 而且不加超时参数、LockSupport#park()
(1)调用wait()方法导致的WAITING状态【in Object.wait() 重点关注非线程池等待】
代码:
1 /** 2 * 线程调用wait方法,状态变成WAITING。 3 */ 4 public static void testStateWatingByWait() { 5 Object lock = new Object(); 6 WaitingThread waitingThread = new WaitingThread("WaitingThread", lock); 7 waitingThread.start(); 8 9 try { 10 Thread.sleep(100); 11 } catch (InterruptedException e) { 12 e.printStackTrace(); 13 } 14 15 System.out.println("Main thread check the state is " + waitingThread.getState() + "."); // WAITING 16 } 17 18 static class WaitingThread extends Thread { 19 private int timeout = 0; 20 private Object lock; 21 22 public WaitingThread(String name, Object lock) { 23 this(name, lock, 0); 24 } 25 26 public WaitingThread(String name, Object lock, int timeout) { 27 super(name); 28 this.timeout = timeout; 29 this.lock = lock; 30 } 31 32 @Override 33 public void run() { 34 synchronized (lock) { 35 if (timeout == 0) { 36 try { 37 System.out.println("Try to wait."); 38 lock.wait(); 39 } catch (InterruptedException e) { 40 e.printStackTrace(); 41 } 42 } else { 43 try { 44 System.out.println("Try to wait in " + timeout + "."); 45 lock.wait(timeout); 46 } catch (InterruptedException e) { 47 e.printStackTrace(); 48 } 49 } 50 } 51 52 System.out.println("Over thread."); 53 } 54 }
线程栈:
"WaitingThread" #10 prio=5 os_prio=0 tid=0x0000000018dea000 nid=0x1220 in Object.wait() [0x00000000198ee000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000000eb6477e8> (a java.lang.Object) at java.lang.Object.wait(Object.java:502) at com.test.threadpool.TestThreadState$WaitingThread.run(TestThreadState.java:138) - locked <0x00000000eb6477e8> (a java.lang.Object)
分析:WaitingThread线程调用lock.wait();所有处在等待中,且没有指定时间。waiting on <0x00000000eb6477e8> 表示该线程使用synchronized申请对象锁成功,locked <0x00000000eb6477e8> 且成功锁住了对象 <0x00000000eb6477e8>
(2)调用join()方法导致的WAITING状态,join()的功能就是让“主线程”等待“子线程”结束之后才能继续运行。【in Object.wait() 重点关注非线程池等待】
代码:
1 /** 2 * 线程调用join方法,状态变成WAITING。 3 */ 4 public static void testStateWatingByJoin() { 5 Object lock = new Object(); 6 WaitingThread waitingThread = new WaitingThread("WaitingThread", lock); 7 waitingThread.start(); 8 JoinThread joinThread = new JoinThread("JoinThread", waitingThread); 9 joinThread.start(); 10 11 try { 12 Thread.sleep(100); 13 } catch (InterruptedException e) { 14 e.printStackTrace(); 15 } 16 17 System.out.println("Main thread check the join thread's state is " + joinThread.getState() + "."); // WAITING 18 } 19 20 static class JoinThread extends Thread { 21 private int timeout = 0; 22 private Thread thread; 23 24 public JoinThread(String name, Thread thread) { 25 this(name, thread, 0); 26 } 27 28 public JoinThread(String name, Thread thread, int timeout) { 29 super(name); 30 this.timeout = timeout; 31 this.thread = thread; 32 } 33 34 @Override 35 public void run() { 36 if (timeout == 0) { 37 try { 38 System.out.println("Try to join."); 39 thread.join(); 40 } catch (InterruptedException e) { 41 e.printStackTrace(); 42 } 43 } else { 44 try { 45 System.out.println("Try to join in " + timeout + "."); 46 thread.join(timeout); 47 } catch (InterruptedException e) { 48 e.printStackTrace(); 49 } 50 } 51 System.out.println("Over join."); 52 } 53 } 54 static class WaitingThread extends Thread { 55 private int timeout = 0; 56 private Object lock; 57 58 public WaitingThread(String name, Object lock) { 59 this(name, lock, 0); 60 } 61 62 public WaitingThread(String name, Object lock, int timeout) { 63 super(name); 64 this.timeout = timeout; 65 this.lock = lock; 66 } 67 68 @Override 69 public void run() { 70 synchronized (lock) { 71 if (timeout == 0) { 72 try { 73 System.out.println("Try to wait."); 74 lock.wait(); 75 } catch (InterruptedException e) { 76 e.printStackTrace(); 77 } 78 } else { 79 try { 80 System.out.println("Try to wait in " + timeout + "."); 81 lock.wait(timeout); 82 } catch (InterruptedException e) { 83 e.printStackTrace(); 84 } 85 } 86 } 87 88 System.out.println("Over thread."); 89 } 90 }
线程栈:
1 "JoinThread" #11 prio=5 os_prio=0 tid=0x0000000019007000 nid=0x33c0 in Object.wait() [0x0000000019c1f000] 2 java.lang.Thread.State: WAITING (on object monitor) 3 at java.lang.Object.wait(Native Method) 4 - waiting on <0x00000000eb64a498> (a com.test.threadpool.TestThreadState$WaitingThread) 5 at java.lang.Thread.join(Thread.java:1252) 6 - locked <0x00000000eb64a498> (a com.test.threadpool.TestThreadState$WaitingThread) 7 at java.lang.Thread.join(Thread.java:1326) 8 at com.test.threadpool.TestThreadState$JoinThread.run(TestThreadState.java:194) 9 "WaitingThread" #10 prio=5 os_prio=0 tid=0x0000000019006000 nid=0x35ac in Object.wait() [0x0000000019b1f000] 10 java.lang.Thread.State: WAITING (on object monitor) 11 at java.lang.Object.wait(Native Method) 12 - waiting on <0x00000000eb64a468> (a java.lang.Object) 13 at java.lang.Object.wait(Object.java:502) 14 at com.test.threadpool.TestThreadState$WaitingThread.run(TestThreadState.java:138) 15 - locked <0x00000000eb64a468> (a java.lang.Object)
分析:从打印日志可以看出WaitingThread先得到执行,但是因为该线程有lock.wait();操作,导致线程WaitingThread处在WAITING状态,转而cpu执行权给到了JoinThread,但是JoinThread线程有了thread.join();代码导致它要等待WaitingThread线程执行完才能执行,所有2个线程就这样一直WAITING下去,从堆栈信息waiting on <0x00000000eb64a498> (a com.test.threadpool.TestThreadState$WaitingThread)也可以看出JoinThread在等待WaitingThread执行完。
(3)调用LockSupport.park方法导致的WAITING状态。【waiting on condition】
使用线程池的时候经常会遇到这种状态,当线程池里面的任务都执行完毕,会等待获取任务。这个例子非常典型
代码:
1 public static void testStateWatingByThreadExecutor() { 2 ExecutorService executeService = Executors.newSingleThreadExecutor(); 3 executeService.submit(new Runnable() { 4 @Override 5 public void run() { 6 System.out.println("Over Run."); 7 } 8 }); 9 10 try { 11 Thread.sleep(10000); 12 } catch (InterruptedException e) { 13 e.printStackTrace(); 14 } 15 }
线程栈:
1 "pool-1-thread-1" #10 prio=5 os_prio=0 tid=0x0000000018f9c000 nid=0x2e88 waiting on condition [0x0000000019aaf000] 2 java.lang.Thread.State: WAITING (parking) 3 at sun.misc.Unsafe.park(Native Method) 4 - parking to wait for <0x00000000eb64cc30> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) 5 at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) 6 at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) 7 at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) 8 at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) 9 at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) 10 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) 11 at java.lang.Thread.run(Thread.java:748)
分析:因为线程执行完了AQS处在自旋状态,或者无线程可执行就会等待,只有线程池加入了新的线程任务,才会被唤醒。
5、TIMED_WATING
有时限的等待另一个线程的特定操作。该线程正在等待,通过使用了 sleep, wait, join 或者是 park 方法。(这个与 WAITING不同是通过方法参数指定了最大等待时间,WAITING可以通过时间或者是外部的变化解除),线程等待指定的时间。
调用了以下方法的线程会进入TIMED_WAITING:Thread#sleep(xxx)、Object#wait() 并加了超时参数、Thread#join() 并加了超时参数、LockSupport#parkNanos()、LockSupport#parkUntil()
(1)Thread#sleep(xxx)【waiting on condition】
代码:
1 1 public static void testSleep() { 2 2 try { 3 3 Thread.sleep(1000 * 100); 4 4 } catch (InterruptedException e) { 5 5 e.printStackTrace(); 6 6 } 7 7 }
线程栈:
1 "main" #1 prio=5 os_prio=0 tid=0x0000000004f80800 nid=0x34bc waiting on condition [0x0000000004e7f000] 2 java.lang.Thread.State: TIMED_WAITING (sleeping) 3 at java.lang.Thread.sleep(Native Method) 4 at com.test.threadpool.TestThreadState.testSleep(TestThreadState.java:233) 5 at com.test.threadpool.TestThreadState.main(TestThreadState.java:53)
(2)Object.wait(long timeout) 方法【in Object.wait() 重点关注非线程池等待】
线程栈:
1 "quartzScheduler_Worker-10" #114 prio=5 os_prio=0 tid=0x00007f3e9af5d000 nid=0x363b in Object.wait() [0x00007f3e6e5de000] 2 java.lang.Thread.State: TIMED_WAITING (on object monitor) 3 at java.lang.Object.wait(Native Method) 4 at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:568) 5 - locked <0x00000006ca783798> (a java.lang.Object)
1)“TIMED_WAITING (on object monitor)”,是因为本线程调用了 java.lang.Object.wait(long timeout) 而进入等待状态。
2)“Wait Set”中等待的线程状态就是“in Object.wait()”。当线程获得了Monitor,进入了临界区之后,如果发现线程继续运行的条件没有满足,它则调用对象(一般就是被 synchronized 的对象)的
wait()方法,放弃了Monitor,进入“Wait Set”队列。只有当别的线程在该对象上调用了 notify() 或者notifyAll(),“Wait Set”队列中线程才得到机会去竞争,但是只有一个线程获得对象的 Monitor,恢复到运行态。
(3)LockSupport.park(long timeout)方法【waiting on condition】
1 "XNIO-1 task-10" #415 prio=5 os_prio=0 tid=0x00007f3eb4214800 nid=0x38d7 waiting on condition [0x00007f3e63fbc000] 2 java.lang.Thread.State: TIMED_WAITING (parking) 3 at sun.misc.Unsafe.park(Native Method) 4 - parking to wait for <0x00000006cd39ae40> (a org.jboss.threads.EnhancedQueueExecutor) 5 at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) 6 at org.jboss.threads.EnhancedQueueExecutor$PoolThreadNode.park(EnhancedQueueExecutor.java:2234) 7 at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1493) 8 at org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282) 9 at java.lang.Thread.run(Thread.java:750)
.TIMED_WAITING 线程处于有时限等待状态,(parking):表示线程处于挂起中。.waiting on condition 要和栈中- parking to wait for <0x00000006cd39ae40> (a org.jboss.threads.EnhancedQueueExecutor)结合来看:首先,本线程肯定是在等待某个条件的发生来把自己唤醒。其次,(org.jboss.threads.EnhancedQueueExecutor)就是本线程在等待的条件。
6、TERMINATED
已退出、销毁、终止,在使用jstack进行线程dump的时候也很少看到该状态的线程栈。
三、线程Dump分析基础-监视器锁
- 进入区(Entrt Set):表示线程通过synchronized要求获取对象的锁。如果获取到了锁,则进入拥有者;否则在进入区等待。一旦对象锁被其他线程释放,立即参与竞争。
- 拥有者(The Owner):表示某一线程成功竞争到对象锁。
- 等待区(Wait Set):表示线程通过对象的wait方法,释放对象的锁,并在等待区等待被唤
锁的状态阅读起来需要一些技巧,与锁相关的重要信息如下:
当一个线程占有一个锁的时候,线程堆栈会打印一个:-locked<0x22bffb60>,当一个线程正在等在其他线程释放该锁,线程堆栈会打印一个:-waiting to lock<0x22bffb60>,当一个线程占有一个锁,但又执行在该锁的wait上,线程堆栈中首先打印locked,然后打印:-waiting on <0x22c03c60>。在线程堆栈中与锁相关的三个最重要的特征字:locked,waiting to lock,waiting on 了解这三个特征字,就可以对锁进行分析了。一般情况下,当一个或一些线程正在等待一个锁的时候,应该有一个线程占用了这个锁,即如果有一个线程正在等待一个锁,该锁必然被另一个线程占用,从线程堆栈中看,如果看到waiting to lock<0x22bffb60>,应该也应该有locked<0x22bffb60>,大多数情况下确实如此,但是有些情况下,会发现线程堆栈中可能根本没有locked<0x22bffb60>,而只有waiting to ,这是什么原因呢,实际上,在一个线程释放锁和另一个线程被唤醒之间有一个时间窗,如果这个期间,恰好打印堆栈信息,那么只会找到waiting to ,但是找不到locked 该锁的线程,当然不同的JAVA虚拟机有不同的实现策略,不一定会立刻响应请求,也许会等待正在执行的线程执行完成。
四、分析工具
1、基础命令
首先,使用top命令找到资源占用最高的java应用PID,比如3429; 然后,使用top -Hp 3429命令查看3429进程里面占用最多的资源的线程,比如3440; 然后,使用命令printf "%x\n" 3440,把线程id转换成16进制数得到:d70; 最后,使用jstack 3429 | grep -20 d70命令查询与该线程有关线程栈前后20行的信息,结合线程栈Dump和程序日志进一步分析程序慢的原因。
附录:动态监视各个线程状态数量,因为线程栈Dump只是一个瞬时快照,不能动态反应JVM各种线程的变化,而且GC会阻塞所有的用户线程,即使获取到同步锁的线程也有可能被阻塞。
[wjy@node101 ~]# jstack -l 549 |grep java.lang.Thread.State | awk '{print $2$3$4$5}' | sort | uniq -c 55 RUNNABLE 16 TIMED_WAITING(onobjectmonitor) 17 TIMED_WAITING(parking) 3 TIMED_WAITING(sleeping) 2 WAITING(onobjectmonitor) 58 WAITING(parking)
2、可视化工具TDA
TDA可以作为JConsole、VisualVM插件使用,这里使用VisualVM来演示TDA使用
(1)使用TDA导入线程Dump文件.
(2)对于每个线程转储文件,TDA将所有找到的线程、监视器Monitor累加,还将waiting on、waiting for和 locking monitors的线程进行分组。单击转储节点本身将为您提供有关转储的信息。如果它有什么特别之处,TDA会给你一些关于它发现了什么以及下一步该怎么做的提示。
(3)如果您想关注在线程中找到的锁,只需单击监视器,TDA就会展开线程Dump的monitor节点,并关注单击的监视器。如果有什么特别之处,例如它没有明显的线程锁定监视器,但其他线程在等待它,它也会向您提供有关监视器的信息。从这里你可以很容易地看到一个线程是否挂着并持有许多其他线程正在等待的锁。如果没有任何锁定线程,而只有等待线程,则很可能垃圾收集器当前正在锁定监视器。在这种情况下,你会得到一个提示来告诉你这件事。
(4)多文件对比分析
如果系统负载过重,则应进行几个线程转储(例如,在短时间内每两分钟转储一次)。所有线程都有一个线程id,该id可以映射到Linux/Solaris系统上的真实进程id。TDA解析ID,并在线程视图中将其显示为“Native ID”。
(5)TDA单独软件里支持创建过滤器filter
(6)TDA单独软件里支持创建分类,这些分类选择特定一些过滤器filter,然后这个分类下按照这些过滤器过滤展示符合条件的一组线程,说白了就是多了一种分组
(7)作为JConsole插件使用
命令:
jconsole -pluginpath ./tda.jar
(8)作为VisualVM插件使用
(9)作为VisualVM里JConsole插件
附:
Online Java Thread Dump Analyzer