Потоки JBoss ожидают на случайном мониторе

Question

Я провожу нагрузочное тестирование веб-приложения, развернутого в JBoss.Он запускается нормально, но по мере того, как тест набирает обороты, и все больше симулируемых пользователей начинают использовать JBoss, производительность резко падает:

Диаграмма времени Resposne http://i46.tinypic.com/2mob2f9.jpg

Подключив VisualVM к нему, я вижувсе потоки были в порядке, затем внезапно начали тратить большую часть своего времени на ожидание монитора (зеленый работает, красный - монитор, желтый - ожидание):

График состояния потока http://i46.tinypic.com/105v6lk.jpg

Работает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 ждут одного и того же монитора.Глядя на log4j.xml для WAR, он имеет одну настройку appender для 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 написано «не регистрировать сообщения отладки», log4j все равно должен выполнить некоторую работу, прежде чем это понять. Рекомендуемый подход для обработки - это обернуть каждый вызов Logger.debug() в if Logger.isDebugEnabled() {Logger.debug (); } `блок. Это должно сместить это конкретное узкое место.

• В вашем 2ndexample вы вызываете метод Node.query() XOM. Этот метод должен перекомпилировать выражение XPath при каждом вызове, и это кажется узким местом. Найдите API, в котором вы можете предварительно скомпилировать выражение XPath и использовать его повторно.

• В третьем примере вы читаете File. Это не очень хорошая идея в высоконагруженной системе, когда вы выполняете большое количество мелких операций, file-io работает медленно. Подумайте над тем, чтобы реализовать это, чтобы по-другому работать, если вы можете.

Все они не связаны, но все существующие узкие места производительности вы увидите при масштабировании для нагрузки. Вы никогда не избавитесь от них всех, но, надеюсь, вы сможете достичь этого до такой степени, что это будет достаточно хорошо.

Answer 2

Я установил приложение в Tomcat, работающее через Eclipse, и не увидел проблемы. В конце концов я обнаружил, что мы запускаем JBoss с использованием 32-битной оболочки служб Windows, хотя мы использовали 64-битный JDK. Машина была 64-битной. Я не уверен, как это будет работать? В любом случае, переход на 32-битный JDK привел к тому, что сумасшедшая проблема исчезла, и я смог продолжить свою жизнь.