9.5　监控线程与锁

在对应用中的线程和同步的效率作性能分析时，有两点需要注意：总的线程数（既不能太大，也不能太小）和线程花在等待锁或其他资源上的时间。

9.5.1　查看线程

几乎所有的 JVM 监控工具都提供了线程数（以及这些线程在干什么）相关的信息。像 jconsole 这样的交互式工具还能显示 JVM 内线程的状态。在 jconsole 的 Threads 面板上，可以实时观察程序执行期间线程数的增减。图 9-2 是一个例子。

在某个时间点，应用（NetBeans）最多使用了 45 个线程。图中刚开始有一个爆发点，最多会使用 38 个线程，后来线程数稳定在 30 到 31 之间。jconsole 可以打印每个单独线程的栈信息；如图所示，Java2D Disposer 线程正在某个引用队列的锁上等待。

{%}

图 9-2：JConsole 中的活跃线程视图

9.5.2　查看阻塞线程

如果想了解应用中有什么线程在运行这类高层视图，实时线程监控会很有用，但至于那些线程在做什么，实际上没有提供任何数据。要确定线程的 CPU 周期都耗在哪儿了，则需要使用分析器（profiler），第 3 章曾讨论过。利用分析器可以很好地观察哪些线程在执行。而且分析器一般非常成熟，可以指出那些能够通过更好的算法、更好的代码选择来加速整体执行效果的代码区域。

诊断阻塞的线程更为困难，尽管这类信息对应用的整体执行而言往往更为重要，特别是当代码运行在多 CPU 系统上，但没有利用起所有可用的 CPU 时。一般有三种执行此类诊断的方法。方法之一还是使用分析器，因为大部分分析工具都会提供线程执行的时间线信息，这就可以看到线程被阻塞的时间点。第 3 章也给出了一个例子。

1. 被阻塞线程与JFR

要了解线程是何时被阻塞的，迄今为止最好的方式是使用可以窥探 JVM 内部、并且可以在较低的层次确定线程被阻塞时间的工具。Java 飞行记录器（Java Flight Recorder，JFR）就是一款这样的工具，第 3 章已经介绍过。我们可以深入到 JFR 捕获的事件中，并寻找那些引发线程阻塞的事件（比如等待获取某个 Monitor，或是等待读写 Socket，不过写的情况较为少见）。

借助 JMC 的直方图面板可以很方便地查看这些事件，如图 9-3 所示。

{%}

图 9-3：JFR 中被某个 Monitor 阻塞的线程

在这个示例中，与 sun.awt.AppContext.get() 方法中的 HashMap 关联的锁被竞争了 163 次（超过 66 秒），使得所测量的请求响应时间平均增加了 31 毫秒。栈轨迹表明竞争源于 JSP 写 java.util.Date 对象的方式。要改进这段代码的可伸缩性，可以使用线程局部的日期格式化对象，而不是简单地调用日期对象的 toString() 方法。

从直方图中选择阻塞事件，然后检查调用代码，这个流程适合任何阻塞事件；这款与 JVM 紧密集成的工具使这一流程就成为可能。

2. 被阻塞线程与JStack

如果没有商用的 JVM 可用，替代方案之一是从程序中拿到大量的线程栈并加以检查。jstack、jcmd 和其他工具可以提供虚拟机中每个线程状态相关的信息，包括线程是在运行、等待锁还是等待 I/O 等。对于确定应用中正在进行的是什么，这可能非常有用，不过输出中也有很多我们不需要的。

在查看线程栈时，有两点需要注意。第一，JVM 只能在特定的位置（safepoint，安全点）转储出一个线程的栈。第二，每次只能针对一个线程转储出栈信息，所以可能会看到彼此冲突的信息：比如两个线程持有同一个锁，或者一个线程正在等待的锁并未被其他线程持有。

JStack 分析器

人们很容易认为，连续快速地抓取多个栈转储信息，就能将其用作一个简单快速的分析器。毕竟，采样分析器本质上就是这么工作的：周期性地探测线程的执行栈，基于这些信息推断在方法上花了多少时间。但是在安全点和不一致的快照之间，这么做不是很有效；通过查看这些线程栈，有时可以从较高的层次上大概获知执行成本较高的方法，但是一款真正的分析器提供的信息要精确得多。

从线程栈可以看出线程阻塞的严重程度（因为阻塞的线程已经在某个安全点上）。如果有连续的线程转储信息表明大量的线程阻塞在某个锁上，那么就可以断定这个锁上有严重的竞争。如果有连续的线程转储信息表明大量的线程在阻塞等待 I/O，则可以断定需要优化正在进行的 I/O 读操作（比如，如果是数据库调用，应该优化 SQL 执行，或者是优化数据库本身）。

在本书的在线示例中，有一个比较基本的 jstack 输出解析器，可以从一个或多个线程转储中总结出所有线程的状态。jstack 的输出有个问题，即不同版本之间可能会有变化，所以开发一个健壮的解析器比较困难。不能保证这个解析器可以不加修改地应用于你所使用的特定的 JVM。

jstack 解析器的基本输出像下面这样：

  1. % jstack pid > jstack.out
  2. % java ParseJStack jstack.out
  3. [Partial output...]
  4. Threads in start Running
  5.     8 threads in java.lang.Throwable.getStackTraceElement(Native
  6. Total Running Threads: 8
  8. Threads in state Blocked by Locks
  9.     41 threads running in
  10.         com.sun.enterprise.loader.EJBClassLoader.getResourceAsStream
  11.         (EJBClassLoader.java:801)
  12. Total Blocked by Locks Threads: 41
  14. Threads in state Waiting for notify
  15.     39 threads running in
  16.         com.sun.enterprise.web.connector.grizzly.LinkedListPipeline.getTask
  17.         (LinkedListPipeline.java:294)
  18.     18 threads running in System Thread
  19. Total Waiting for notify Threads: 74
  21. Threads in state Waiting for I/O read
  22.     14 threads running in com.acme.MyServlet.doGet(MyServlet.java:603)
  23. Total Waiting for I/O read Threads: 14

解析器聚合了所有的线程，可以显示处于各种状态的线程分别有多少。8 个线程正在运行（它们碰巧正在获取栈轨迹信息，这个操作成本非常高，最好避免）。

41 个线程被某个锁阻塞了。所报告的方法是栈轨迹中第一个非 JDK 方法，在这个例子中是 GlassFish 的 EJBClassLoader.getResourceAsStream()。下一步就是考虑栈轨迹信息，搜索这个方法，看看线程是阻塞到什么资源上了。

在这个例子中，所有线程都被阻塞了，在等待读取同一个 JAR 文件；这些线程的栈轨迹表明，所有调用都来自实例化新 SAX 实例的操作。如第 10 章所讨论的，SAX 解析器可以通过列出应用 JAR 文件中 manifest 文件内的资源来动态定义，这意味着 JDK 必须搜索整个类路径来寻找那些条目，直到找到应用想使用的一个（或者是找不到，回到系统解析器）。因为读取这个 JAR 文件需要一个同步锁，所以所有尝试创建一个解析器的线程最终都会竞争同一个锁，这会极大影响应用的吞吐量。（第 10 章建议设置 -Djavax.xml.parsers.SAXParserFactory 属性来避免这些查找，原因就在于此。）

更重要的一点是，大量被阻塞的线程会成为影响性能的问题。不管阻塞的根源是什么，都要对配置或应用加以修改，以避免之。

等待通知的线程又是什么样的情况呢？那些线程在等待其他事件发生。它们往往是在某个池中，等待任务就绪（比如，上面输出中的 getTask() 方法在等待请求）这类通知。系统线程会在处理像 RMI 分布式 GC 或 JMX 监控这样的事情，它们以栈中只有 JDK 类这类线程的形式出现在 jstack 的输出中。这些条件不一定表明有性能问题；对这些线程而言，等待通知是正常现象。

如果线程正在进行的是阻塞式 I/O 读取（通常是 socketRead0() 方法），也会导致问题。这也会影响吞吐量：线程正在等待某个后端资源回复其请求。这时候应该检查数据库或其他后端资源的性能。

9.5　监控线程与锁 - 图3　快速小结

1. 利用系统提供的线程基本信息，可以对正在运行的线程的数目有个大致了解。

2. 就性能分析而言，当线程阻塞在某个资源或 I/O 上时，能够看到线程的相关细节就显得比较重要。

3. JFR 使得我们可以很方便地检查引发线程阻塞的事件。

4. 利用 jstack，一定程度上可以检查线程是阻塞在什么资源上。