Search code examples
javaperformancedebuggingconcurrencyjboss

JBoss threads waiting on random monitor

I'm doing some load testing on a web app deployed in JBoss. It starts up fine, but as the test ramps up and more simulated users start hitting JBoss, performance degrades severely:

Resposne time chart

Connecting VisualVM to it, I can see the threads were all fine, then suddenly started spending most of their time waiting for a monitor (green is running, red is monitor, yellow is wait):

Thread state graph

Running jstack, I see the threads are all waiting in the same place:

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

Most of the ~200 HTTP processor threads are waiting for the same monitor. Looking at log4j.xml for the WAR, it has a single appender setup for CONSOLE. I delete the appender and try my test again. Same behavior, except jstack shows all the threads waiting in a different place:

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

Changing nothing, I restart JBoss, run the test, then run jstack once it gets slow. All the threads are waiting in yet a different place:

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

What in the heck is going on? I have used jstack in the past and I tried running it when things are running fine and got the expected results. I assume jstack is fine. Any ideas what could cause such weird behavior? Any ideas on where to go from here?

Solution

  • I set up the application in Tomcat running through Eclipse and did not see the problem. Eventually I found we were starting JBoss using a 32-bit Windows service wrapper, even though we were using a 64-bit JDK. The machine was 64-bit. I'm not sure how this would even work? At any rate, changing to a 32-bit JDK caused the crazy problem to go away and I was able to move on with my life.