java - JBoss 线程等待随机监视器

Question

我正在对部署在 JBoss 中的 Web 应用程序进行一些负载测试。它启动时很好，但随着测试的增加和更多模拟用户开始使用 JBoss，性能严重下降:

将 VisualVM 连接到它，我可以看到线程都很好，然后突然开始花费大部分时间等待监视器(绿色正在运行，红色是监视器，黄色是等待):

运行 jstack，我看到线程都在同一个地方等待:

"http-0.0.0.0-8080-172" daemon prio=6 tid=0x000000005da90000 nid=0xd2c waiting for monitor entry [0x000000006cb4e000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.apache.log4j.Category.callAppenders(Category.java:185)
    - waiting to lock  (a org.apache.log4j.spi.RootCategory)
    at org.apache.log4j.Category.forcedLog(Category.java:372)
    at org.apache.log4j.Category.debug(Category.java:241)
    [my code]

大约 200 个 HTTP 处理器线程中的大多数都在等待同一个监视器。查看 WAR 的 log4j.xml，它有一个用于 CONSOLE 的附加程序设置。我删除了 appender 并再次尝试我的测试。相同的行为，除了 jstack 显示所有线程在不同的地方等待:

"http-0.0.0.0-8080-251" daemon prio=6 tid=0x0000000059811800 nid=0x1108 waiting for monitor entry [0x0000000073ebe000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at java.util.Hashtable.get(Hashtable.java:333)
    - waiting to lock  (a org.jboss.util.property.PropertyMap)
    at java.util.Properties.getProperty(Properties.java:932)
    at org.jboss.util.property.PropertyMap.getProperty(PropertyMap.java:626)
    at java.lang.System.getProperty(System.java:653)
    at org.jaxen.saxpath.helpers.XPathReaderFactory.createReader(XPathReaderFactory.java:109)
    at org.jaxen.BaseXPath.(BaseXPath.java:124)
    at org.jaxen.BaseXPath.(BaseXPath.java:153)
    at nu.xom.JaxenConnector.(JaxenConnector.java:49)
    at nu.xom.Node.query(Node.java:424)
    [my code]

什么都不做，我重新启动 JBoss，运行测试，然后在它变慢时运行 jstack。所有线程都在不同的地方等待:

"http-0.0.0.0-8080-171" daemon prio=6 tid=0x000000005d0d1000 nid=0x15d4 waiting for monitor entry [0x000000006cb4e000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at sun.nio.cs.FastCharsetProvider.charsetForName(FastCharsetProvider.java:118)
    - waiting to lock  (a sun.nio.cs.StandardCharsets)
    at java.nio.charset.Charset.lookup2(Charset.java:449)
    at java.nio.charset.Charset.lookup(Charset.java:437)
    at java.nio.charset.Charset.isSupported(Charset.java:479)
    at sun.nio.cs.StreamDecoder.forInputStreamReader(StreamDecoder.java:49)
    at java.io.InputStreamReader.(InputStreamReader.java:57)
    at java.io.FileReader.(FileReader.java:41)
    [my code]

这到底是怎么回事？我过去使用过 jstack，当一切运行良好并获得预期结果时，我尝试运行它。我认为 jstack 没问题。有什么想法会导致这种奇怪的行为吗？关于从这里去哪里有什么想法吗？

Answer 1

这种行为是意料之中的。当您扩大负载测试时，您总是会发现瓶颈，而在复杂的系统中，这些瓶颈会转移。

您的工作是找出这些瓶颈并尝试解决它们，一次一个。每次你这样做，你总会找到另一个，但希望系统每次都能扩展得更好。这并不容易，但扩展负载也不容易。

• 举第一个例子。您对 log4j 的 Logger.debug() 方法有很多调用。 Log4j 在负载下记录时表现不佳，因此您需要采取一些预防措施。即使您的 log4j 配置说“不记录 DEBUG 消息”，log4j 在意识到这一点之前仍然需要做一些工作。推荐的处理方法是将每个 Logger.debug() 调用包装在 if Logger.isDebugEnabled() { Logger.debug(); }` block 。这应该会转移那个特定的瓶颈。

• 在您的第二个示例中，您正在调用 XOM 的 Node.query() 方法。此方法必须在每次调用时重新编译 XPath 表达式，这似乎是一个瓶颈。找到一个 API，您可以在其中预编译 XPath 表达式并重新使用它。

• 在第三个示例中，您正在读取一个文件。这在高负载系统中不是一个好主意，当您执行大量小操作时，file-io 很慢。如果可以，请考虑以不同的方式重新实现它。

所有这些都是不相关的，但都存在性能瓶颈，您会在扩展负载时看到。您永远无法摆脱它们，但希望您可以将其达到足够好的程度。