Java性能分析之线程栈详解
Java性能分析迈不过去的一个关键点是线程栈,新的性能班级也讲到了JVM这一块,所以本篇文章对线程栈进行基础知识普及以及如何对线程栈进行性能分析。
基本概念
线程堆栈也称线程调用堆栈,是虚拟机中线程(包括锁)状态的一个瞬间状态的快照,即系统在某一个时刻所有线程的运行状态,包括每一个线程的调用堆栈,锁的持有情况。虽然不同的虚拟机打印出来的格式有些不同,但是线程堆栈的信息都包含:
1、线程名字,id,线程的数量等。
2、线程的运行状态,锁的状态(锁被哪个线程持有,哪个线程在等待锁等)
3、调用堆栈(即函数的调用层次关系)调用堆栈包含完整的类名,所执行的方法,源代码的行数。
线程作用
因为线程栈是瞬时快照包含线程状态以及调用关系,所以借助堆栈信息可以帮助分析很多问题,比如线程死锁,锁争用,死循环,识别耗时操作等等。线程栈是瞬时记录,所以没有历史消息的回溯,一般我们都需要结合程序的日志进行跟踪,一般线程栈能分析如下性能问题:
1、系统无缘无故的cpu过高
2、系统挂起,无响应
3、系统运行越来越慢
4、性能瓶颈(如无法充分利用cpu等)
5、线程死锁,死循环等
6、由于线程数量太多导致的内存溢出(如无法创建线程等)
线程栈状态
线程栈状态有如下几种
1、NEW
2、RUNNABLE
3、BLOCKED
4、WAITING
5、TIMED_WAITING
6、TERMINATED
下面依次对6种线程栈状态进行介绍。
线程栈状态详解
1、NEW
线程刚刚被创建,也就是已经new过了,但是还没有调用start()方法,这个状态我们使用jstack进行线程栈dump的时候基本看不到,因为是线程刚创建时候的状态。
2、RUNNABLE
从虚拟机的角度看,线程正在运行状态,状态是线程正在正常运行中, 当然可能会有某种耗时计算/IO等待的操作/CPU时间片切换等, 这个状态下发生的等待一般是其他系统资源, 而不是锁, Sleep等。
处于RUNNABLE状态的线程是不是一定会消耗cpu呢,不一定,像socket IO操作,线程正在从网络上读取数据,尽管线程状态RUNNABLE,但实际上网络io,线程绝大多数时间是被挂起的,只有当数据到达后,线程才会被唤起,挂起发生在本地代码(native)中,虚拟机根本不一致,不像显式的调用sleep和wait方法,虚拟机才能知道线程的真正状态,但在本地代码中的挂起,虚拟机无法知道真正的线程状态,因此一概显示为RUNNABLE。
3、BLOCKED
线程处于阻塞状态,正在等待一个monitor lock。通常情况下,是因为本线程与其他线程公用了一个锁。其他在线程正在使用这个锁进入某个synchronized同步方法块或者方法,而本线程进入这个同步代码块也需要这个锁,最终导致本线程处于阻塞状态。
真实生活例子:
今天你要去阿里面试。这是你梦想的工作,你已经盯着它多年了。你早上起来,准备好,穿上你最好的外衣,对着镜子打理好。当你走进车库发现你的朋友已经把车开走了。在这个场景,你只有一辆车,所以怎么办?在真实生活中,可能会打架抢车。 现在因为你朋友把车开走了你被BLOCKED了。你不能去参加面试。
这就是BLOCKED状态。用技术术语讲,你是线程T1,你朋友是线程T2,而锁是车。T1被BLOCKED在锁(例子里的车)上,因为T2已经获取了这个锁。
4、WAITING
这个状态下是指线程拥有了某个锁之后,
调用了他的wait方法, 等待其他线程/锁拥有者调用 notify / notifyAll一遍该线程可以继续下一步操作, 这里要区分
BLOCKED 和 WATING 的区别, 一个是在临界点外面等待进入, 一个是在理解点里面wait等待别人notify,
线程调用了join方法 join了另外的线程的时候, 也会进入WAITING状态,
等待被他join的线程执行结束,处于waiting状态的线程基本不消耗CPU。
真实生活例子:
再看下几分钟后你的朋友开车回家了,锁(车)就被释放了,现在你意识到快到面试时间了,而开车过去很远。所以你拼命地踩油门。限速120KM/H而你以160KM/H的速度在开。很不幸,一个交警发现你超速了,让你停到路边。现在你进入了WAITING状态。你停下车坐在那等着交警过来检查开罚单然后给你放行。基本上,你只有等他让你走(你没法开车逃),你被卡在WAITING状态了。
用技术术语来讲,你是线程T1而交警是线程T2。你释放你的锁(例子中你停下了车),并进入WAITING状态,直到警察(例子中T2)让你走,你陷入了WAITING状态。
小贴士:当线程调用以下方法时会进入WAITING状态:
1、Object#wait() 而且不加超时参数
2、Thread#join() 而且不加超时参数
3、LockSupport#park()
5、TIMED_WAITING
该线程正在等待,通过使用了 sleep, wait, join 或者是 park 方法。(这个与 WAITING 不同是通过方法参数指定了最大等待时间,WAITING 可以通过时间或者是外部的变化解除),线程等待指定的时间。
真实生活例子:
尽管这次面试过程充满戏剧性,但你在面试中做的非常好,惊艳了所有人并获得了高薪工作。你回家告诉你的邻居你的新工作并表达你激动的心情。你的朋友告诉你他也在同一个办公楼里工作。他建议你坐他的车去上班。你想这不错。所以去阿里上班的第一天,你走到你邻居的房子,在他的房子前停好你的车。你等了他10分钟,但你的邻居没有出现。你然后继续开自己的车去上班,这样你不会在第一天就迟到。这就是TIMED_WAITING.
用技术术语来解释,你是线程T1而你的邻居是线程T2。你释放了锁(这里是停止开车)并等了足足10分钟。如果你的邻居T2没有来,你继续开车(老司机注意车速,其他乘客记得买票)。
小贴士:调用了以下方法的线程会进入TIMED_WAITING:
1、Thread#sleep()
2、Object#wait() 并加了超时参数
3、Thread#join() 并加了超时参数
4、LockSupport#parkNanos()
5、LockSupport#parkUntil()
TIMED_WAITING (parking)实例如下:
从图中可以看出
1)“TIMED_WAITING (parking)”中的 timed_waiting 指等待状态,但这里指定了时间,到达指定的时间后自动退出等待状态;parking指线程处于挂起中。
2)“waiting on condition”需要与堆栈中的“parking to wait for <0x00000000acd84de8> (a java.util.concurrent.SynchronousQueue$TransferStack)”结合来看。
首先,本线程肯定是在等待某个条件的发生,来把自己唤醒。
其次,SynchronousQueue 并不是一个队列,只是线程之间移交信息的机制,当我们把一个元素放入到 SynchronousQueue 中时必须有另一个线程正在等待接受移交的任务,因此这就是本线程在等待的条件。
3)别的就看不出来了。
TIMED_WAITING (on object monitor)状态如下图,表示当前线程被挂起一段时间,说明该线程正在执行obj.waiting time方法,该状态的线程不消耗cpu。
从图中可以看出
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,恢复到运行态。
6、TERMINATED
线程终止,同样我们在使用jstack进行线程dump的时候也很少看到该状态的线程栈。
状态小结
这些状态中NEW状态是开始,TERMINATED是销毁,在整个线程对象的运行过程中,这个两个状态只能出现一次。其他任何状态都可以出现多次,彼此之间可以相互转换
处于timed_waiting/waiting状态的线程一定不消耗cpu,处于runnable状态的线程不一定会消耗cpu,要结合当前线程代码的性质判断,是否消耗cpu
如果是纯java运算代码,则消耗cpu
如果线程处于网络io,很少消耗cpu
如果是本地代码,通过查看代码,可以通过pstack获取本地的线程堆栈,如果是纯运算代码,则消耗cpu,如果被挂起,则不消耗,如果是io,则不怎么消耗cpu。
以下是状态转化图,可以较为清晰地看到状态转换的场景与条件:
线程栈解读
从main线程看,线程堆栈里面的最直观的信息是当前线程的调用上下文,即从哪个函数调用到哪个函数(从下往上看),正执行到哪一类的哪一行,借助这些信息,我们就对当前系统正在做什么一目了然。
其中"线程对应的本地线程Id号"所指的本地线程是指该java虚拟机所对应的虚拟机中的本地线程,我们知道java是解析型语言,执行的实体是java虚拟机,因此java代码是依附于java虚拟机的本地线程执行的,当启动一个线程时,是创建一个native本地线程,本地线程才是真实的线程实体,为了更加深入理解本地线程和java线程的关系,我们可以通过以下方式将java虚拟机的本地线程打印出来:
1、试用ps -ef|grep java 获得java进行id
2、试用pstack<java pid> 获得java虚拟机本地线程的堆栈
从操作系统打印出来的虚拟机的本地线程看,本地线程数量和java线程数量是相同的,说明二者是一一对应的关系。
那么本地线程号如何与java线程堆栈文件对应起来呢,每一个线程都有tid,nid的属性,通过这些属性可以对应相应的本地线程,我们先看java线程第一行,里面有一个属性是nid,
main" prio=1 tid=0x0805c988 nid=0xd28 runnable [0xfff65000..0xfff659c8]
其中nid是native thread id,也就是本地线程中的LWPID,二者是相同的,只不过java线程中的nid用16进制表示,本地线程的id(top -H里取到的java线程id)用十进制表示。3368的十六进制表示0xd28,在java线程堆栈中查找nid为0xd28就是本地线程对应的java线程。
线程锁解读
线程栈中包含直接信息为:线程个数,每个线程调用的方法堆栈,当前锁的状态。从线程个数可以直接数出来,线程调用的方法堆栈,从下向上看,表示了当前线程调用哪个类哪个方法,锁的状态看起来需要一些技巧,与锁相关的重要信息如下:
当一个线程占有一个锁的时候,线程堆栈会打印一个-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虚拟机有不同的实现策略,不一定会立刻响应请求,也许会等待正在执行的线程执行完成。
结合jstack结果对线程状态详解
上篇文章详细介绍了线程栈的作用、状态、任何查看理解,本篇文章结合jstack工具来查看线程状态,并列出重点关注目标。Jstack是常用的排查工具,它能输出在某一个时间,Java进程中所有线程的状态,很多时候这些状态信息能给我们的排查工作带来有用的线索。 Jstack的输出中,Java线程状态主要是以下几种:
1、BLOCKED 线程在等待monitor锁(synchronized关键字)
2、TIMED_WAITING 线程在等待唤醒,但设置了时限
3、WAITING 线程在无限等待唤醒
4、RUNNABLE 线程运行中或I/O等待
下面通过详细的实例来对这几种状态进行解释
BLOCKED
如下图所示,为使用jstack工具dump线程后,查看到的线程处于blocked状态。dump线程后,最先看的是线程所处的状态。这个线程处于Blocked状态,我们需要重点分析。
首先,我们来逐条分析下jstack工具抓取到的线程信息:
jstack工具抓取到的线程信息,是从下往上分析的,由上图可见,线程先是开始运行,之后运行业务的一些方法,直到调用 org.apache.log4j.Category.forcedLog之后,开始waiting to lock。
- 线程的状态是:BLOCKED (on object monitor)
说明线程处于阻塞状态,正在等待一个monitor lock。阻塞原因是:因为本线程与其他线程公用了一个锁,这时,已经有其他在线程正在使用这个锁进入某个synchronized同步方法块或者方法。当本线程想要进入这个同步代码块时,也需要这个锁,但锁已被占用,从而导致本线程处于阻塞状态。
- 第一行中包含了线程名和id等信息,如上图中的"druid-consumer-pool-3",nid(每个线程都有线程pid,将该pid转成16进制的值,即为jstack结果中的nid,可以通过nid唯一确认一个线程。)
- 第一行中还有线程目前正在 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,执行临界区的代码
2、该 monitor被其它线程拥有,本线程在 Entry Set队列中等待。
在第一种情况下,线程将处于 “Runnable”的状态
而第二种情况下,线程 DUMP会显示处于 “waiting for monitor entry”
根据以上分析,我们可以看出,线程想要调用log4j,目的是打印日志,但是由于调用log4j写日志有锁机制,于是线程被阻塞了。再排查项目使用的log4j版本,得知此版本存在性能bug,优化手段为升级log4j版本或者调整日志级别、优化日志打印的内容,或者添加缓存。
- waiting to lock <地址>
说明线程使用synchronized申请对象锁未成功,于是开始等待别的线程释放锁。线程在监视器的进入区等待。这条一般在调用栈顶出现,线程状态一般对应为Blocked。
TIMED_WAITING
如下图所示,为使用jstack工具dump线程后,查看到的线程处于TIMED_WAITING状态。
- 线程的状态是:TIMED_WAITING
这时的线程处于sleep状态,说明线程在有时限的等待另一个线程的特定操作,一般会有超时时间唤醒。就一般情况来说,出现TIMED_WAITING很正常,等待网络IO等都会出现这种状态,但是大量的线程处于TIMED_WAITING时,需要我们重点分析。
- 第一行中,显示线程在waiting on condition,这说明线程在等待某个条件的发生,从而自己唤醒,或者是调用了 sleep(n)。
当线程在waiting on condition时,线程状态可能为:
1、java.lang.Thread.State: WAITING (parking):一直等某个条件发生;
2、java.lang.Thread.State: TIMED_WAITING (parking或sleeping):定时等待某个条件发生,即使这个条件不到来,也将定时唤醒自己。
在我们这个例子里,线程处于 TIMED_WAITING状态。
- parking to wait for <地址>目标
这里即为第一行“waiting on condition" 所等待的条件,等待是java.util.concurrent.CountDownLatch$Sync,这是一种闭锁的实现,是一种同步工具类,可以延迟线程的进度直到闭锁到达终止状态,其内部包含一个计数器,该计数器被初始化为一个整数,表示需要等待事件的数量。由以上分析可以知道,线程是因为向druid写数据,由于有同步机制,而进入TIMED_WAITING状态。
- 和上个例子线程在parking to wait for 不同,在这个例子中,线程也是处于TIMED_WAITING状态,但是第一行中显示线程正在 in Object.wait(),第四行显示线程waiting on <地址> 目标。
线程在in Object.wait(), 说明线程在获得了监视器之后,又调用了 java.lang.Object.wait() 方法。
上篇线程详解(一)中说过等待monitor 的线程分为两种
在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”
在 “Wait Set”中等待的线程状态是 “in Object.wait()”
本例是在“Wait Set”中等待的线程,其状态是in Object.wait(),这说明线程获得了 Monitor,但是线程继续运行的条件没有满足,则调用对象(一般就是被 synchronized 的对象)的 wait() 方法,放弃了 Monitor,进入 “Wait Set”队列。
此时线程状态大致为以下几种:
1、java.lang.Thread.State: TIMED_WAITING (on object monitor);
2、java.lang.Thread.State: WAITING (on object monitor);
本例中线程就处于TIMED_WAITING状态。
WAITING
如下图所示,为使用jstack工具dump线程后,查看到的线程处于WAITING状态。
(1)线程的状态是:WAITING
意思就是线程在等待另外一个线程去解除它的等待状态。一个典型的例子就是生产者消费者模型,当生产者生产太慢的时候,消费者要等待生产者生产才能去消费,这段时间消费者线程就处于waiting状态。还可以使用lock.wait()方法使线程进入waiting状态,无超时的等待,必须等待lock.notify()或lock.notifyAll()或接收到interrupt信号才能退出等待状态。
(2)parking to wait for <地址> 目标
第一行中,显示线程在waiting on condition,这说明线程在等待某个条件的发生,从而自己唤醒。
当线程在waiting on condition时,线程状态可能为
java.lang.Thread.State: WAITING (parking):一直等某个条件发生;
java.lang.Thread.State: TIMED_WAITING (parking或sleeping):定时等待某个条件发生,即使这个条件不到来,也将定时唤醒自己。
在这个例子里,线程处于 WAITING状态,parking to wait for所等待的是java.util.concurrent.locks.AbstractQueuedSynchronizer,这也是java实现同步机制。
RUNNABLE
如下图所示,为使用jstack工具dump线程后,查看到的线程处于RUNNABLE 状态。
在这个例子里,可以清楚看到整个线程运行的过程。在线程运行过程中,有很多次获取锁,即为上图中locked <地址> 目标,即此线程使用synchronized申请对象锁成功,是监视器的拥有者,可以在临界区内进行操作。上图所lock的内容有java IO的输入输出流等。
在一次测试过程中,通过线程打印有了一个意外收获
如下面信息,“http-bio-18272-exec-258”,表示Tomcat 的启动模式为 bio模式,将bio模式改为nio模式,在该项目中,其他条件不变,只将bio模式更改为nio模式,tps提升了一倍
tomcat的运行模式有3种.修改他们的运行模式.3种模式的运行是否成功,可以看他的启动控制台,或者启动日志.或者登录他们的默认页面http://localhost:8080/查看其中的服务器状态。
1)bio :默认的模式,性能非常低下,没有经过任何优化处理和支持.
2)nio :利用java的异步io护理技术,no blocking IO技术.
想运行在该模式下,直接修改server.xml里的Connector节点,修改protocol为
<Connector port="" protocol="org.apache.coyote.http11.Http11NioProtocol" connectionTimeout="" URIEncoding="UTF-8" useBodyEncodingForURI="true" enableLookups="false" redirectPort="" />
启动后,就可以生效。
3)apr
安装起来最困难,但是从操作系统级别来解决异步的IO问题,大幅度的提高性能.
必须要安装apr和native,直接启动就支持apr。