jstack工具查看系统线程问题

最近在做项目系统的异常测试，项目依赖于nkv，需要模拟依赖组件nkv异常时系统的响应及性能情况。通过tc工具模拟当服务器发送到nkv的请求超时时系统的响应。发现接口返回错误率100%，查看服务器日志报大量线程池已满,想要通过工具看下线程情况，由此简单学习了jstack。

WARN AbortPolicyWithReport - [DUBBO] Thread pool is EXHAUSTED! Thread Name: DubboServerHandler-10.165.185.170:22021, Pool Size: 200 (active: 200, core: 200, max: 200, largest: 200), Task: 182763 (completed: 182563), Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://10.165.185.170:22021!, dubbo version: 2.8.4-nisp, current host: 127.0.0.1 2016-11-21 13:55:33,801 WARN AbortPolicyWithReport - [DUBBO] Thread pool is EXHAUSTED! Thread Name: DubboServerHandler-10.165.185.170:22021, Pool Size: 200 (active: 200, core: 200, max: 200, largest: 200), Task: 182763 (completed: 182563), Executor status:(isShutdown:false, isTerminated:false, isTerminating:false), in dubbo://10.165.185.170:22021!, dubbo version: 2.8.4-nisp, current host: 127.0.0.1 jstack

基本介绍
jstack是用于生成java虚拟机当前时刻线程快照的工具。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。线程出现停顿的时候通过jstack来查看各个线程的调用堆栈，就可以知道没有响应的线程到底在后台做什么事情，或者等待什么资源。

命令语法格式

jstack <pid>

可以通过top查看java进程的pid

可通过jstack > jstack.log将快照打印至文件jstack.log

在实际运行中往往一次dump信息不足以确认问题，建议dump三次以便确认问题。

线程分析

线程示例
在线程中有一些JVM后台线程用于执行垃圾回收等任务，这些线程在JVM初始化时就存在，我们主要查看用户线程。在本次异常测试中，模拟异常后，系统响应慢大量报错，查看服务器日志显示线程池已满，通过jstack工具dump线程快照如下：

Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.60-b09 mixed mode): "MySQL Statement Cancellation Timer" daemon prio=10 tid=0x00000000019dc000 nid=0x3fab in Object.wait() [0x00007f035fe36000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x00000000c45a8680> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) "pool-5-thread-257" prio=10 tid=0x00000000014e7800 nid=0x3f8a waiting on condition [0x00007f035f129000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c45e9ea0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "pool-5-thread-256" prio=10 tid=0x00000000013c2800 nid=0x3f89 waiting on condition [0x00007f035f42c000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c45e9ea0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "pool-5-thread-255" prio=10 tid=0x00000000019fb000 nid=0x3f88 waiting on condition [0x00007f035f22a000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c45e9ea0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "pool-5-thread-254" prio=10 tid=0x00000000019d0000 nid=0x3f87 waiting on condition [0x00007f035f52d000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c45e9ea0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "pool-5-thread-253" prio=10 tid=0x00000000014ee000 nid=0x3f86 waiting on condition [0x00007f035f62e000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c45eabb0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "AMQP Connection 10.165.124.207:5672" prio=10 tid=0x0000000001862800 nid=0x3f85 runnable [0x00007f0360038000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.io.BufferedInputStream.fill(BufferedInputStream.java:235) at java.io.BufferedInputStream.read(BufferedInputStream.java:254) - locked <0x00000000c45ea970> (a java.io.BufferedInputStream) at java.io.DataInputStream.readUnsignedByte(DataInputStream.java:288) at com.rabbitmq.client.impl.Frame.readFrom(Frame.java:95) at com.rabbitmq.client.impl.SocketFrameHandler.readFrame(SocketFrameHandler.java:139) - locked <0x00000000c45ea950> (a java.io.DataInputStream) at com.rabbitmq.client.impl.AMQConnection$MainLoop.run(AMQConnection.java:536) at java.lang.Thread.run(Thread.java:745) "MySQL Statement Cancellation Timer" daemon prio=10 tid=0x000000000152b800 nid=0x395a in Object.wait() [0x00007f0360139000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) - locked <0x00000000c45f2b18> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) "Attach Listener" daemon prio=10 tid=0x00000000017a4000 nid=0x2168 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "pool-8-thread-1" prio=10 tid=0x00000000022e1800 nid=0x2d0 waiting on condition [0x00007f035e71f000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c05f7478> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "DubboResponseTimeoutScanTimer" daemon prio=10 tid=0x0000000002359800 nid=0x3972 waiting on condition [0x00007f035d40c000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at com.alibaba.dubbo.remoting.exchange.support.DefaultFuture$RemotingInvocationTimeoutScan.run(DefaultFuture.java:300) at java.lang.Thread.run(Thread.java:745) "pool-7-thread-1" prio=10 tid=0x00007f036ccf4800 nid=0x3825 waiting on condition [0x00007f0360b43000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000c05f7218> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:745) "DubboServerHandler-10.165.185.170:22021-thread-200" daemon prio=10 tid=0x00007f036c04e000 nid=0x381b waiting on condition [0x00007f0360c43000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000000ffcff858> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2176) at com.netease.backend.nkv.client.rpc.net.NkvFuture.innerWait(NkvFuture.java:162) at com.netease.backend.nkv.client.rpc.net.NkvFuture.get(NkvFuture.java:180) at com.netease.backend.nkv.client.rpc.future.NkvResultFutureImpl.innerGet(NkvResultFutureImpl.java:144) at com.netease.backend.nkv.client.rpc.future.NkvResultFutureImpl.get(NkvResultFutureImpl.java:81) at com.netease.backend.nkv.client.impl.DefaultNkvClient.futureGet(DefaultNkvClient.java:530) at com.netease.backend.nkv.client.impl.DefaultNkvClient.get(DefaultNkvClient.java:70) at com.netease.is.ec.rpc.nkv.NkvOpService.getValue(NkvOpService.java:78) at com.netease.is.ec.rpc.nkv.NkvOpService.setValue(NkvOpService.java:108) at com.netease.is.ec.rpc.cacheservice.KVSqlService.setValue(KVSqlService.java:61) at com.netease.is.ec.drag.create.CaptchaGetControl.getCaptcha(CaptchaGetControl.java:85) at com.netease.is.ec.drag.provider.DraggingCaptchaImpl.getCaptchaImg(DraggingCaptchaImpl.java:45) at com.alibaba.dubbo.common.bytecode.Wrapper1.invokeMethod(Wrapper1.java) at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:46) at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72) at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53) at com.alibaba.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:64) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:42) at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75)

线程状态

Runnable
该状态表示线程具备所有运行条件，在运行队列中准备操作系统的调度，或者正在运行。