tomcat-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Mike Wertheim ...@hyperreal.org>
Subject Re: help analyzing thread dump for Tomcat 7.0.23 issue
Date Wed, 04 Jan 2012 01:04:47 GMT
On Mon, Jan 2, 2012 at 6:55 PM, Mike Wertheim <mw@hyperreal.org> wrote:
> On Mon, Jan 2, 2012 at 3:09 PM, Christopher Schultz
> <chris@christopherschultz.net> wrote:
>> -----BEGIN PGP SIGNED MESSAGE-----
>> Hash: SHA1
>>
>> Mike,
>>
>> On 12/29/11 9:01 PM, Mike Wertheim wrote:
>>> I did a stack dump on 7.0.23 when it was in its messed up state.
>>> No threads are blocked on critical sections of my app.
>>
>> That's good.
>>
>>> For the port 8080 connector, there are 196 threads in "waiting on
>>> condition" and 4 threads in "runnable".
>>
>> What were those 4 RUNNABLE threads doing?
>
> They were processing POST requests from the client with a somewhat
> large data payload.
>
> Here's the stack from one of them:
> "http-apr-8080-exec-169" daemon prio=10 tid=0x00002aaabc893000
> nid=0x5253 runnable [0x00000000451a9000]
>   java.lang.Thread.State: RUNNABLE
>        at org.apache.tomcat.jni.Socket.recvbb(Native Method)
>        at org.apache.coyote.http11.InternalAprInputBuffer.fill(InternalAprInputBuffer.java:614)
>        at org.apache.coyote.http11.InternalAprInputBuffer$SocketInputBuffer.doRead(InternalAprInputBuffer.java:656)
>        at org.apache.coyote.http11.filters.IdentityInputFilter.doRead(IdentityInputFilter.java:118)
>        at org.apache.coyote.http11.InternalAprInputBuffer.doRead(InternalAprInputBuffer.java:548)
>        at org.apache.coyote.Request.doRead(Request.java:422)
>        at org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:290)
>        at org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:429)
>        at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:315)
>        at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:200)
>        at org.apache.catalina.connector.Request.readPostBody(Request.java:3096)
>        at org.apache.catalina.connector.Request.parseParameters(Request.java:3049)
>        at org.apache.catalina.connector.Request.getParameter(Request.java:1139)
>        at org.apache.catalina.connector.RequestFacade.getParameter(RequestFacade.java:382)
>        at com.mycompany.UploadServlet.service(UploadServlet.java:29)
>        at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
>        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
>        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
>        at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:738)
>        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
>        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
>        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:207)
>        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169)
>        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
>        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
>        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98)
>        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
>        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
>        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:987)
>        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:539)
>        at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:1773)
>        - locked <0x00000006680fdee8> (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:722)
>
>
>
>>
>>> For the port 8443 connector, there are 81 threads in "waiting on
>>> condition" and 119 threads in "runnable".
>>
>> Well, that looks like it might be a problem. What about the stack
>> traces for THOSE threads?
>
> They mostly look like this:
>
> "http-apr-8443-exec-200" daemon prio=10 tid=0x00002aaac8132800
> nid=0x520f runnable [0x0000000044fba000]
>   java.lang.Thread.State: RUNNABLE
>        at org.apache.tomcat.jni.SSLSocket.handshake(Native Method)
>        at org.apache.tomcat.util.net.AprEndpoint.setSocketOptions(AprEndpoint.java:751)
>        at org.apache.tomcat.util.net.AprEndpoint$SocketWithOptionsProcessor.run(AprEndpoint.java:1766)
>        - locked <0x000000067f3101e0> (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:722)
>
>
>> When you say "slowly grinds to a halt" do you mean that there's point
>> where you can no longer accept HTTP requests? How about HTTPS? When
>> you get stuck, what does 'top' show? Do the threads look idle or are
>> you burning up your CPU?
>
> It definitely stops accepting some (but not all) http requests.  To
> answer the other questions, I'd have to run the test again (and it
> takes a day to fail).

To follow up on this... I just ran the experiment again.  The CPUs are
very idle.

Currently, the system is not rejecting any requests.  Both http and
https are working.  (But in the past when I did this experiment, it
definitely was rejecting requests.  Maybe that will happen if I let it
run a little longer.)



>>> I don't know how to interpret this data, since I'm not really clear
>>> on what the difference is between "runnable" and "waiting on
>>> condition".
>>
>> "Waiting on condition" means that the thread is asleep, waiting for a
>> notify() signal from another thread telling it to re-attempt a monitor
>> lock (i.e. enter a synchronized block). "Runnable" means that the
>> thread is actually doing something.
>>
>>> Do these numbers seem normal, or are they perhaps giving a clue as
>>> to what the underlying problem might be?
>>
>> If those are production numbers, then you don't look like you have 1%
>> HTTPS traffic -- at least not at the moment you took your thread
>> dump(s). Otherwise, your connector is getting fouled-up. There's
>> another thread this week about weirdness in the NIO connector that
>> sounds somewhat similar, but I doubt the causes are connected. You
>> might want to read that thread just the kicks.
>>
>> - -chris
>> -----BEGIN PGP SIGNATURE-----
>> Version: GnuPG/MacGPG2 v2.0.17 (Darwin)
>> Comment: GPGTools - http://gpgtools.org
>> Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/
>>
>> iEYEARECAAYFAk8CORkACgkQ9CaO5/Lv0PCAUACeJSL6ueAhjdOmiwY0qEF+oLw7
>> xTUAn2nMUUwofRRlJSAX8EYMXw51W2QX
>> =v+SV
>> -----END PGP SIGNATURE-----
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Mime
View raw message