[prev in list] [next in list] [prev in thread] [next in thread]
List: tomcat-user
Subject: Re: long running socketwrite
From: Rallavagu <rallavagu () gmail ! com>
Date: 2016-03-30 22:17:12
Message-ID: 56FC5068.5030207 () gmail ! com
[Download RAW message or body]
On 3/30/16 10:25 AM, Rallavagu wrote:
>
>
> On 3/30/16 9:55 AM, Christopher Schultz wrote:
> > -----BEGIN PGP SIGNED MESSAGE-----
> > Hash: SHA1
> >
> > Rallavagu,
> >
> > On 3/30/16 11:54 AM, Rallavagu wrote:
> > > Tomcat 7.0.47, JDK 7
> > >
> > > I have following long running socketwrite thread (more than 10
> > > sec). Wondering what could cause this so I can further look and
> > > investigate.
> > >
> > > "http-bio-28080-exec-1497" daemon prio=10 tid=0x00007f812c230800
> > > nid=0x72fa runnable [0x00007f80010f9000] java.lang.Thread.State:
> > > RUNNABLE at java.net.SocketOutputStream.socketWrite0(Native
> > > Method) at
> > > java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
> > >
> > >
> > at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
> > > at
> > > org.apache.coyote.http11.InternalOutputBuffer.realWriteBytes(InternalO
> > utputBuffer.java:215)
> > >
> > > at
> > > org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:480)
> > >
> > >
> > at
> > > org.apache.coyote.http11.InternalOutputBuffer.flush(InternalOutputBuff
> > er.java:119)
> > >
> > > at
> > > org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11
> > Processor.java:805)
> > >
> > > at org.apache.coyote.Response.action(Response.java:174) at
> > > org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:3
> > 66)
> > >
> > >
> > at
> > > org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:333
> > )
> > >
> > >
> > at
> > > org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStr
> > eam.java:101)
> > >
> > > at
> > > org.springframework.security.web.context.SaveContextOnUpdateOrErrorRes
> > ponseWrapper$SaveContextServletOutputStream.flush(SaveContextOnUpdateOrE
> > rrorResponseWrapper.java:354)
> > >
> > > at
> > > com.sun.jersey.spi.container.servlet.WebComponent$Writer.flush(WebComp
> > onent.java:308)
> > >
> > > at
> > > com.sun.jersey.spi.container.ContainerResponse$CommittingOutputStream.
> > flush(ContainerResponse.java:146)
> > >
> > > at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297) at
> > > sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141) - locked
> > > <0x000000075a610750> (a java.io.OutputStreamWriter) at
> > > java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229) at
> > > java.io.BufferedWriter.flush(BufferedWriter.java:254) - locked
> > > <0x000000075a610750> (a java.io.OutputStreamWriter) at
> > > com.sun.jersey.core.util.ReaderWriter.writeToAsString(ReaderWriter.jav
> > a:191)
> > >
> > > at
> > > com.sun.jersey.core.provider.AbstractMessageReaderWriterProvider.write
> > ToAsString(AbstractMessageReaderWriterProvider.java:128)
> > >
> > > at
> > > com.sun.jersey.core.impl.provider.entity.StringProvider.writeTo(String
> > Provider.java:88)
> > >
> > > at
> > > com.sun.jersey.core.impl.provider.entity.StringProvider.writeTo(String
> > Provider.java:58)
> > >
> > > at
> > > com.sun.jersey.spi.container.ContainerResponse.write(ContainerResponse
> > .java:302)
> > >
> > > at
> > > com.sun.jersey.server.impl.application.WebApplicationImpl._handleReque
> > st(WebApplicationImpl.java:1510)
> > >
> > > at
> > > com.sun.jersey.server.impl.application.WebApplicationImpl.handleReques
> > t(WebApplicationImpl.java:1419)
> > >
> > > at
> > > com.sun.jersey.server.impl.application.WebApplicationImpl.handleReques
> > t(WebApplicationImpl.java:1409)
> > >
> > > at
> > > com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent
> > .java:409)
> > >
> > > at
> > > com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletC
> > ontainer.java:558)
> > >
> > > at
> > > com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletC
> > ontainer.java:733)
> > >
> > > at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
> > >
> > >
> > > This is during slow response times where many threads were opened
> > > (Tomcat configured with 500). Also, thread dump shows that 240 of
> > > tomcat threads are in following state which suggests that they are
> > > idle.
> > >
> > > "http-bio-28080-exec-1230" daemon prio=10 tid=0x00007f812c361800
> > > nid=0x29a0 waiting on condition [0x00007f810a7e6000]
> > > java.lang.Thread.State: TIMED_WAITING (parking) at
> > > sun.misc.Unsafe.park(Native Method) - parking to wait for
> > > <0x000000071d193f50> (a
> > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
> > >
> > >
> > at
> > > java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
> > >
> > >
> > at
> > > java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.
> > awaitNanos(AbstractQueuedSynchronizer.java:2082)
> > >
> > > at
> > > java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java
> > > 467)
> > >
> > >
> > at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:86)
> > > at
> > > org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:32)
> > > at
> > > java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.jav
> > a:1068)
> > >
> > > at
> > > java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.j
> > ava:1130)
> > >
> > > at
> > > java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.
> > java:615)
> > >
> > > at java.lang.Thread.run(Thread.java:744)
> > >
> > > Any clues would help. Thanks.
> >
> > So ~50% of your request-processing threads are active, and at least
> > one of them is hanging on socket.write().
> >
> > I would imagine you have a slow or unreliable client (e.g. mobile
> > phone with a bad connection) or the client has disappeared but the
> > socket hasn't closed, yet.
> >
> > You can set a write timeouts on your sockets, but you might end up
> > with more server-side errors and cranky clients getting connections
> > dropped.
>
> Thanks for the clue. Actually, there are multiple (185) of these long
> running socketwrite threads that are running for more than 10 seconds.
>
After further investigation, here is the snippet from stacktrace that
instrumentation APM found where there is a ClientAbortException thrown.
org.apache.catalina.connector.ClientAbortException.null
at
org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:371)
at
org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:333)
at
org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:101)
at
org.springframework.security.web.context.SaveContextOnUpdateOrErrorResponseWrapper$Sav \
eContextServletOutputStream.flush(SaveContextOnUpdateOrErrorResponseWrapper.java:354) \
at com.sun.jersey.spi.container.servlet.WebComponent$Writer.flush(WebComponent.java:308)
at
com.sun.jersey.spi.container.ContainerResponse$CommittingOutputStream.flush(ContainerResponse.java:146)
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
at java.io.BufferedWriter.flush(BufferedWriter.java:254)
at
com.sun.jersey.core.util.ReaderWriter.writeToAsString(ReaderWriter.java:191)
at
com.sun.jersey.core.provider.AbstractMessageReaderWriterProvider.writeToAsString(AbstractMessageReaderWriterProvider.java:128)
at
com.sun.jersey.core.impl.provider.entity.StringProvider.writeTo(StringProvider.java:88)
at
com.sun.jersey.core.impl.provider.entity.StringProvider.writeTo(StringProvider.java:58)
at
com.sun.jersey.spi.container.ContainerResponse.write(ContainerResponse.java:302)
at
com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1510)
at
com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419)
at
com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409)
at
com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409)
at
com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:558)
at
com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:733)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
However, the thread continue to live in "RUNNABLE" state as below. I
wonder what makes the thread not to disconnect.
java.lang.Thread.State: RUNNABLE
at java.net.SocketOutputStream.socketWrite0(Native Method)
at
java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
at
org.apache.coyote.http11.InternalOutputBuffer.realWriteBytes(InternalOutputBuffer.java:215)
at
org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:480)
at
org.apache.coyote.http11.InternalOutputBuffer.flush(InternalOutputBuffer.java:119)
at
org.apache.coyote.http11.AbstractHttp11Processor.action(AbstractHttp11Processor.java:805)
at org.apache.coyote.Response.action(Response.java:174)
at
org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:366)
at
org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:333)
at
org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:101)
at
org.springframework.security.web.context.SaveContextOnUpdateOrErrorResponseWrapper$Sav \
eContextServletOutputStream.flush(SaveContextOnUpdateOrErrorResponseWrapper.java:354) \
at com.sun.jersey.spi.container.servlet.WebComponent$Writer.flush(WebComponent.java:308)
at
com.sun.jersey.spi.container.ContainerResponse$CommittingOutputStream.flush(ContainerResponse.java:146)
at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297)
at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
- locked <0x000000075644bc58> (a java.io.OutputStreamWriter)
at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229)
at java.io.BufferedWriter.flush(BufferedWriter.java:254)
- locked <0x000000075644bc58> (a java.io.OutputStreamWriter)
at
com.sun.jersey.core.util.ReaderWriter.writeToAsString(ReaderWriter.java:191)
at
com.sun.jersey.core.provider.AbstractMessageReaderWriterProvider.writeToAsString(AbstractMessageReaderWriterProvider.java:128)
at
com.sun.jersey.core.impl.provider.entity.StringProvider.writeTo(StringProvider.java:88)
at
com.sun.jersey.core.impl.provider.entity.StringProvider.writeTo(StringProvider.java:58)
at
com.sun.jersey.spi.container.ContainerResponse.write(ContainerResponse.java:302)
at
com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1510)
at
com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419)
at
com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409)
at
com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409)
at
com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:558)
at
com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:733)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
>
> >
> > - -chris
> > -----BEGIN PGP SIGNATURE-----
> > Comment: GPGTools - http://gpgtools.org
> > Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/
> >
> > iEYEARECAAYFAlb8BRkACgkQ9CaO5/Lv0PCu9QCfZejhctedau7gZzPbhOpllIH7
> > 7ooAnjwHoWz3/aLkjKKDSFlUs3n47MMN
> > =cJ/8
> > -----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
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic