On Dec 23, 2013, at 7:55 PM, David Bullock <david.bull...@machaira.com.au> wrote:
> On 24 December 2013 07:58, Daniel Mikusa <dmik...@gopivotal.com> wrote: >> On Dec 19, 2013, at 8:08 PM, David Bullock <david.bull...@machaira.com.au> >> wrote: >> >>> On 20 December 2013 04:10, Daniel Mikusa <dmik...@gopivotal.com> wrote: > >> Unfortunately, once this problem starts to occur onWritePossible doesn't get >> called back. > >> When I take a thread dump of the code, it just shows all of the threads >> doing nothing. > >> Increasing timeout doesn't seem to help. Failures still occur within the >> same timeframe (i.e. same number requests to the server). The only affect >> is to create a delay between when requests stop being processed and the >> stack trace shows up. > >>> What happens if you instead pass the ServletOutputStream to the >>> DataStreamWriteListener's constructor? >> >> Unfortunately nothing. I still see the issue. > > OK, new theory. At some point, something happens in your onWritePossible > handler which throws an unchecked exception and crashes the Tomcat thread > which is responsible for keeping track of which async servlets are > still wanting to write data and doing appropriate cleanup of the NIO > selectors/keys. When onWritePossible is called by Tomcat, it's wrapped in a try..catch..finally, which catches Throwable. If it catches something, the write listener's onError method should get called with the exception. That's not happening in my unit test, so it doesn't seem like an exception is being raised in onWritePossible. See around line 369. http://svn.apache.org/viewvc/tomcat/trunk/java/org/apache/catalina/connector/CoyoteAdapter.java?view=markup > My money would have been on calling getOutputStream() on the response a > second time > (it throws java.lang.IllegalStateException, which is unchecked), but > you say you got rid of that. As far as I can tell, you should be able to call getOutputStream() as many times as you want. According to the javadoc, it only throws IllegalStateException if you've called getWriter() and then call getOutputStream(). http://tomcat.apache.org/tomcat-8.0-doc/servletapi/javax/servlet/ServletResponse.html#getOutputStream() > To eliminate other unchecked candidates, make your > onWritePossible() catch java.lang.Throwable and emit appropriate log messages > if it catches anything (or more usefully, point a debugger at the catch > clause). Tried this. Unfortunately, it does not catch anything. > If that doesn't yield success, then I would like to see 2 thread dumps > - once when > onWritePossible() has been called (maybe put in a Thread.sleep(5000) so you > have time to tickle the JVM), Here's a thread dump from the unit test, which I've paused in the debugger during the first call to the onWritePossible method. 2013-12-29 09:07:04 Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.45-b08 mixed mode): "http-nio-127.0.0.1-auto-1-exec-1" daemon prio=5 tid=0x00007fde4b888000 nid=0x8403 at breakpoint[0x00000001965b4000] java.lang.Thread.State: RUNNABLE at org.apache.catalina.nonblocking.TestWriteListener$DataStreamingServlet$DataStreamWriteListener.onWritePossible(TestWriteListener.java:114) at org.apache.coyote.Response.onWritePossible(Response.java:658) at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:369) at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1618) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:631) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) - locked <0x0000000165068000> (a org.apache.tomcat.util.net.NioChannel) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-Acceptor-0" daemon prio=5 tid=0x00007fde4f07e000 nid=0x8203 runnable [0x0000000197303000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241) - locked <0x0000000165018110> (a java.lang.Object) at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:693) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-ClientPoller-1" daemon prio=5 tid=0x00007fde4b89f800 nid=0x8003 runnable [0x0000000197124000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:200) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x0000000165030078> (a sun.nio.ch.Util$2) - locked <0x0000000165030088> (a java.util.Collections$UnmodifiableSet) - locked <0x0000000165030028> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1054) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-ClientPoller-0" daemon prio=5 tid=0x00007fde4b89f000 nid=0x7e03 runnable [0x0000000197021000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:200) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x0000000165020078> (a sun.nio.ch.Util$2) - locked <0x0000000165020088> (a java.util.Collections$UnmodifiableSet) - locked <0x0000000165020028> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1054) at java.lang.Thread.run(Thread.java:744) "ContainerBackgroundProcessor[StandardEngine[Tomcat]]" daemon prio=5 tid=0x00007fde4b928800 nid=0x7c03 waiting on condition [0x0000000196d6c000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1331) at java.lang.Thread.run(Thread.java:744) "localhost-startStop-1" daemon prio=5 tid=0x00007fde4c945800 nid=0x7a03 waiting on condition [0x0000000196ac0000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000016500b718> (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 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "Tomcat-startStop-1" daemon prio=5 tid=0x00007fde4b928000 nid=0x7803 waiting on condition [0x00000001964b1000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000016500b088> (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 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "NioBlockingSelector.BlockPoller-1" daemon prio=5 tid=0x00007fde4b925000 nid=0x7107 runnable [0x00000001963ae000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:200) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000016500ac38> (a sun.nio.ch.Util$2) - locked <0x000000016500ac28> (a java.util.Collections$UnmodifiableSet) - locked <0x000000016500aae8> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.tomcat.util.net.NioBlockingSelector$BlockPoller.run(NioBlockingSelector.java:342) "AsyncFileHandlerWriter-1967726688" daemon prio=5 tid=0x00007fde4d08c800 nid=0x6f03 waiting on condition [0x000000019612c000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000001650300c8> (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.LinkedBlockingDeque.pollFirst(LinkedBlockingDeque.java:519) at java.util.concurrent.LinkedBlockingDeque.poll(LinkedBlockingDeque.java:682) at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:147) "ReaderThread" prio=5 tid=0x00007fde4d075000 nid=0x6d03 runnable [0x0000000195ded000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) - locked <0x0000000165036230> (a java.io.InputStreamReader) at java.io.InputStreamReader.read(InputStreamReader.java:184) at java.io.BufferedReader.fill(BufferedReader.java:154) at java.io.BufferedReader.readLine(BufferedReader.java:317) - locked <0x0000000165036230> (a java.io.InputStreamReader) at java.io.BufferedReader.readLine(BufferedReader.java:382) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner$ReaderThread.run(RemoteTestRunner.java:140) "Service Thread" daemon prio=5 tid=0x00007fde4e01c000 nid=0x6903 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=5 tid=0x00007fde4c803000 nid=0x6703 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=5 tid=0x00007fde4c802800 nid=0x6503 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Command Reader" daemon prio=5 tid=0x00007fde4d811800 nid=0x6303 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Event Helper Thread" daemon prio=5 tid=0x00007fde4d810000 nid=0x6103 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Transport Listener: dt_socket" daemon prio=5 tid=0x00007fde4d80f000 nid=0x5f03 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=5 tid=0x00007fde4e016800 nid=0x5d03 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=5 tid=0x00007fde4b85d000 nid=0x4a03 in Object.wait() [0x000000019520b000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000001650110f8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000001650110f8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189) "Reference Handler" daemon prio=5 tid=0x00007fde4b85a000 nid=0x4803 in Object.wait() [0x0000000195108000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000165010ab8> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x0000000165010ab8> (a java.lang.ref.Reference$Lock) "main" prio=5 tid=0x00007fde4d800800 nid=0x1903 runnable [0x000000010556a000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.io.BufferedInputStream.fill(BufferedInputStream.java:235) at java.io.BufferedInputStream.read1(BufferedInputStream.java:275) at java.io.BufferedInputStream.read(BufferedInputStream.java:334) - locked <0x000000016501a220> (a java.io.BufferedInputStream) at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:687) at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:633) at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1323) - locked <0x000000016501a2d0> (a sun.net.www.protocol.http.HttpURLConnection) at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468) at org.apache.catalina.startup.TomcatBaseTest.methodUrl(TomcatBaseTest.java:247) at org.apache.catalina.startup.TomcatBaseTest.getUrl(TomcatBaseTest.java:219) at org.apache.catalina.startup.TomcatBaseTest.getUrl(TomcatBaseTest.java:213) at org.apache.catalina.startup.TomcatBaseTest.getUrl(TomcatBaseTest.java:202) at org.apache.catalina.nonblocking.TestWriteListener.testEchoListener1(TestWriteListener.java:53) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) at org.junit.runners.ParentRunner.run(ParentRunner.java:309) at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50) at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197) "VM Thread" prio=5 tid=0x00007fde4b859800 nid=0x4603 runnable "GC task thread#0 (ParallelGC)" prio=5 tid=0x00007fde4d80d800 nid=0x3603 runnable "GC task thread#1 (ParallelGC)" prio=5 tid=0x00007fde4b819800 nid=0x3803 runnable "GC task thread#2 (ParallelGC)" prio=5 tid=0x00007fde4b81a800 nid=0x3a03 runnable "GC task thread#3 (ParallelGC)" prio=5 tid=0x00007fde4b81b000 nid=0x3c03 runnable "GC task thread#4 (ParallelGC)" prio=5 tid=0x00007fde4b81b800 nid=0x3e03 runnable "GC task thread#5 (ParallelGC)" prio=5 tid=0x00007fde4b81c000 nid=0x4003 runnable "GC task thread#6 (ParallelGC)" prio=5 tid=0x00007fde4b81d000 nid=0x4203 runnable "GC task thread#7 (ParallelGC)" prio=5 tid=0x00007fde4b81d800 nid=0x4403 runnable "VM Periodic Task Thread" prio=5 tid=0x00007fde4e017800 nid=0x6b03 waiting on condition JNI global references: 2833 Heap PSYoungGen total 38912K, used 9856K [0x0000000162f00000, 0x0000000167b00000, 0x000000018da00000) eden space 33792K, 14% used [0x0000000162f00000,0x00000001633c02b8,0x0000000165000000) from space 5120K, 97% used [0x0000000165000000,0x00000001654e0050,0x0000000165500000) to space 5120K, 0% used [0x0000000167600000,0x0000000167600000,0x0000000167b00000) ParOldGen total 87040K, used 72K [0x000000010da00000, 0x0000000112f00000, 0x0000000162f00000) object space 87040K, 0% used [0x000000010da00000,0x000000010da12010,0x0000000112f00000) PSPermGen total 21504K, used 13713K [0x0000000108800000, 0x0000000109d00000, 0x000000010da00000) object space 21504K, 63% used [0x0000000108800000,0x0000000109564758,0x0000000109d00000) > and once when it is in the failure state. (one in the > starting-to-fail state would be good too). Here's a thread dump taken from the same execution after requests start timing out. I used the debugger to pause during the call to the onTimeout method of my AsyncListener and then took the thread dump. 2013-12-29 09:07:29 Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.45-b08 mixed mode): "http-nio-127.0.0.1-auto-1-exec-10" daemon prio=5 tid=0x00007fde4e114800 nid=0x8e03 waiting on condition [0x000000019770f000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-9" daemon prio=5 tid=0x00007fde4e113800 nid=0x8c03 waiting on condition [0x000000019760c000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-8" daemon prio=5 tid=0x00007fde4d801800 nid=0x8a03 waiting on condition [0x0000000197509000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-7" daemon prio=5 tid=0x00007fde4e056000 nid=0x8803 waiting on condition [0x0000000197406000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-6" daemon prio=5 tid=0x00007fde4d009000 nid=0x8603 waiting on condition [0x0000000196e6f000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-5" daemon prio=5 tid=0x00007fde4c945800 nid=0x5817 at breakpoint[0x0000000196ac0000] java.lang.Thread.State: RUNNABLE at org.apache.catalina.nonblocking.TestWriteListener$DataStreamingServlet$1.onTimeout(TestWriteListener.java:75) at org.apache.catalina.core.AsyncListenerWrapper.fireOnTimeout(AsyncListenerWrapper.java:45) at org.apache.catalina.core.AsyncContextImpl.timeout(AsyncContextImpl.java:151) at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:306) at org.apache.coyote.http11.AbstractHttp11Processor.asyncDispatch(AbstractHttp11Processor.java:1618) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:640) at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1576) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1534) - locked <0x000000010e06f480> (a org.apache.tomcat.util.net.NioChannel) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-4" daemon prio=5 tid=0x00007fde4b928000 nid=0x5107 waiting on condition [0x00000001968fc000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-3" daemon prio=5 tid=0x00007fde4d24c000 nid=0x4c07 waiting on condition [0x00000001966b7000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-2" daemon prio=5 tid=0x00007fde4e0b0000 nid=0x7a07 waiting on condition [0x00000001964b1000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-exec-1" daemon prio=5 tid=0x00007fde4b888000 nid=0x8403 waiting on condition [0x00000001965b4000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010dee9e60> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104) at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:1) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-Acceptor-0" daemon prio=5 tid=0x00007fde4f07e000 nid=0x8203 runnable [0x0000000197303000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method) at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:241) - locked <0x000000010df20f40> (a java.lang.Object) at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:693) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-ClientPoller-1" daemon prio=5 tid=0x00007fde4b89f800 nid=0x8003 runnable [0x0000000197124000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:200) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000010e06f800> (a sun.nio.ch.Util$2) - locked <0x000000010e06f7f0> (a java.util.Collections$UnmodifiableSet) - locked <0x000000010e06f1d0> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1054) at java.lang.Thread.run(Thread.java:744) "http-nio-127.0.0.1-auto-1-ClientPoller-0" daemon prio=5 tid=0x00007fde4b89f000 nid=0x7e03 runnable [0x0000000197021000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:200) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000010e06ed88> (a sun.nio.ch.Util$2) - locked <0x000000010e06ed78> (a java.util.Collections$UnmodifiableSet) - locked <0x000000010e06ec38> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1054) at java.lang.Thread.run(Thread.java:744) "ContainerBackgroundProcessor[StandardEngine[Tomcat]]" daemon prio=5 tid=0x00007fde4b928800 nid=0x7c03 waiting on condition [0x0000000196d6c000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1331) at java.lang.Thread.run(Thread.java:744) "NioBlockingSelector.BlockPoller-1" daemon prio=5 tid=0x00007fde4b925000 nid=0x7107 runnable [0x00000001963ae000] java.lang.Thread.State: RUNNABLE at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method) at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:200) at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87) - locked <0x000000010df209a8> (a sun.nio.ch.Util$2) - locked <0x000000010df20998> (a java.util.Collections$UnmodifiableSet) - locked <0x000000010df20858> (a sun.nio.ch.KQueueSelectorImpl) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98) at org.apache.tomcat.util.net.NioBlockingSelector$BlockPoller.run(NioBlockingSelector.java:342) "AsyncFileHandlerWriter-1967726688" daemon prio=5 tid=0x00007fde4d08c800 nid=0x6f03 waiting on condition [0x000000019612c000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x000000010e080aa0> (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.LinkedBlockingDeque.pollFirst(LinkedBlockingDeque.java:519) at java.util.concurrent.LinkedBlockingDeque.poll(LinkedBlockingDeque.java:682) at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:147) "ReaderThread" prio=5 tid=0x00007fde4d075000 nid=0x6d03 runnable [0x0000000195ded000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) - locked <0x000000010e0b00b8> (a java.io.InputStreamReader) at java.io.InputStreamReader.read(InputStreamReader.java:184) at java.io.BufferedReader.fill(BufferedReader.java:154) at java.io.BufferedReader.readLine(BufferedReader.java:317) - locked <0x000000010e0b00b8> (a java.io.InputStreamReader) at java.io.BufferedReader.readLine(BufferedReader.java:382) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner$ReaderThread.run(RemoteTestRunner.java:140) "Service Thread" daemon prio=5 tid=0x00007fde4e01c000 nid=0x6903 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread1" daemon prio=5 tid=0x00007fde4c803000 nid=0x6703 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" daemon prio=5 tid=0x00007fde4c802800 nid=0x6503 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Command Reader" daemon prio=5 tid=0x00007fde4d811800 nid=0x6303 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Event Helper Thread" daemon prio=5 tid=0x00007fde4d810000 nid=0x6103 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "JDWP Transport Listener: dt_socket" daemon prio=5 tid=0x00007fde4d80f000 nid=0x5f03 runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Signal Dispatcher" daemon prio=5 tid=0x00007fde4e016800 nid=0x5d03 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" daemon prio=5 tid=0x00007fde4b85d000 nid=0x4a03 in Object.wait() [0x000000019520b000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000010e02ba78> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x000000010e02ba78> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189) "Reference Handler" daemon prio=5 tid=0x00007fde4b85a000 nid=0x4803 in Object.wait() [0x0000000195108000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x000000010e02b620> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x000000010e02b620> (a java.lang.ref.Reference$Lock) "main" prio=5 tid=0x00007fde4d800800 nid=0x1903 runnable [0x000000010556a000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:152) at java.net.SocketInputStream.read(SocketInputStream.java:122) at java.io.BufferedInputStream.fill(BufferedInputStream.java:235) at java.io.BufferedInputStream.read1(BufferedInputStream.java:275) at java.io.BufferedInputStream.read(BufferedInputStream.java:334) - locked <0x000000016b36f6f0> (a java.io.BufferedInputStream) at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:687) at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:633) at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1323) - locked <0x000000016b36d738> (a sun.net.www.protocol.http.HttpURLConnection) at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:468) at org.apache.catalina.startup.TomcatBaseTest.methodUrl(TomcatBaseTest.java:247) at org.apache.catalina.startup.TomcatBaseTest.getUrl(TomcatBaseTest.java:219) at org.apache.catalina.startup.TomcatBaseTest.getUrl(TomcatBaseTest.java:213) at org.apache.catalina.startup.TomcatBaseTest.getUrl(TomcatBaseTest.java:202) at org.apache.catalina.nonblocking.TestWriteListener.testEchoListener1(TestWriteListener.java:53) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) at org.junit.runners.ParentRunner.run(ParentRunner.java:309) at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50) at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390) at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197) "VM Thread" prio=5 tid=0x00007fde4b859800 nid=0x4603 runnable "GC task thread#0 (ParallelGC)" prio=5 tid=0x00007fde4d80d800 nid=0x3603 runnable "GC task thread#1 (ParallelGC)" prio=5 tid=0x00007fde4b819800 nid=0x3803 runnable "GC task thread#2 (ParallelGC)" prio=5 tid=0x00007fde4b81a800 nid=0x3a03 runnable "GC task thread#3 (ParallelGC)" prio=5 tid=0x00007fde4b81b000 nid=0x3c03 runnable "GC task thread#4 (ParallelGC)" prio=5 tid=0x00007fde4b81b800 nid=0x3e03 runnable "GC task thread#5 (ParallelGC)" prio=5 tid=0x00007fde4b81c000 nid=0x4003 runnable "GC task thread#6 (ParallelGC)" prio=5 tid=0x00007fde4b81d000 nid=0x4203 runnable "GC task thread#7 (ParallelGC)" prio=5 tid=0x00007fde4b81d800 nid=0x4403 runnable "VM Periodic Task Thread" prio=5 tid=0x00007fde4e017800 nid=0x6b03 waiting on condition JNI global references: 2829 Heap PSYoungGen total 440832K, used 151268K [0x0000000162f00000, 0x000000018da00000, 0x000000018da00000) eden space 432128K, 34% used [0x0000000162f00000,0x000000016c01ecf8,0x000000017d500000) from space 8704K, 30% used [0x000000017d500000,0x000000017d79a3b8,0x000000017dd80000) to space 8704K, 0% used [0x000000018d180000,0x000000018d180000,0x000000018da00000) ParOldGen total 87040K, used 8243K [0x000000010da00000, 0x0000000112f00000, 0x0000000162f00000) object space 87040K, 9% used [0x000000010da00000,0x000000010e20cc28,0x0000000112f00000) PSPermGen total 21504K, used 13906K [0x0000000108800000, 0x0000000109d00000, 0x000000010da00000) object space 21504K, 64% used [0x0000000108800000,0x0000000109594ad8,0x0000000109d00000) Thanks for the help! Dan > > cheers, > David. > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org > --------------------------------------------------------------------- To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org For additional commands, e-mail: users-h...@tomcat.apache.org
