Nici JBoss czekające na losowym monitorze

Question

Przeprowadzam testy obciążenia w aplikacji internetowej wdrożonej w JBoss. Zaczyna się dobrze, ale jak pochylnie przetestowanie i więcej symulowanych użytkowników rozpocząć uderzenie JBoss, wydajność obniża poważnie:

Resposne time chart http://i46.tinypic.com/2mob2f9.jpg

Podłączanie VisualVM do niego, widzę gwinty były w porządku, a potem nagle zaczął wydatków większość czasu oczekiwania na monitorze (zielony jest uruchomiony, czerwony jest monitor, żółty to czekać):

Thread state graph http://i46.tinypic.com/105v6lk.jpg

Running jstack widzę gwinty wszyscy czekają w tym samym miejscu:

"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]

Większość ~ 200 wątków procesora HTTP czeka na ten sam monitor. Patrząc na log4j.xml dla WAR, ma on konfigurację pojedynczego instalatora dla CONSOLE. Usuwam aplikanta i ponownie testuję. Takie samo zachowanie, z wyjątkiem jstack pokazuje wszystkie wątki czekające w innym miejscu:

"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]

Zmiana nic, ja zrestartować JBoss, uruchom test, a następnie uruchomić jstack raz robi się powoli. Wszystkie wątki czekają jeszcze w innym miejscu:

"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]

Co u diabła się dzieje? Używałem jstack w przeszłości i próbowałem go uruchomić, gdy wszystko działa dobrze i przynosi oczekiwane rezultaty. Zakładam, że jstack jest w porządku. Wszelkie pomysły, które mogą powodować takie dziwne zachowanie? Jakieś pomysły na temat, dokąd się udać?

Answer 1

Ustawiłem aplikację w Tomcacie działającą przez Eclipse i nie widziałem problemu. Ostatecznie odkryłem, że zaczynamy JBossa przy użyciu 32-bitowej usługi Windows, mimo że używaliśmy 64-bitowego JDK. Maszyna była 64-bitowa. Nie jestem pewien, jak to by zadziałało? W każdym razie przejście na 32-bitowy JDK spowodowało, że szalony problem zniknął i mogłem ruszyć dalej z moim życiem.

Answer 2

Tego rodzaju zachowania należy się spodziewać. W miarę zwiększania obciążenia testowego zawsze znajdziecie wąskie gardła, a w złożonym systemie wąskie gardła będą się przesuwać.

Twoim zadaniem jest zidentyfikować wąskie gardła i spróbować je naprawić, po jednym na raz. Za każdym razem będziesz zawsze znajdować inny, ale mam nadzieję, że za każdym razem system będzie się skalować lepiej. To nie jest łatwe, ale skalowanie w celu załadowania nie jest łatwe.

• Weź swój pierwszy przykład. Masz wiele połączeń z metodą log4j pod numerem Logger.debug(). Log4j nie działa dobrze podczas logowania pod obciążeniem, więc należy podjąć pewne środki ostrożności. Nawet jeśli twoja konfiguracja log4j mówi "nie loguj wiadomości DEBUG", log4j nadal musi wykonać trochę pracy zanim to zrobisz. Zalecanym podejściem do obsługi jest zawijanie każdego wywołania Logger.debug() w postaci if Logger.isDebugEnabled() {Logger.debug(); } `blok. To powinno zmienić to wąskie gardło.

• W twoim drugim przykładzie nazywasz metodę XOM Node.query(). Ta metoda musi rekompilować wyrażenie XPath przy każdym wywołaniu i wydaje się, że jest to wąskie gardło. Znajdź interfejs API, w którym możesz wstępnie skompilować wyrażenie XPath i użyć go ponownie.

• W trzecim przykładzie czytasz File. To nie jest dobry pomysł w systemie z dużym obciążeniem, plik-io jest powolny, gdy wykonujesz wiele małych operacji. Rozważ ponowne wdrożenie tego, aby działało inaczej, jeśli możesz.

Wszystkie te elementy nie są powiązane, ale wszystkie obecne wąskie gardła występujące podczas skalowania pod kątem obciążenia. Nigdy się ich nie pozbędziesz, ale miejmy nadzieję, że uda ci się doprowadzić to do punktu, w którym jest wystarczająco dobry.