Java程序性能基础定位分析

1. 背景

在做性能测试中不断思考java应用，性能怎么观察，怎么通过方法定位到代码，是否有通用步骤，通过查找资料与参考前人的知识总结，才有如下文章，话说知道不等于会，会不等于能运用，只有不断有意识的去练习才能掌握。总之，这属于基础技能，有了这层基础，再去使用高级版的工具（如阿里的Arthas），也就顺风顺水，水到渠成。

本次定位的是Jmeter性能压测平台，对这个平台的介绍可以见：https://smooth.blog.csdn.net/article/details/83380879，为了让JAVA进程能占CPU高一点，我们把压测平台跑起来（让后台跑一个脚本就行）：

2. Linux下的定位

2.1 操作步骤

• 使用TOP命令找到谁在消耗CPU比较高的进程，例如pid = 1234
• 使用top -p 1234 单独监控该进程
• 输入大写的H列出当前进程下的所有线程
• 查看消耗CPU比较高的线程，并看线程编号，例如 131420
• 使用jstack 1234 > pagainfo.dump 获取当前进程下的dump线程信息（jstack是JDK自带的）
• 将第四步获取的线程编号131420转换成16进制2015c（printf "%x\n" 131420）
• 根据2015c在第5步获取的栈信息中查找nid=0x2015c的线程
• 定位代码位置（根据打印出来的堆栈信息查看代码所在位置）

注意：从操作系统打印出的虚拟机的本地线程看，本地线程数量和Java线程堆栈中的线程数量相同， 说明二者是一一对应的。只不过java线程中的nid中用16进制来表示， 而本地线程中的id用十进制表示。

2.2 演示

1. 先用TOP命令找到占用CPU高的进程：当然是JAVA（只是为了演示，其实不高，就相对别的进程高而已）

2. 使用top -p 29866 H 监控该进程的所有线程

我们就挑打头的线程70603作为我们的监测对象（暂时没有发现占CPU高的线程，就随便挑一个相对高一点的）。

3. 将第2步获取的线程编号70603转换成16进制113cb （printf "%x\n" 70603）

[root@localhost local]# printf "%x\n" 70603
113cb

4. 先用jstack 29866 > /opt/smooth/test.dump 获取当前进程下的dump线程信息

再用vi或vim命令打开test.dump文件，并找到113cb，如下所示：

第一行里，"main"是 Thread Name 。tid指Java Thread id。nid指native线程的id。prio是线程优先级。[0x00007f1064064000]是线程栈起始地址。

从上面可以看出目前线程正处于TIMED_WAITING状态，并且表示当前正在被有条件的挂起，根据性能压测平台的特性，这是正在压测，在等待压测线程停止：waitThreadstopped，我们定位到红框标示部分的类和方法，找到类文件LocalStandardJMeterEngine的第540行代码，如下所示：

再找到红框标示的下一行所提示的第468行代码：

到此，我们已经追踪到所要找的函数了（当然要追踪到慢的代码行，前提也是要对系统源码及结构有所了解，否则追踪起来也是比较费劲的）。

3. Windows下的定位

3.1 操作步骤

• 使用任务管理器（需要查看->选择列中勾选上PID），查看占用CPU高的进程，例如pid = 1234
• 使用 pslist -dmx 1234 命令（需要到微软官网下载http://technet.microsoft.com/en-us/sysinternals/bb896682.aspx ，解压后，将pslist.exe拷到 C:\Windows\System32 下即可使用）监视该进程的所有线程
• 查看消耗时间比较高的线程，并看线程编号，例如 131420
• 在cmd中进入JDK bin目录，使用jstack 1234 > pagainfo.dump 获取当前进程下的dump线程信息
• 将第三步获取的线程编号131420转换成16进制2015c （转换麻烦的话，可以上网用在线进制转换工具）
• 根据2015c在第4步获取的栈信息中查找nid=0x2015c的线程
• 定位代码位置（根据打印出来的堆栈信息查看代码所在位置）

说明： Windows下和Linux定位步骤基本上没有差别，只是windows下没有top命令，但是有更直观的任务管理器，由于任务管理器监视不到线程，所以利用了另外一个工具PSTool。

3.2 演示

1. 打开任务管理器（在选择列中把PID和命令行都勾上），找JAVA进程，查看命令行确定是我们要监控的应用：

2. 在任务管理器中找到对应的PID 4564，通过命令 pslist -dmx 4564，查看所有线程：

我们找到Cswtch（上下文切换）和User Time相对高的一个线程（不是所有占用资源高的线程都属于我们要监控的对象，需要比对查看dump 文件的内容后才能断定）：

3. 到网上找个在线进制转换工具，把Tid=7612进行转换：

4. 进入JDK的bin目录，执行 jstack 7612 > test.dump 命令，生成dump文件，用编辑器打开，找到1dbc：

可以看到线程处于挂起状态（等待另一个条件wait for <0x0000000083e72c18>来把自唤醒）， BackendListener属于jmeter引擎自带的类，不是我们这次关注的范围（我们这次就关注性能压测平台里的类和方法）。

5. 重新换一个线程来查看，挑User Time相对高的另一个线程，Tid=8120：

6. 转换进程后，到dump文件中，搜索1fb8，找到如下线程的stack信息：

这条stack多么熟悉，就是和Linux下定位的那条一样样，LocalStandardJMeterEngine类， 当前线程也是被有条件的挂起，打开源代码类，找到第523行代码，也是一样样的：

找到第467行代码，也是一样的结果：

说明我们在Windows下，也可以做到和Linux下一样的进行JAVA进程线程追踪（当然Java程序一般都是部署在Linux下）。

4. 总结

以上只是举例子，实际上真正分析要比这个难多了，因为以上过程不属于性能测试，也并没有出现性能瓶颈问题，只是做个简单的Java进程、线程和代码追踪。话说知道不等于会，会不等于能运用，只有不断有意识去练习才能掌握。

另外对于线程的状态，我们要能看的懂，只有看懂了才能有助于分析：

1>> RUNNABLE: 线程正在执行中，占用了资源，比如处理某个请求/进行计算/文件操作等。

2>> BLOCKED/Waiting to lock (需重点关注):

>>> Blocked 线程处于阻塞状态，等待某种资源 (可理解为等待资源超时的线程)；

>>> "waiting to lock <xxx>"，即等待给xxx上锁，grep stack文件找locked <xxx> 查找获得锁的线程；

>>> "waiting for monitor entry" 线程通过synchronized(obj){……}申请进入了临界区，但该obj对应的monitor被其他线程拥有，从而处于等待。

3>>WAITING/TIMED_WAITING {定时} (关注):

>>> "TIMED_WAITING (parking)"：等待状态，且指定了时间，到达指定的时间后自动退出等待状态，parking指线程处于挂起中；

>>> "waiting on condition" 需与堆栈中的"parking to wait for <xxx> ( at java.util.concurrent.SynchronousQueue$TransferStack )"结合来看。first-->此线程是在等待某个条件的发生，来把自己唤醒，second-->SynchronousQueue不是一个队列，其是线程之间移交信息的机制，当我们把一个元素放入到 SynchronousQueue 中时必须有另一个线程正在等待接受移交的任务，因此这就是本线程在等待的条件。

4>>Deadlock (需特别关注)：死锁，资源相互占用。

其他说明：

• 线程说明为“waiting for monitor entry”

意味着它 在等待进入一个临界区 ，所以它在”Entry Set“队列中等待。

此时线程状态一般都是 Blocked：

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

• 线程说明为“waiting on condition”

说明它在等待另一个条件的发生，来把自己唤醒，或者干脆它是调用了 sleep(N)。

此时线程状态大致为以下几种：

java.lang.Thread.State: WAITING (parking)：一直等那个条件发生；

java.lang.Thread.State: TIMED_WAITING (parking或sleeping)：定时的，那个条件不到来，也将定时唤醒自己。

• 如果大量线程在“waiting for monitor entry”

可能是一个全局锁阻塞住了大量线程。

如果短时间内打印的 thread dump 文件反映，随着时间流逝，waiting for monitor entry 的线程越来越多，没有减少的趋势，可能意味着某些线程在临界区里呆的时间太长了，以至于越来越多新线程迟迟无法进入临界区。

• 如果大量线程在“waiting on condition”

可能是它们又跑去获取第三方资源，尤其是第三方网络资源，迟迟获取不到Response，导致大量线程进入等待状态。

所以如果你发现有大量的线程都处在 Wait on condition，从线程堆栈看，正等待网络读写，这可能是一个网络瓶颈的征兆，因为网络阻塞导致线程无法执行。

线程状态为“in Object.wait()”：

说明它获得了监视器之后，又调用了 java.lang.Object.wait() 方法。

每个 Monitor在某个时刻，只能被一个线程拥有，该线程就是 “Active Thread”，而其它线程都是 “Waiting Thread”，分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”，而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。

当线程获得了 Monitor，如果发现线程继续运行的条件没有满足，它则调用对象（一般就是被 synchronized 的对象）的 wait() 方法，放弃了 Monitor，进入 “Wait Set”队列。

此时线程状态大致为以下几种：

java.lang.Thread.State: TIMED_WAITING (on object monitor)；

java.lang.Thread.State: WAITING (on object monitor)；

一般都是RMI相关线程（RMI RenewClean、 GC Daemon、RMI Reaper），GC线程（Finalizer），引用对象垃圾回收线程（Reference Handler）等系统线程处于这种状态。