Hi, I'm running Tomcat trunk (revision 992708, 2010-09-03) and I'm hitting an async servlet (see attached) with Apache Bench, and every once in a while I see a NullPointerException in org.apache.catalina.core.AsyncContextImpl.doInternalComplete: Sep 4, 2010 8:09:39 PM org.apache.catalina.core.AsyncContextImpl doInternalDispatch FINE: TIMING OUT! Sep 4, 2010 8:09:40 PM org.apache.catalina.core.AsyncContextImpl doInternalDispatch FINE: TIMING OUT! Sep 4, 2010 8:09:40 PM org.apache.catalina.core.AsyncContextImpl doInternalComplete SEVERE: Throwable occurred: java.lang.NullPointerException at org.apache.catalina.core.AsyncContextImpl.doInternalComplete(AsyncContextImpl.java:384) at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:327) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:238) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:201) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:163) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:108) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:557) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118) at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:301) at org.apache.coyote.http11.Http11Processor.asyncDispatch(Http11Processor.java:333) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:258) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:257) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:898) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:920) at java.lang.Thread.run(Thread.java:736)
Created attachment 25989 [details] Servlet used to reproduce the problem
The state changes in AsyncContextImpl aren't atomic so I think what you are seeing is the result of multiple parallel calls to doInternalComplete(). Am I correct in thinking this error is fairly rare?
(In reply to comment #2) > The state changes in AsyncContextImpl aren't atomic so I think what you are > seeing is the result of multiple parallel calls to doInternalComplete(). Am I > correct in thinking this error is fairly rare? Yes, it is rare. The reason I reported this is that I'm load testing this servlet (well, my real servlet, but this one just to repro the problem), and every once in a while I get a 200 or 500 response that takes over 10 seconds whereas the average is half a second (using AccessLogValve %D to see this). I ran with tracing and noticed this NPE and thought maybe it's somehow related to the sporadic long request, but I don't know if it's root cause. Also, it is preceded by the "TIMING OUT!" entry, so maybe this NPE is just a side effect of the timeout?
I've been able to spend some time looking at this. It is very easy to reproduce on a multi-core machine with relatively low numbers of requests and concurrency. There is definitely a threading issue at the heart of this. I need to dig deeper to find out exactly what the root cause is.
(In reply to comment #4) > I've been able to spend some time looking at this. It is very easy to reproduce > on a multi-core machine with relatively low numbers of requests and > concurrency. > > There is definitely a threading issue at the heart of this. I need to dig > deeper to find out exactly what the root cause is. Thanks Mark.
Created attachment 26022 [details] Patch to make some private fields final They are probably not a cause of the synch. issues, but it would not harm to make these fields final.
This has been fixed in trunk and will be included in 7.0.3. Thanks for uncovering this. It highlighted a bunch of issues with the async implementation that are hopefully now fixed.