在哪里寻找java中的同步争用证据？

Question

当数百个用户使用我们的 Tomcat Web 应用程序时，会感觉速度很慢。 服务器位于托管公司，他们的报告没有显示任何带宽或 CPU 工作负载问题，因此我怀疑速度下降的原因可能是由于我们在同步调用下封装的一些遗留代码存在争用，因为它是更容易的路径。

我在开发环境中做了一些人工测试，使用 ThreadLocal 解决方案更改同步调用，它变得更快，但我知道我的老板会要求我提供一些证据，证明它在生产中也会更快。

我如何确定我的应用程序中是否存在线程争用问题？

Answer 1

我认为最新 Java 6 JDK 附带的 VisualVM 工具的 线程详细信息 视图将能够为支持（或反对）你的理论提供确凿的证据。 它为每个线程显示一个饼图，显示它在运行、睡眠、等待和监视器中花费了多少时间。 最后一个（以红色显示）是您感兴趣的内容：

Answer 2

如果您有一个您认为更快的修改版本，请使用一些负载测试器对其进行测试（例如 JMeter ）来测试两个版本。 如果存在显着差异，您将有结果来证明这一点。

Answer 3

您可以使用许多开源 Java 分析器，以及其他可能需要付费，例如 YourKit。 您应该使用现有代码和增强代码运行测试。 一般而言，使用 ThreadLocals 应该会减少争用，但请考虑在开始优化之前进行基准测试也是有好处的。

另一个无需设置任何分析器即可完成的非常简单的测试是在应用程序显得缓慢时进行一些线程转储（ctrl-break 或kill-QUIT）。 在短时间内发现一些线程在相似或相同的监视器上等待可能会非常清楚地指出慢点。 您可以使用 TDA 等工具（Java 线程转储分析器）来帮助您梳理线程转储。

同样，在开始优化之前完成这项工作是一个好主意。 这是因为，尽管优化可能会在一些明显的地方产生影响，但实际的用户行为可能会触发开发人员没有考虑到的路径，而这些可能会成为真正的问题区域。

Answer 4

jstack PID

将打印出带有进程 ID PID 的 JVM 状态列表，以及有关线程状态的信息。

示例输出（摘录）：

"AWT-XAWT" daemon prio=10 tid=0x0000000000e5f800 nid=0x476d runnable [0x00007f1a75616000..0x00007f1a75616bf0]
   java.lang.Thread.State: RUNNABLE
    at sun.awt.X11.XToolkit.waitForEvents(Native Method)
    at sun.awt.X11.XToolkit.run(XToolkit.java:543)
    at sun.awt.X11.XToolkit.run(XToolkit.java:518)
    at java.lang.Thread.run(Thread.java:636)

"Java2D Disposer" daemon prio=10 tid=0x0000000000d8b800 nid=0x476c in Object.wait() [0x00007f1a759df000..0x00007f1a759dfc70]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00007f1a82e2c3f8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:133)
    - locked <0x00007f1a82e2c3f8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:149)
    at sun.java2d.Disposer.run(Disposer.java:143)
    at java.lang.Thread.run(Thread.java:636)

我还尝试隔离争用的资源。 例如，如果遗留库正在锁定以同步对数据库的写入，那么您可能会最小化写入。

Answer 5

你的分析听起来很有道理。 您能否将 VisualVM（在 JDK 中）附加到进程中，以便您可以看到时间花在哪里？

Answer 6

我可以像这样在同步调用中添加日志记录，

//...
long t0 = System.currentTimeMillis();
synchronized(lockObj){
    logger.info("T sync :" + (t0 - System.currentTimeMillis()));
    //...
}

但这感觉既便宜又肮脏。