Tomcat thread consumes maximum CPU

Question

We have a Tomcat 7.0.21 server running on OpenJDK Server VM (20.0-b11 mixed mode). The webapp runs well for usually several hours or days after startup - typical CPU load is 1-2%.

At some point, the tomcat process starts to consume 100% CPU. At some time later it will consume 200%, then 300% etc (there are 4 processors).

I ran this command to identify which threads are causing the problem:

ps H -eo user,pid,ppid,tid,time,%cpu,cmd --sort=%cpu

...and then got a thread dump from the JVM

kill -QUIT <processId>

Predictably with the CPU at 200%, there are 2 offending threads. Their stack traces are the same:

"http-bio-80-exec-19" daemon prio=10 tid=0x08dcfc00 nid=0x192e runnable [0x442fe000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jasper.runtime.JspWriterImpl.write(JspWriterImpl.java:339)
    at org.apache.jasper.runtime.JspWriterImpl.write(JspWriterImpl.java:353)
    at org.apache.jsp.returnBubble_jsp._jspService(returnBubble_jsp.java:343)
    at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
    at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:433)
    at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:389)
    at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:333)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:224)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:185)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:151)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:405)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:269)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:515)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:300)
    - locked <0x6f39c2b0> (a org.apache.tomcat.util.net.SocketWrapper)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
    at java.lang.Thread.run(Thread.java:679)

The jsp file that it refers to (returnBubble_jsp.java:343) is not really doing anything special - it's called frequently by every user. If we look at line 343 of the generated java:

out.write("</td></tr>\n");

So I'm fairly confident it's not my JSP that's causing it! Note that the line number does change in other offending threads, but it always a similar out.write method.

What is this thread doing? And how do I prevent it from happening?

can you post the whole thread dump? maybe into a `pastebin.com`? — Tom, May 24 '12 at 08:03
Can you post a little bit of the JSP in question? This could easily be an infinite loop where out.write() takes all the thread's time and so you only see that kind of thing in stack traces. — Christopher Schultz, May 24 '12 at 15:34
Many thanks @Christopher Schultz - your comment made me go through the jsp a bit more carefully, and you were right. Simple when you find it. For interest, I had this: `for (int i=0; i — ricsearle, May 24 '12 at 23:09

score 0 · Answer 1 · answered May 24 '12 at 13:39

try disabling the feedFetcher task, as it looks to be another thread which might be causing livelock problems;

"Timer-3" daemon prio=10 tid=0x46135400 nid=0x1901 runnable [0x45f69000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketConnect(Native Method)
    at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:327)
    - locked <0x85153b58> (a java.net.SocksSocketImpl)
    at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:193)
    at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:180)
    at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:384)
    at java.net.Socket.connect(Socket.java:546)
    at java.net.Socket.connect(Socket.java:495)
    at sun.net.NetworkClient.doConnect(NetworkClient.java:178)
    at sun.net.www.http.HttpClient.openServer(HttpClient.java:409)
    at sun.net.www.http.HttpClient.openServer(HttpClient.java:530)
    - locked <0x851458d8> (a sun.net.www.http.HttpClient)
    at sun.net.www.http.HttpClient. (HttpClient.java:240)
    at sun.net.www.http.HttpClient.New(HttpClient.java:321)
    at sun.net.www.http.HttpClient.New(HttpClient.java:338)
    at sun.net.www.protocol.http.HttpURLConnection.getNewHttpClient(HttpURLConnection.java:935)
    at sun.net.www.protocol.http.HttpURLConnection.plainConnect(HttpURLConnection.java:876)
    at sun.net.www.protocol.http.HttpURLConnection.connect(HttpURLConnection.java:801)
    at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1139)
    - locked <0x851c9e58> (a sun.net.www.protocol.http.HttpURLConnection)
    at com.sun.org.apache.xerces.internal.impl.XMLEntityManager.setupCurrentEntity(XMLEntityManager.java:654)
    at com.sun.org.apache.xerces.internal.impl.XMLVersionDetector.determineDocVersion(XMLVersionDetector.java:189)
    at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:783)
    at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(XML11Configuration.java:748)
    at com.sun.org.apache.xerces.internal.parsers.XMLParser.parse(XMLParser.java:123)
    at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1208)
    at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$JAXPSAXParser.parse(SAXParserImpl.java:525)
    at org.jdom.input.SAXBuilder.build(SAXBuilder.java:518)
    at org.jdom.input.SAXBuilder.build(SAXBuilder.java:905)
    at uk.rock7.tracker.FeedFetcher.run(FeedFetcher.java:73)
    at java.util.TimerThread.mainLoop(Timer.java:534)
    at java.util.TimerThread.run(Timer.java:484)

The FeedFetcher task is only running on one of our 3 servers, but the same issue is occuring on all three servers. — ricsearle, May 24 '12 at 21:44

score 0 · Accepted Answer · answered May 24 '12 at 23:15

Many thanks @Christopher Schultz - your comment made me go through the jsp a bit more carefully, and you were right. Simple when you find it. For interest, I had this:

for (int i=0; i<n; i++) { 
    ...
    myArray[i=3].method();
...
}

The 'equals' should have been a 'minus'. Might teach me to use a bigger font in my IDE!

Tomcat thread consumes maximum CPU

2 Answers2