当 JVM 在 GC 中花费时间时，Thread Dump 是什么样子的

Question

在分析 Java 应用程序时，我注意到一个有趣的事实。当 JVM 处于 GC 死亡螺旋时，线程转储如下所示：

"1304802943@qtp-393978767-9985" prio=10 tid=0x00007f3ed02dd000 nid=0x74e7 in Object.wait() [0x000000004febb000]
 java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
    - locked <0x00000007aed40048> (a org.mortbay.thread.QueuedThreadPool$PoolThread)

"26774405@qtp-393978767-9984" prio=10 tid=0x00007f3ee4b37000 nid=0x74e6 in Object.wait() [0x0000000045d1a000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
    - locked <0x00000007aed83aa0> (a org.mortbay.thread.QueuedThreadPool$PoolThread)

"764808089@qtp-393978767-9983" prio=10 tid=0x00007f3ee4c50000 nid=0x74e5 in Object.wait() [0x000000004ad6a000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:626)
    - locked <0x00000007aed5c448> (a org.mortbay.thread.QueuedThreadPool$PoolThread)

因此，有很多线程处于 TIMED_WAITING 状态。理论上，这种情况在正常运行的应用程序中很容易找到（应用程序目前没有任何传入请求），但我什至找不到单个请求分派线程做一些有用的事情（标称命中率约为 100 hps）。

这种行为与 GC 有什么关系，还是只是巧合？

Answer 1

仅回答问题标题：

当 JVM 在 GC 中花费时间时，线程转储是什么样子？

答案是：您无法（以通常的方式）获取此类转储。

JVM 仅在到达 安全点 后才处理线程转储请求这在 GC 中是不可能发生的。

但是有一种作弊方法可以借助未记录的 JVMTI 函数 AsyncGetCallTrace 来获取活动 GC 的线程转储，这篇文章中提到了这一点：

http://jeremymanson.blogspot.com/2010/07/why-many-profilers-have-serious.html

它还暗示Oracle Solaris Studio 可以 用于来获取此类混合的本机/java线程转储。

Answer 2

尝试 jmap -histo:live 随着时间的推移，您可以比较输出，查看哪些对象类型正在增长。

您需要为 jmap 安装 JDK。
http://docs.oracle.com/javase/6 /docs/technotes/tools/share/jmap.html

警告，jmap 是密集型的，它会在运行时暂停所有线程，这应该只有几秒钟。进程可以进行核心转储，因为它是密集型的，通常它是快速且安全的，但我看到它锁定或杀死大型应用程序、多千兆堆。

Answer 3

我的猜测是您有一个线程池正在等待执行某些操作。如果您的进程非常高效，并且每秒甚至有 100 个请求，那么您甚至可能很难捕获一个正在执行某项操作的线程。我建议你看看你的进程的CPU负载。如果是 50%，则您有 50% 的机会找到一个线程（可能不是请求线程）在做某事。

如果您想查看服务器花时间做什么，我会尝试使用 VisualVM 等分析器或 YourKit 等商业分析器。

在谷歌上搜索你的代码，我发现了一个不同的版本http://grepcode.com/file/repo1.maven.org/maven2/org.mortbay.jetty/jetty-util/7.0.0.pre5/org/mortbay/thread/QueuedThreadPool.java< /a> 但是我怀疑你的线程在 run() 方法中的这个块中处于 TIMED_WAIT

                // We are idle
                // wait for a dispatched job
                synchronized (this)
                {
                    if (_job==null)
                        this.wait(getMaxIdleTimeMs());
                    job=_job;
                    _job=null;
                }